fix(orders): fix cancel order race condition using time-based cache #2232

shamardy · 2024-09-28T08:40:11Z

This PR addresses the issue where cancelled orders can sometimes remain in the orderbook due to P2P message caching and out-of-order message delivery.

Changes:

Added a time-based cache to orderbook to track recently cancelled orders
Modified order processing logic to check the cancellation cache before processing create maker order messages.
Set cache expiration time to 2 minutes, exceeding the 1-minute gossipsub cache to ensure coverage of delayed messages.
Added maker_order_cancelled_p2p_notify to a location where it was previously missing, this needs careful review. Old PR that added the maker order deletion without notifying Fix orders "leak" due to race condition. #1178 and the reason for the old PR order leakage #1173 (comment)

The solution works as follows:

When an order is cancelled, its UUID is added to the cancellation cache with a 2 minutes expiration time.
Incoming create maker order messages are checked against the cache before processing.
If a matching UUID is found in the cache and the pubkey is the maker pubkey, the create maker order message is ignored.
Cache entries expire after 2 minutes to reduce memory usage.

This approach provides a simple fix for the immediate issue while avoiding major changes to the P2P layer or gossipsub protocol. It prevents cancelled orders from reappearing in the orderbook due to delayed or out-of-order message delivery.

Next steps:

Monitor for any new issues related to P2P message ordering.
Consider more comprehensive solutions for ensuring message ordering if needed in the future.

potentially fixes #1726

mariocynicys

took a quick look and tried the fix on the electrum connections branch (since it exemplifies the issue 1000x for some reason).

I fear though that nodes don't receive messages at the same time and we have some node getting the message AFTER (because some other node received the cancellation late enough that it's still in its gossibpub cache) the cancellation cache timed out and it would consider it a new order creation.

can't we enforce in-order-delivery somehow on p2p layer? or at leas t only causal delivery.

mm2src/common/expirable_map.rs

mm2src/mm2_main/tests/mm2_tests/mm2_tests_inner.rs

mm2src/mm2_main/src/lp_ordermatch.rs

mm2src/common/expirable_map.rs

shamardy · 2024-10-01T08:16:59Z

Received this message from @cipig

i run 2 nodes with this PR, the last commits are missing. I noticed that those 2 nodes showed this
30 22:00:01, mm2_p2p::behaviours::atomicdex:324] ERROR notify_on_adex_event error send failed because channel is full
30 22:00:01, mm2_p2p::behaviours::atomicdex:324] ERROR notify_on_adex_event error send failed because channel is full
30 22:00:01, mm2_p2p::behaviours::atomicdex:324] ERROR notify_on_adex_event error send failed because channel is full
30 22:00:05, libp2p_gossipsub::behaviour:3415] INFO HEARTBEAT: relays low. Contains: 0 needs: 2
at the same time, while the other nodes didn't
question is if the changes increase the probability of this to happen

Will look into it after fixing the review comments

shamardy · 2024-10-01T08:45:36Z

About this #2232 (comment) , only reason for delay is holding the orderbook lock for some time, I can move the new recently cancelled map to OrdermatchContext instead with its own lock to reduce the delay.

onur-ozkan · 2024-10-01T08:46:32Z

Received this message from @cipig
i run 2 nodes with this PR, the last commits are missing. I noticed that those 2 nodes showed this
30 22:00:01, mm2_p2p::behaviours::atomicdex:324] ERROR notify_on_adex_event error send failed because channel is full
30 22:00:01, mm2_p2p::behaviours::atomicdex:324] ERROR notify_on_adex_event error send failed because channel is full
30 22:00:01, mm2_p2p::behaviours::atomicdex:324] ERROR notify_on_adex_event error send failed because channel is full
30 22:00:05, libp2p_gossipsub::behaviour:3415] INFO HEARTBEAT: relays low. Contains: 0 needs: 2
at the same time, while the other nodes didn't
question is if the changes increase the probability of this to happen
Will look into it after fixing the review comments

How is this PR related with those logs 🤔

shamardy · 2024-10-01T08:49:00Z

About this #2232 (comment) , only reason for delay is holding the orderbook lock for some time, I can move the new recently cancelled map to OrdermatchContext instead with its own lock to reduce the delay.

How is this PR related with those logs 🤔

I can see that process_msg is async, so you are right, it shouldn't affect messages buffer. But I should add this optimization nonetheless.

Edit: the log ERROR notify_on_adex_event error send failed because channel is full is related to the tx part of the channel, so it's not related to process_msg or this PR at all. Sorry for the confusion.

…Context`

shamardy · 2024-10-01T09:05:30Z

I can move the new recently cancelled map to OrdermatchContext instead with its own lock to reduce the delay.

Done here 14f7f34

shamardy · 2024-10-01T10:21:28Z

@onur-ozkan @mariocynicys all issues raised in review comments should have been fixed. Please give this another look when you have the time.

onur-ozkan

Last notes from my side:

mm2src/mm2_main/src/lp_ordermatch.rs

mm2src/mm2_main/tests/mm2_tests/mm2_tests_inner.rs

mm2src/mm2_main/src/lp_ordermatch.rs

mm2src/common/expirable_map.rs

shamardy · 2024-10-02T06:32:50Z

only reason for delay is holding the orderbook lock for some time, I can move the new recently cancelled map to OrdermatchContext instead with its own lock to reduce the delay.

Sorry about more confusion I am about to create @mariocynicys @onur-ozkan but I will move recently cancelled map back to orderbook struct and handle it in both insert_or_update_order_update_trie and delete_order where it's already locked. I was reluctant to do that at first since recently cancelled will be checked when order is being added by means other than maker order created message but once cancel order message is broadcasted an order shouldn't be added by any means whether through creation message or pubkey sync.

…dermatchContext`" This reverts commit 14f7f34.

…etter place

shamardy · 2024-10-02T07:19:31Z

Reverted the moving of recently cancelled to it's own lock here e0e5d41 and fixed this #2232 (comment) here cdfd809.

mm2src/coins/eth/web3_transport/websocket_transport.rs

mm2src/mm2_core/src/data_asker.rs

shamardy · 2024-10-02T07:46:05Z

Now test_cancel_all_orders fails after the latest additions 😩

shamardy · 2024-10-02T07:54:34Z

Now test_cancel_all_orders fails after the latest additions

I understand why, will fix it. The below claim

komodo-defi-framework/mm2src/mm2_main/src/lp_ordermatch.rs

Lines 380 to 381 in 860544f

    
           // We only do this if the order is not in the order_set, because if it is, it means that the order was already 
        
           // created and messages did arrive in the correct order

is not right as we can receive it through orderbook call and receive order creation message later.

mm2src/common/expirable_map.rs

…r_expired_entries` function

…ellation_received_before_creation`

onur-ozkan

Final notes from my side, LGTM other than these notes:

mm2src/mm2_main/src/lp_ordermatch.rs

mariocynicys

Last points, LGTM otherwise :)

mm2src/mm2_main/tests/mm2_tests/orderbook_sync_tests.rs

…creation`

mariocynicys

LGTM

mm2src/mm2_core/Cargo.toml

* dev: fix(orders): fix cancel order race condition using time-based cache (#2232) fix(legacy-swap): taker failed spend maker payment marked as failed (#2199) chore(adex-cli): deprecate adex-cli (#2234) feat(new-RPC): connection healthcheck implementation for peers (#2194) fix(proxy-signature): add message lifetime overflows (#2233) feat(CI): handle remote files in a safer way (#2217) chore(doc): update issue address in README (#2227) fix(merge): remove duplicated db_root function (#2229) feat(wallets): add `get_wallet_names` rpc (#2202) chore(tests): don't use `.wait()` and use `block_on` instead (#2220) fix(native-rpc): remove escaped response body (#2219) fix(clippy): fix coins mod clippy warnings in wasm (#2224) feat(core): handling CTRL-C signal with graceful shutdown (#2213) docs(README): fix typos (#2212) remove the non-sense arguments (#2216) fix(db): stop creating the all-zeroes dir on KDF start (#2218)

* dev: fix(cosmos): fix tx broadcasting error (#2238) chore(solana): remove solana implementation (#2239) chore(cli): remove leftover subcommands from help message (#2235) fix(orders): fix cancel order race condition using time-based cache (#2232) fix(legacy-swap): taker failed spend maker payment marked as failed (#2199) chore(adex-cli): deprecate adex-cli (#2234) feat(new-RPC): connection healthcheck implementation for peers (#2194) fix(proxy-signature): add message lifetime overflows (#2233) feat(CI): handle remote files in a safer way (#2217) chore(doc): update issue address in README (#2227) fix(merge): remove duplicated db_root function (#2229) feat(wallets): add `get_wallet_names` rpc (#2202) chore(tests): don't use `.wait()` and use `block_on` instead (#2220) fix(native-rpc): remove escaped response body (#2219) fix(clippy): fix coins mod clippy warnings in wasm (#2224) feat(core): handling CTRL-C signal with graceful shutdown (#2213) docs(README): fix typos (#2212) remove the non-sense arguments (#2216) fix(db): stop creating the all-zeroes dir on KDF start (#2218)

add recently cancelled orders time cache to orderbook

6ad60e9

shamardy added the in progress Changes will be made from the author label Sep 28, 2024

shamardy changed the title ~~fix(orders): Fix order cancellation race condition using time-based cache~~ fix(orders): fix order cancellation race condition using time-based cache Sep 28, 2024

shamardy changed the title ~~fix(orders): fix order cancellation race condition using time-based cache~~ fix(orders): fix cancel order race condition using time-based cache Sep 28, 2024

revert test_cancel_order changes

232019b

shamardy added under review and removed in progress Changes will be made from the author labels Sep 28, 2024

shamardy requested a review from mariocynicys September 28, 2024 09:41

mariocynicys reviewed Sep 28, 2024

View reviewed changes

mm2src/common/expirable_map.rs Show resolved Hide resolved

mm2src/mm2_main/tests/mm2_tests/mm2_tests_inner.rs Outdated Show resolved Hide resolved

review fix: cherry-pick 62d26c7

1c38da7

onur-ozkan reviewed Sep 30, 2024

View reviewed changes

mm2src/mm2_main/src/lp_ordermatch.rs Outdated Show resolved Hide resolved

mm2src/mm2_main/src/lp_ordermatch.rs Outdated Show resolved Hide resolved

mm2src/common/expirable_map.rs Show resolved Hide resolved

shamardy added 3 commits September 30, 2024 12:04

optimize clear_expired_entries

da884fc

provide a consistent interface for ExpirableMap

5762d13

use Copy type parameter instead of Clone in ExpirableMap

f2ef6d3

laruh mentioned this pull request Oct 1, 2024

check status of peers in kdf network KomodoPlatform/komodo-defi-proxy#25

Merged

make test_cancel_all_orders not rely on the order of messages

87c53f8

shamardy added 2 commits October 1, 2024 11:19

Make RECENTLY_CANCELLED_TIMEOUT Duration Type

5591f89

use ctx as reference in maker_order_cancelled_p2p_notify

69fdfe9

move recently_cancelled time cache to it's own mutex in `Ordermatch…

14f7f34

…Context`

onur-ozkan reviewed Oct 1, 2024

View reviewed changes

shamardy added 2 commits October 2, 2024 09:36

Revert "move recently_cancelled time cache to it's own mutex in `Or…

e0e5d41

…dermatchContext`" This reverts commit 14f7f34.

move recently cancelled back to orderbook struct and handle it in a b…

cdfd809

…etter place

mariocynicys reviewed Oct 2, 2024

View reviewed changes

mm2src/coins/eth/web3_transport/websocket_transport.rs Show resolved Hide resolved

mm2src/coins/eth/web3_transport/websocket_transport.rs Show resolved Hide resolved

mm2src/mm2_core/src/data_asker.rs Show resolved Hide resolved

shamardy added 3 commits October 2, 2024 11:02

add order to recently_cancelled even if it was in the order_set

20fa7e5

review fix: add implementation details to clear_expired_entries

d2675d2

review fix: check expiry on remove as well

abfb252

mariocynicys reviewed Oct 2, 2024

View reviewed changes

mm2src/common/expirable_map.rs Outdated Show resolved Hide resolved

shamardy added 3 commits October 2, 2024 13:24

review fix: move implementation details to a comment inside the `clea…

5a839be

…r_expired_entries` function

revert test_cancel_all_orders to dev state and add `test_order_canc…

598045d

…ellation_received_before_creation`

fix clippy

9faa804

shamardy mentioned this pull request Oct 3, 2024

feat(new-RPC): connection healthcheck implementation for peers #2194

Merged

4 tasks

onur-ozkan previously approved these changes Oct 3, 2024

View reviewed changes

mm2src/mm2_main/src/lp_ordermatch.rs Outdated Show resolved Hide resolved

mm2src/mm2_main/src/lp_ordermatch.rs Outdated Show resolved Hide resolved

mm2src/mm2_main/src/lp_ordermatch.rs Show resolved Hide resolved

review fix: remove return types from some functions that don't need them

158252c

shamardy dismissed onur-ozkan’s stale review via 158252c October 3, 2024 08:04

shamardy mentioned this pull request Oct 3, 2024

feat(utxo): prioritize electrum connections #1966

Merged

mariocynicys reviewed Oct 3, 2024

View reviewed changes

mm2src/mm2_main/tests/mm2_tests/orderbook_sync_tests.rs Outdated Show resolved Hide resolved

mm2src/mm2_main/tests/mm2_tests/orderbook_sync_tests.rs Outdated Show resolved Hide resolved

shamardy added 4 commits October 3, 2024 17:57

review fix: fix comments in `test_order_cancellation_received_before_…

ff54b83

…creation`

Merge remote-tracking branch 'origin/dev' into fix-p2p-cancellation

3f0a6bd

reorder imports after merge

b1cae0f

remove adex-cli CI workflow

9dd4544

mariocynicys previously approved these changes Oct 4, 2024

View reviewed changes

mm2src/mm2_core/Cargo.toml Outdated Show resolved Hide resolved

shamardy added 2 commits October 4, 2024 13:51

update mm2_libp2p dependency name for consistency

d55efc3

Merge remote-tracking branch 'origin/dev' into fix-p2p-cancellation

1e6bbb8

shamardy dismissed mariocynicys’s stale review via 1e6bbb8 October 4, 2024 10:51

shamardy merged commit ce18376 into dev Oct 4, 2024
22 of 23 checks passed

shamardy deleted the fix-p2p-cancellation branch October 4, 2024 11:21

shamardy mentioned this pull request Nov 19, 2024

chore(release): v2.2.0-beta #2197

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix(orders): fix cancel order race condition using time-based cache #2232

fix(orders): fix cancel order race condition using time-based cache #2232

shamardy commented Sep 28, 2024 •

edited

Loading

mariocynicys left a comment

shamardy commented Oct 1, 2024

shamardy commented Oct 1, 2024 •

edited

Loading

onur-ozkan commented Oct 1, 2024

shamardy commented Oct 1, 2024 •

edited

Loading

shamardy commented Oct 1, 2024

shamardy commented Oct 1, 2024

onur-ozkan left a comment

shamardy commented Oct 2, 2024

shamardy commented Oct 2, 2024

shamardy commented Oct 2, 2024

shamardy commented Oct 2, 2024

onur-ozkan left a comment

mariocynicys left a comment

mariocynicys left a comment

fix(orders): fix cancel order race condition using time-based cache #2232

fix(orders): fix cancel order race condition using time-based cache #2232

Conversation

shamardy commented Sep 28, 2024 • edited Loading

mariocynicys left a comment

Choose a reason for hiding this comment

shamardy commented Oct 1, 2024

shamardy commented Oct 1, 2024 • edited Loading

onur-ozkan commented Oct 1, 2024

shamardy commented Oct 1, 2024 • edited Loading

shamardy commented Oct 1, 2024

shamardy commented Oct 1, 2024

onur-ozkan left a comment

Choose a reason for hiding this comment

shamardy commented Oct 2, 2024

shamardy commented Oct 2, 2024

shamardy commented Oct 2, 2024

shamardy commented Oct 2, 2024

onur-ozkan left a comment

Choose a reason for hiding this comment

mariocynicys left a comment

Choose a reason for hiding this comment

mariocynicys left a comment

Choose a reason for hiding this comment

shamardy commented Sep 28, 2024 •

edited

Loading

shamardy commented Oct 1, 2024 •

edited

Loading

shamardy commented Oct 1, 2024 •

edited

Loading