Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Cyclical or irregular failure pattern in Movement client tests in 690 #856

Open
andygolay opened this issue Nov 14, 2024 · 0 comments
Open

Cyclical or irregular failure pattern in Movement client tests in 690 #856

andygolay opened this issue Nov 14, 2024 · 0 comments

Comments

@andygolay
Copy link
Contributor

andygolay commented Nov 14, 2024 •
edited
Loading

Describe the bug

In #690, branch musitdev/e2e_mvt_eth_happy_path, when running Movement initiator-side tests in , there is an inconsistent pass vs failure behavior where there are sometimes two successful tests followed by constantly repeating failures, or sometimes one to all three of the Movement-side initiated transfers fail. It seems to be related to something inconsistent either in the tests or in the node.

  • Example terminal output when successfully running: DOT_MOVEMENT_PATH="$(pwd)/.movement" cargo test --test client_mvt_tests movement_client_refund_transfer -- --nocapture --test-threads=1 against a local node already running with `:
CELESTIA_LOG_LEVEL=FATAL CARGO_PROFILE=release CARGO_PROFILE_FLAGS=--release  nix develop --extra-experimental-features nix-command --extra-experimental-features flakes --command bash  -c "just bridge native build.setup.eth-local.celestia-local.bridge.bridge-indexer --keep-tui"

  • These are not the bridge logs, they are only the testing terminal output.

  • I was expecting a pattern I had previously seen where all tests pass twice and then repeatedly fail. However, now there's a sort of cyclical-seeming but I think maybe just irregular pattern. I performed the tests a few times. (See timestamps for pattern.)

  • Repeated WARN statements are removed for brevity.

Example of passing tests: This typically happens when the node first starts, all tests will pass. Sometimes there has been a pattern where all 5 tests pass twice then fail repeatedly, but I haven't been able to reproduce it.

running 5 tests
test test_movement_client_abort_transfer ... 2024-11-14T19:24:55.345789Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:25:19.382648Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_counterparty_complete_transfer ... 2024-11-14T19:25:29.988078Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:25:34.026038Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetailsCounterparty { bridge_transfer_id: BridgeTransferId([232, 230, 186, 11, 98, 206, 92, 142, 30, 180, 171, 131, 227, 77, 64, 179, 84, 171, 11, 2, 7, 172, 181, 103, 124, 207, 70, 197, 189, 116, 165, 131]), initiator_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), recipient_address: BridgeAddress(MovementAddress(3078303030303030303030303030303030303030303030303030303066616365)), hash_lock: HashLock([97, 77, 217, 241, 18, 77, 33, 153, 211, 234, 142, 64, 207, 234, 83, 182, 251, 213, 151, 46, 140, 221, 171, 244, 224, 15, 143, 64, 142, 83, 242, 105]), time_lock: TimeLock(1731612337), amount: Amount(1), state: 1 }
2024-11-14T19:25:34.026172Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_initiate_transfer ... 2024-11-14T19:25:42.105101Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:25:46.136346Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:25:46.136387Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:25:46.137120Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0xa44bd49c1f55307f5c56de58dae6d950e94edbc830a342e1461a2fbdd7d7f108"), "hash_lock": String("0xc049804ae416e027b3fa4aa0f8a4efdea8cfa2d5a571cccead9665a2f523fbf1"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:24
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([164, 75, 212, 156, 31, 85, 48, 127, 92, 86, 222, 88, 218, 230, 217, 80, 233, 78, 219, 200, 48, 163, 66, 225, 70, 26, 47, 189, 215, 215, 241, 8]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([192, 73, 128, 74, 228, 22, 224, 39, 179, 250, 74, 160, 248, 164, 239, 222, 168, 207, 162, 213, 165, 113, 204, 206, 173, 150, 101, 162, 245, 35, 251, 241]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:25:46.145608Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([164, 75, 212, 156, 31, 85, 48, 127, 92, 86, 222, 88, 218, 230, 217, 80, 233, 78, 219, 200, 48, 163, 66, 225, 70, 26, 47, 189, 215, 215, 241, 8])
ok
test test_movement_client_initiator_complete_transfer ... 2024-11-14T19:25:50.190407Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:25:54.225304Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:25:54.225367Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:25:54.226071Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0xae8902eb0fdb91ea904f5ada2cc4e4c3bad50285ef0a074a18072ca9903847cf"), "hash_lock": String("0x2dd72c2cad53191d03b7626f811f4a946d54216d2d34bf9f16d905c1102c1e4f"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:25
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([174, 137, 2, 235, 15, 219, 145, 234, 144, 79, 90, 218, 44, 196, 228, 195, 186, 213, 2, 133, 239, 10, 7, 74, 24, 7, 44, 169, 144, 56, 71, 207]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([45, 215, 44, 44, 173, 83, 25, 29, 3, 183, 98, 111, 129, 31, 74, 148, 109, 84, 33, 109, 45, 52, 191, 159, 22, 217, 5, 193, 16, 44, 30, 79]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:25:54.231941Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([174, 137, 2, 235, 15, 219, 145, 234, 144, 79, 90, 218, 44, 196, 228, 195, 186, 213, 2, 133, 239, 10, 7, 74, 24, 7, 44, 169, 144, 56, 71, 207])
Unpadded preimage: [32, 223, 71, 248, 138, 198, 15, 249, 7, 13, 180, 41, 159, 124, 134, 255, 248, 230, 39, 109, 239, 229, 60, 1, 81, 119, 76, 3, 17, 127, 251, 15]
2024-11-14T19:25:54.232044Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:25:54.735172Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health 
2024-11-14T19:25:58.269601Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([174, 137, 2, 235, 15, 219, 145, 234, 144, 79, 90, 218, 44, 196, 228, 195, 186, 213, 2, 133, 239, 10, 7, 74, 24, 7, 44, 169, 144, 56, 71, 207]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([45, 215, 44, 44, 173, 83, 25, 29, 3, 183, 98, 111, 129, 31, 74, 148, 109, 84, 33, 109, 45, 52, 191, 159, 22, 217, 5, 193, 16, 44, 30, 79]), time_lock: TimeLock(1731612363), amount: Amount(100), state: 2 }
ok
test test_movement_client_refund_transfer ... 2024-11-14T19:26:02.308192Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:26:06.343550Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:26:06.343602Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:26:06.344247Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0x7cc838bce06a7c40447c02198f4aad77128bab2e0dd1d97efaeb384e3d8c77ed"), "hash_lock": String("0x4e6d3e714dd8f1d35f23b428deeed1026638c62af903bb302bb61d4d0488449a"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:26
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([124, 200, 56, 188, 224, 106, 124, 64, 68, 124, 2, 25, 143, 74, 173, 119, 18, 139, 171, 46, 13, 209, 217, 126, 250, 235, 56, 78, 61, 140, 119, 237]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([78, 109, 62, 113, 77, 216, 241, 211, 95, 35, 180, 40, 222, 238, 209, 2, 102, 56, 198, 42, 249, 3, 187, 48, 43, 182, 29, 77, 4, 136, 68, 154]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:26:06.351718Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([124, 200, 56, 188, 224, 106, 124, 64, 68, 124, 2, 25, 143, 74, 173, 119, 18, 139, 171, 46, 13, 209, 217, 126, 250, 235, 56, 78, 61, 140, 119, 237])
14T19:26:24.688116Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
refund event data: Object {"bridge_transfer_id": String("0x7cc838bce06a7c40447c02198f4aad77128bab2e0dd1d97efaeb384e3d8c77ed")} sequence_number:7
2024-11-14T19:26:24.894866Z  INFO client_mvt_tests: Transfer details after refund: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([124, 200, 56, 188, 224, 106, 124, 64, 68, 124, 2, 25, 143, 74, 173, 119, 18, 139, 171, 46, 13, 209, 217, 126, 250, 235, 56, 78, 61, 140, 119, 237]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([78, 109, 62, 113, 77, 216, 241, 211, 95, 35, 180, 40, 222, 238, 209, 2, 102, 56, 198, 42, 249, 3, 187, 48, 43, 182, 29, 77, 4, 136, 68, 154]), time_lock: TimeLock(1731612375), amount: Amount(100), state: 3 }
ok

test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 92.58s

Example of test_movement_client_initiate_transfer and test_movement_client_initiator_complete_transfer failing

Some Movement-initiator side tests fail when running DOT_MOVEMENT_PATH="$(pwd)/.movement" cargo test --test client_mvt_tests -- --nocapture --test-threads=1

running 5 tests
test test_movement_client_abort_transfer ... 2024-11-14T19:10:48.497387Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:11:12.537075Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_counterparty_complete_transfer ... 2024-11-14T19:11:23.138897Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:11:27.181382Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetailsCounterparty { bridge_transfer_id: BridgeTransferId([123, 23, 179, 145, 243, 184, 163, 56, 53, 25, 141, 130, 56, 57, 222, 203, 191, 103, 215, 205, 75, 66, 74, 19, 82, 169, 83, 219, 49, 202, 176, 128]), initiator_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), recipient_address: BridgeAddress(MovementAddress(3078303030303030303030303030303030303030303030303030303066616365)), hash_lock: HashLock([16, 190, 189, 199, 22, 62, 83, 217, 97, 214, 87, 114, 62, 139, 179, 115, 176, 115, 151, 54, 139, 7, 233, 198, 233, 114, 109, 141, 87, 5, 4, 142]), time_lock: TimeLock(1731611491), amount: Amount(1), state: 1 }
2024-11-14T19:11:27.181542Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_initiate_transfer ... 2024-11-14T19:11:35.264342Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:11:39.301980Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:11:39.302028Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:11:39.302698Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel

thread 'test_movement_client_initiate_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:133:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
FAILED
test test_movement_client_initiator_complete_transfer ... 2024-11-14T19:12:13.855641Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:12:17.892457Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:12:17.892520Z  INFO client_mvt_tests: Wait for the Movement Initiated event.

2024-11-14T19:12:47.482428Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
thread 'test_movement_client_initiator_complete_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:276:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
FAILED
test test_movement_client_refund_transfer ... 2024-11-14T19:12:49.926430Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:12:53.955507Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:12:53.955530Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:12:53.955842Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0xc4b9ce501772b71edb3d36c3c7807cfd59fa4c512a42fb18021524094c09f39c"), "hash_lock": String("0xf375d615c403d648a54f6c2ffdf04acbd78edfe7b29b8929026c654430037180"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:17
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([196, 185, 206, 80, 23, 114, 183, 30, 219, 61, 54, 195, 199, 128, 124, 253, 89, 250, 76, 81, 42, 66, 251, 24, 2, 21, 36, 9, 76, 9, 243, 156]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([243, 117, 214, 21, 196, 3, 214, 72, 165, 79, 108, 47, 253, 240, 74, 203, 215, 142, 223, 231, 178, 155, 137, 41, 2, 108, 101, 68, 48, 3, 113, 128]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:12:53.959874Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([196, 185, 206, 80, 23, 114, 183, 30, 219, 61, 54, 195, 199, 128, 124, 253, 89, 250, 76, 81, 42, 66, 251, 24, 2, 21, 36, 9, 76, 9, 243, 156])
2024-11-14T19:12:54.462032Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
2024-11-14T19:12:54.967329Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel

2024-11-14T19:13:08.712284Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
2024-11-14T19:13:08.961858Z  INFO client_mvt_tests: Current timestamp: 1731611588
2024-11-14T19:13:08.962004Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:13:12.281627Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
refund event data: Object {"bridge_transfer_id": String("0xc4b9ce501772b71edb3d36c3c7807cfd59fa4c512a42fb18021524094c09f39c")} sequence_number:6
2024-11-14T19:13:12.501902Z  INFO client_mvt_tests: Transfer details after refund: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([196, 185, 206, 80, 23, 114, 183, 30, 219, 61, 54, 195, 199, 128, 124, 253, 89, 250, 76, 81, 42, 66, 251, 24, 2, 21, 36, 9, 76, 9, 243, 156]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([243, 117, 214, 21, 196, 3, 214, 72, 165, 79, 108, 47, 253, 240, 74, 203, 215, 142, 223, 231, 178, 155, 137, 41, 2, 108, 101, 68, 48, 3, 113, 128]), time_lock: TimeLock(1731611584), amount: Amount(100), state: 3 }
ok

failures:

failures:
    test_movement_client_initiate_transfer
    test_movement_client_initiator_complete_transfer

test result: FAILED. 3 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 146.03s

Refund failing

running 5 tests
test test_movement_client_abort_transfer ... 2024-11-14T19:34:32.518214Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:34:56.560945Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_counterparty_complete_transfer ... 2024-11-14T19:35:06.661932Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:35:10.699296Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetailsCounterparty { bridge_transfer_id: BridgeTransferId([99, 247, 11, 85, 140, 189, 4, 19, 28, 125, 23, 156, 22, 144, 157, 168, 31, 189, 223, 35, 234, 23, 251, 131, 168, 137, 130, 49, 19, 33, 205, 205]), initiator_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), recipient_address: BridgeAddress(MovementAddress(3078303030303030303030303030303030303030303030303030303066616365)), hash_lock: HashLock([178, 28, 139, 175, 34, 59, 33, 20, 231, 129, 156, 73, 161, 231, 109, 141, 79, 192, 92, 28, 68, 156, 230, 139, 75, 126, 1, 67, 58, 88, 229, 191]), time_lock: TimeLock(1731612915), amount: Amount(1), state: 1 }
2024-11-14T19:35:10.699454Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_initiate_transfer ... 2024-11-14T19:35:18.782261Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:35:22.817506Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:35:22.817555Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:35:22.818239Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0xf254730f703f868c959a9828a4ab076215b1eca711dda7fd573bab5644f06692"), "hash_lock": String("0xa03a1115c8b025021a781d388fd8c8661adfb032691c995a02600aa38794c8af"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:27
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([242, 84, 115, 15, 112, 63, 134, 140, 149, 154, 152, 40, 164, 171, 7, 98, 21, 177, 236, 167, 17, 221, 167, 253, 87, 59, 171, 86, 68, 240, 102, 146]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([160, 58, 17, 21, 200, 176, 37, 2, 26, 120, 29, 56, 143, 216, 200, 102, 26, 223, 176, 50, 105, 28, 153, 90, 2, 96, 10, 163, 135, 148, 200, 175]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:35:22.826033Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([242, 84, 115, 15, 112, 63, 134, 140, 149, 154, 152, 40, 164, 171, 7, 98, 21, 177, 236, 167, 17, 221, 167, 253, 87, 59, 171, 86, 68, 240, 102, 146])
ok
test test_movement_client_initiator_complete_transfer ... 2024-11-14T19:35:26.869383Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:35:30.905124Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:35:30.905166Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:35:30.905733Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0xeda4007145be1a5099b6f422cca0cdfdb4028f2f5779b320c312c06ed75e8ebd"), "hash_lock": String("0x1a79c56dd1c83346ac868a950ad627a1eaa1a947353746e33858a713e7d2dc3e"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:28
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([237, 164, 0, 113, 69, 190, 26, 80, 153, 182, 244, 34, 204, 160, 205, 253, 180, 2, 143, 47, 87, 121, 179, 32, 195, 18, 192, 110, 215, 94, 142, 189]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([26, 121, 197, 109, 209, 200, 51, 70, 172, 134, 138, 149, 10, 214, 39, 161, 234, 161, 169, 71, 53, 55, 70, 227, 56, 88, 167, 19, 231, 210, 220, 62]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:35:30.912053Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([237, 164, 0, 113, 69, 190, 26, 80, 153, 182, 244, 34, 204, 160, 205, 253, 180, 2, 143, 47, 87, 121, 179, 32, 195, 18, 192, 110, 215, 94, 142, 189])
Unpadded preimage: [192, 24, 131, 159, 246, 183, 175, 100, 158, 91, 124, 141, 21, 233, 246, 185, 242, 141, 30, 148, 62, 3, 240, 251, 178, 30, 49, 135, 102, 98, 254, 93]
2024-11-14T19:35:30.912156Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:35:31.414994Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
2024-11-14T19:35:34.949610Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([237, 164, 0, 113, 69, 190, 26, 80, 153, 182, 244, 34, 204, 160, 205, 253, 180, 2, 143, 47, 87, 121, 179, 32, 195, 18, 192, 110, 215, 94, 142, 189]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([26, 121, 197, 109, 209, 200, 51, 70, 172, 134, 138, 149, 10, 214, 39, 161, 234, 161, 169, 71, 53, 55, 70, 227, 56, 88, 167, 19, 231, 210, 220, 62]), time_lock: TimeLock(1731612941), amount: Amount(100), state: 2 }
ok
test test_movement_client_refund_transfer ... 2024-11-14T19:35:39.493667Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:35:43.529381Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:35:43.529432Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:35:43.530106Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel

2024-11-14T19:35:58.325628Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
thread 'test_movement_client_refund_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:351:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
FAILED

failures:

failures:
    test_movement_client_refund_transfer

test result: FAILED. 4 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 88.55s

Initiate and initiator_complete failing

running 5 tests
test test_movement_client_abort_transfer ... 2024-11-14T19:39:17.798707Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:39:41.833038Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_counterparty_complete_transfer ... 2024-11-14T19:39:52.402822Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:39:56.433153Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetailsCounterparty { bridge_transfer_id: BridgeTransferId([192, 45, 237, 108, 91, 56, 144, 208, 117, 89, 46, 29, 78, 82, 240, 193, 26, 200, 71, 131, 133, 240, 204, 146, 152, 105, 146, 107, 187, 77, 155, 11]), initiator_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), recipient_address: BridgeAddress(MovementAddress(3078303030303030303030303030303030303030303030303030303066616365)), hash_lock: HashLock([72, 216, 110, 9, 91, 247, 183, 0, 205, 70, 88, 98, 148, 55, 148, 38, 53, 140, 141, 83, 48, 72, 8, 249, 146, 53, 86, 39, 68, 160, 194, 165]), time_lock: TimeLock(1731613200), amount: Amount(1), state: 1 }
2024-11-14T19:39:56.433324Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_initiate_transfer ... 2024-11-14T19:40:04.514924Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:40:08.552593Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:40:08.552642Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:40:08.553345Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel

2024-11-14T19:40:38.124922Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
thread 'test_movement_client_initiate_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:133:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
FAILED
test test_movement_client_initiator_complete_transfer ... 2024-11-14T19:40:40.582527Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:40:44.614078Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:40:44.614129Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:40:44.614629Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel

thread 'test_movement_client_initiator_complete_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:276:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
FAILED
test test_movement_client_refund_transfer ... 2024-11-14T19:41:17.146051Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:41:21.182388Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:41:21.182436Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:41:21.183070Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0xe16d3d08a0a3b3910e6d95daa901c4aa29885434116b1d0094dea6b3f551369e"), "hash_lock": String("0x346aeafb4057643580005af1f5a822e41520df16f12b9533ba17a41686709f7e"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:32
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([225, 109, 61, 8, 160, 163, 179, 145, 14, 109, 149, 218, 169, 1, 196, 170, 41, 136, 84, 52, 17, 107, 29, 0, 148, 222, 166, 179, 245, 81, 54, 158]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([52, 106, 234, 251, 64, 87, 100, 53, 128, 0, 90, 241, 245, 168, 34, 228, 21, 32, 223, 22, 241, 43, 149, 51, 186, 23, 164, 22, 134, 112, 159, 126]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:41:21.189989Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([225, 109, 61, 8, 160, 163, 179, 145, 14, 109, 149, 218, 169, 1, 196, 170, 41, 136, 84, 52, 17, 107, 29, 0, 148, 222, 166, 179, 245, 81, 54, 158])
2024-11-14T19:41:21.692420Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel

2024-11-14T19:41:36.191698Z  INFO client_mvt_tests: Current timestamp: 1731613296
2024-11-14T19:41:36.191836Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    

2024-11-14T19:41:39.226370Z  INFO client_mvt_tests: Transfer details after refund: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([225, 109, 61, 8, 160, 163, 179, 145, 14, 109, 149, 218, 169, 1, 196, 170, 41, 136, 84, 52, 17, 107, 29, 0, 148, 222, 166, 179, 245, 81, 54, 158]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([52, 106, 234, 251, 64, 87, 100, 53, 128, 0, 90, 241, 245, 168, 34, 228, 21, 32, 223, 22, 241, 43, 149, 51, 186, 23, 164, 22, 134, 112, 159, 126]), time_lock: TimeLock(1731613290), amount: Amount(100), state: 3 }
ok

failures:

failures:
    test_movement_client_initiate_transfer
    test_movement_client_initiator_complete_transfer

test result: FAILED. 3 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 143.95s

Only 1 failure but it's complete instead of refund

running 5 tests
test test_movement_client_abort_transfer ... 2024-11-14T19:43:32.584464Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:43:56.626506Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_counterparty_complete_transfer ... 2024-11-14T19:44:07.228672Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:44:11.269901Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetailsCounterparty { bridge_transfer_id: BridgeTransferId([196, 123, 35, 12, 102, 93, 166, 243, 45, 64, 58, 127, 100, 57, 173, 68, 207, 93, 90, 120, 193, 172, 14, 250, 175, 52, 21, 144, 233, 90, 125, 214]), initiator_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), recipient_address: BridgeAddress(MovementAddress(3078303030303030303030303030303030303030303030303030303066616365)), hash_lock: HashLock([232, 67, 24, 201, 212, 45, 85, 89, 151, 170, 55, 246, 24, 36, 47, 107, 177, 93, 157, 193, 114, 14, 60, 29, 128, 166, 205, 97, 19, 171, 246, 92]), time_lock: TimeLock(1731613455), amount: Amount(1), state: 1 }
2024-11-14T19:44:11.270067Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_initiate_transfer ... 2024-11-14T19:44:19.346664Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:44:23.381569Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:44:23.381622Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:44:23.382378Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0xc5cc22845927f809209ccccc44ecc6604aa73fc8f11d80cf4ca4da458f75cbe7"), "hash_lock": String("0xea8b7901f39889ea892441a9af3981d5517d0d75bddb624a2ff5e3a1dd54020d"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:33
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([197, 204, 34, 132, 89, 39, 248, 9, 32, 156, 204, 204, 68, 236, 198, 96, 74, 167, 63, 200, 241, 29, 128, 207, 76, 164, 218, 69, 143, 117, 203, 231]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([234, 139, 121, 1, 243, 152, 137, 234, 137, 36, 65, 169, 175, 57, 129, 213, 81, 125, 13, 117, 189, 219, 98, 74, 47, 245, 227, 161, 221, 84, 2, 13]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:44:23.389873Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([197, 204, 34, 132, 89, 39, 248, 9, 32, 156, 204, 204, 68, 236, 198, 96, 74, 167, 63, 200, 241, 29, 128, 207, 76, 164, 218, 69, 143, 117, 203, 231])
ok
test test_movement_client_initiator_complete_transfer ... 2024-11-14T19:44:27.434427Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:44:31.470053Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:44:31.470110Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:44:31.470743Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel

thread 'test_movement_client_initiator_complete_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:276:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
FAILED
test test_movement_client_refund_transfer ... 2024-11-14T19:45:03.503508Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:45:07.540251Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:45:07.540298Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:45:07.540932Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0x5b5060debffd802c780e394995d240d6335f9f98e90bb3f6776965656be4a9f1"), "hash_lock": String("0x2590e639d9ae5e0531241e7e278adc15bf0124c762d96567934839fd1d299480"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:35
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([91, 80, 96, 222, 191, 253, 128, 44, 120, 14, 57, 73, 149, 210, 64, 214, 51, 95, 159, 152, 233, 11, 179, 246, 119, 105, 101, 101, 107, 228, 169, 241]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([37, 144, 230, 57, 217, 174, 94, 5, 49, 36, 30, 126, 39, 138, 220, 21, 191, 1, 36, 199, 98, 217, 101, 103, 147, 72, 57, 253, 29, 41, 148, 128]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:45:07.547790Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([91, 80, 96, 222, 191, 253, 128, 44, 120, 14, 57, 73, 149, 210, 64, 214, 51, 95, 159, 152, 233, 11, 179, 246, 119, 105, 101, 101, 107, 228, 169, 241])
2024-11-14T19:45:08.050213Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel

refund event data: Object {"bridge_transfer_id": String("0x5b5060debffd802c780e394995d240d6335f9f98e90bb3f6776965656be4a9f1")} sequence_number:9
2024-11-14T19:45:26.084480Z  INFO client_mvt_tests: Transfer details after refund: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([91, 80, 96, 222, 191, 253, 128, 44, 120, 14, 57, 73, 149, 210, 64, 214, 51, 95, 159, 152, 233, 11, 179, 246, 119, 105, 101, 101, 107, 228, 169, 241]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([37, 144, 230, 57, 217, 174, 94, 5, 49, 36, 30, 126, 39, 138, 220, 21, 191, 1, 36, 199, 98, 217, 101, 103, 147, 72, 57, 253, 29, 41, 148, 128]), time_lock: TimeLock(1731613518), amount: Amount(100), state: 3 }
ok

failures:

failures:
    test_movement_client_initiator_complete_transfer

test result: FAILED. 4 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 116.54s

Initiate and refund failing

running 5 tests
test test_movement_client_abort_transfer ... 2024-11-14T19:47:05.117508Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:47:29.175351Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_counterparty_complete_transfer ... 2024-11-14T19:47:39.777849Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:47:43.817616Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetailsCounterparty { bridge_transfer_id: BridgeTransferId([137, 59, 238, 2, 42, 163, 115, 42, 188, 149, 95, 35, 56, 116, 179, 159, 218, 170, 16, 247, 18, 220, 56, 239, 139, 218, 39, 54, 137, 151, 153, 52]), initiator_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), recipient_address: BridgeAddress(MovementAddress(3078303030303030303030303030303030303030303030303030303066616365)), hash_lock: HashLock([13, 148, 93, 212, 239, 134, 92, 33, 48, 235, 27, 22, 56, 236, 40, 87, 12, 28, 99, 204, 65, 243, 110, 2, 41, 238, 109, 111, 200, 3, 106, 90]), time_lock: TimeLock(1731613667), amount: Amount(1), state: 1 }
2024-11-14T19:47:43.817728Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_initiate_transfer ... 2024-11-14T19:47:51.889879Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:47:55.926378Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:47:55.926426Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:48:25.545702Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
thread 'test_movement_client_initiate_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:133:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
FAILED
test test_movement_client_initiator_complete_transfer ... 2024-11-14T19:48:27.958472Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:48:31.995998Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:48:31.996056Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:48:31.996669Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0x4f45f1c8c1d2f0dd9d9685ce29dfb1b605011f5d488ca36172a92f4d6bca9b35"), "hash_lock": String("0xb918353bbbc57b120eced18d8aec3c4b994633907059d663776e4a50fe820120"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:37
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([79, 69, 241, 200, 193, 210, 240, 221, 157, 150, 133, 206, 41, 223, 177, 182, 5, 1, 31, 93, 72, 140, 163, 97, 114, 169, 47, 77, 107, 202, 155, 53]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([185, 24, 53, 59, 187, 197, 123, 18, 14, 206, 209, 141, 138, 236, 60, 75, 153, 70, 51, 144, 112, 89, 214, 99, 119, 110, 74, 80, 254, 130, 1, 32]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:48:32.003226Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([79, 69, 241, 200, 193, 210, 240, 221, 157, 150, 133, 206, 41, 223, 177, 182, 5, 1, 31, 93, 72, 140, 163, 97, 114, 169, 47, 77, 107, 202, 155, 53])
Unpadded preimage: [233, 38, 92, 142, 125, 110, 3, 105, 231, 78, 70, 213, 3, 248, 137, 93, 29, 95, 0, 190, 194, 36, 42, 29, 190, 142, 43, 173, 113, 122, 109, 183]
2024-11-14T19:48:32.003330Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:48:35.567910Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
2024-11-14T19:48:36.041007Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([79, 69, 241, 200, 193, 210, 240, 221, 157, 150, 133, 206, 41, 223, 177, 182, 5, 1, 31, 93, 72, 140, 163, 97, 114, 169, 47, 77, 107, 202, 155, 53]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([185, 24, 53, 59, 187, 197, 123, 18, 14, 206, 209, 141, 138, 236, 60, 75, 153, 70, 51, 144, 112, 89, 214, 99, 119, 110, 74, 80, 254, 130, 1, 32]), time_lock: TimeLock(1731613722), amount: Amount(100), state: 2 }
ok
test test_movement_client_refund_transfer ... 2024-11-14T19:48:40.583010Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:48:44.617864Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:48:44.617916Z  INFO client_mvt_tests: Wait for the Movement Initiated event.

thread 'test_movement_client_refund_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:351:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
FAILED

failures:

failures:
    test_movement_client_initiate_transfer
    test_movement_client_refund_transfer

test result: FAILED. 3 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 117.01s

Only Initiate failing

running 5 tests
test test_movement_client_abort_transfer ... 2024-11-14T19:50:39.729359Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:51:03.774586Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_counterparty_complete_transfer ... 2024-11-14T19:51:14.385319Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:51:18.422700Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetailsCounterparty { bridge_transfer_id: BridgeTransferId([162, 234, 97, 186, 54, 55, 99, 194, 46, 184, 55, 183, 6, 54, 153, 98, 159, 179, 77, 78, 115, 197, 189, 252, 211, 184, 190, 18, 224, 194, 79, 144]), initiator_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), recipient_address: BridgeAddress(MovementAddress(3078303030303030303030303030303030303030303030303030303066616365)), hash_lock: HashLock([135, 245, 72, 13, 20, 170, 69, 113, 218, 5, 69, 1, 235, 59, 8, 138, 39, 244, 140, 106, 6, 46, 129, 124, 201, 198, 28, 22, 172, 206, 216, 219]), time_lock: TimeLock(1731613881), amount: Amount(1), state: 1 }
2024-11-14T19:51:18.422833Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
ok
test test_movement_client_initiate_transfer ... 2024-11-14T19:51:26.496762Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:51:30.529520Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:51:30.529568Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
00.108472Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
thread 'test_movement_client_initiate_transfer' panicked at protocol-units/bridge/integration-tests/tests/client_mvt_tests.rs:133:10:
Timeout while waiting for the Movement Initiated event: Elapsed(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
FAILED
test test_movement_client_initiator_complete_transfer ... 2024-11-14T19:52:02.561037Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:52:06.598039Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:52:06.598116Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:52:06.598693Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0xeb3168da5667a09e42e68a80893c7f3cc04d361ab181c5565c21735526b4d75f"), "hash_lock": String("0x8b940d655c7fd6b620c8f7bbb5c25b81f305ce5766532bbf489217e9a7d6c496"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:40
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([235, 49, 104, 218, 86, 103, 160, 158, 66, 230, 138, 128, 137, 60, 127, 60, 192, 77, 54, 26, 177, 129, 197, 86, 92, 33, 115, 85, 38, 180, 215, 95]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([139, 148, 13, 101, 92, 127, 214, 182, 32, 200, 247, 187, 181, 194, 91, 129, 243, 5, 206, 87, 102, 83, 43, 191, 72, 146, 23, 233, 167, 214, 196, 150]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:52:06.605009Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([235, 49, 104, 218, 86, 103, 160, 158, 66, 230, 138, 128, 137, 60, 127, 60, 192, 77, 54, 26, 177, 129, 197, 86, 92, 33, 115, 85, 38, 180, 215, 95])
Unpadded preimage: [243, 120, 157, 106, 157, 9, 188, 173, 103, 101, 252, 235, 87, 223, 211, 116, 164, 93, 195, 36, 184, 7, 135, 226, 97, 27, 68, 210, 70, 104, 124, 146]
2024-11-14T19:52:06.605109Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    

2024-11-14T19:52:10.168263Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
2024-11-14T19:52:10.643026Z  INFO client_mvt_tests: Bridge transfer details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([235, 49, 104, 218, 86, 103, 160, 158, 66, 230, 138, 128, 137, 60, 127, 60, 192, 77, 54, 26, 177, 129, 197, 86, 92, 33, 115, 85, 38, 180, 215, 95]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([139, 148, 13, 101, 92, 127, 214, 182, 32, 200, 247, 187, 181, 194, 91, 129, 243, 5, 206, 87, 102, 83, 43, 191, 72, 146, 23, 233, 167, 214, 196, 150]), time_lock: TimeLock(1731613936), amount: Amount(100), state: 2 }
ok
test test_movement_client_refund_transfer ... 2024-11-14T19:52:14.682192Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    
2024-11-14T19:52:18.718172Z  INFO client_mvt_tests: Initiate result: ()
2024-11-14T19:52:18.718223Z  INFO client_mvt_tests: Wait for the Movement Initiated event.
2024-11-14T19:52:18.718884Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
Initiate event data: Object {"amount": String("100"), "bridge_transfer_id": String("0x1a551a6fa5827bd80e16ea995abd5baf91e9fd0d4ff318cfdfe672690884e0e3"), "hash_lock": String("0xa79110c0b6c8e5eef5c5343271ce6179685f029cf9e23871068787fc74bc475c"), "initiator": String("0xf90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16"), "recipient": String("0x33324265333433423934663836303132346443346645653237384644434244333843313032443838"), "time_lock": String("11")} sequence_number:41
Initiate event transfer_details: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([26, 85, 26, 111, 165, 130, 123, 216, 14, 22, 234, 153, 90, 189, 91, 175, 145, 233, 253, 13, 79, 243, 24, 207, 223, 230, 114, 105, 8, 132, 224, 227]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([167, 145, 16, 192, 182, 200, 229, 238, 245, 197, 52, 50, 113, 206, 97, 121, 104, 95, 2, 156, 249, 226, 56, 113, 6, 135, 135, 252, 116, 188, 71, 92]), time_lock: TimeLock(11), amount: Amount(100), state: 0 }
2024-11-14T19:52:18.725770Z  INFO client_mvt_tests: Received bridge_transfer_id: BridgeTransferId([26, 85, 26, 111, 165, 130, 123, 216, 14, 22, 234, 153, 90, 189, 91, 175, 145, 233, 253, 13, 79, 243, 24, 207, 223, 230, 114, 105, 8, 132, 224, 227])

2024-11-14T19:52:33.728204Z  INFO client_mvt_tests: Current timestamp: 1731613953
2024-11-14T19:52:33.728340Z  INFO bridge_service::chains::movement::utils: Starting send_aptos_transaction    

2024-11-14T19:52:37.077483Z  WARN bridge_service::chains::movement::event_monitoring: Check Mvt monitoring loop health channel error: receiving on a closed channel
refund event data: Object {"bridge_transfer_id": String("0x1a551a6fa5827bd80e16ea995abd5baf91e9fd0d4ff318cfdfe672690884e0e3")} sequence_number:10
2024-11-14T19:52:37.263952Z  INFO client_mvt_tests: Transfer details after refund: BridgeTransferDetails { bridge_transfer_id: BridgeTransferId([26, 85, 26, 111, 165, 130, 123, 216, 14, 22, 234, 153, 90, 189, 91, 175, 145, 233, 253, 13, 79, 243, 24, 207, 223, 230, 114, 105, 8, 132, 224, 227]), initiator_address: BridgeAddress(MovementAddress(f90391c81027f03cdea491ed8b36ffaced26b6df208a9b569e5baf2590eb9b16)), recipient_address: BridgeAddress([51, 50, 66, 101, 51, 52, 51, 66, 57, 52, 102, 56, 54, 48, 49, 50, 52, 100, 67, 52, 102, 69, 101, 50, 55, 56, 70, 68, 67, 66, 68, 51, 56, 67, 49, 48, 50, 68, 56, 56]), hash_lock: HashLock([167, 145, 16, 192, 182, 200, 229, 238, 245, 197, 52, 50, 113, 206, 97, 121, 104, 95, 2, 156, 249, 226, 56, 113, 6, 135, 135, 252, 116, 188, 71, 92]), time_lock: TimeLock(1731613948), amount: Amount(100), state: 3 }
ok

failures:

failures:
    test_movement_client_initiate_transfer

test result: FAILED. 4 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 119.59s

After that, all tests passed again.

To Reproduce

  1. Run local node with
CELESTIA_LOG_LEVEL=FATAL CARGO_PROFILE=release CARGO_PROFILE_FLAGS=--release  nix develop --extra-experimental-features nix-command --extra-experimental-features flakes --command bash  -c "just bridge native build.setup.eth-local.celestia-local.bridge.bridge-indexer --keep-tui"
  1. Repeatedly run DOT_MOVEMENT_PATH="$(pwd)/.movement" cargo test --test client_mvt_tests -- --nocapture --test-threads=1 against the musitdev/e2e_mvt_eth_happy_path branch

Expected behavior
All tests should always pass.

Additional context

  • Movement -> Eth E2E Test Errors #831 contains details about failures in E2E tests that appear to potentially be related. From what I can tell this may be related to the event monitoring somehow failing to pick up events. I'm not sure. Any insight is appreciated.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@andygolay