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.

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

Order is not returned back to order book of taker after no route err #1816

Closed
raladev opened this issue Aug 17, 2020 · 1 comment · Fixed by #1830
Closed

Order is not returned back to order book of taker after no route err #1816

raladev opened this issue Aug 17, 2020 · 1 comment · Fixed by #1830
Assignees
Labels
bug Something isn't working order book P1 top priority swaps

Comments

@raladev
Copy link
Contributor

raladev commented Aug 17, 2020

Steps:

  1. Place ETH/LTC order as a maker
  2. try to fill it as a taker - > no route error
  3. wait 1 min / 3 min / 5 min

Actual result:
Maker's order is not returned back to Taker's orderbook

Expected result:
Maker's order is returned back to Taker's orderbook after some time

Logs:

17/08/2020 10:33:54.410 [RPC] debug: received call /xudrpc.Xud/PlaceOrder
17/08/2020 10:33:54.410 [ORDERBOOK] debug: removed order e1c5db90-e074-11ea-b568-59ce54a73c83 while matching order 2626e4a0-e075-11ea-9afa-610bda093e3d
17/08/2020 10:33:54.411 [ORDERBOOK] debug: matched with peer 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase), executing swap on taker 2626e4a0-e075-11ea-9afa-610bda093e3d and maker e1c5db90-e074-11ea-b568-59ce54a73c83 for 10000
17/08/2020 10:33:54.413 [DB] trace: Executing (default): SELECT `id`, `nodeId`, `localId`, `initialQuantity`, `pairId`, `price`, `isBuy`, `createdAt` FROM `orders` AS `Order` WHERE `Order`.`id` = 'e1c5db90-e074-11ea-b568-59ce54a73c83';
17/08/2020 10:33:54.415 [DB] trace: Executing (default): INSERT INTO `orders` (`id`,`nodeId`,`initialQuantity`,`pairId`,`price`,`isBuy`,`createdAt`) VALUES ($1,$2,$3,$4,$5,$6,$7);
17/08/2020 10:33:54.423 [BACKUP] trace: xud database changed
17/08/2020 10:33:54.425 [SWAPS] debug: New deal: {"takerCltvDelta":576,"rHash":"64a3272877ab4c0d879d44f77a92ac853ff6295e5c86eedef9f6be3231e4ef69","orderId":"e1c5db90-e074-11ea-b568-59ce54a73c83","pairId":"ETH/LTC","proposedQuantity":10000,"rPreimage":"bbddeac34b50ca27168cc6af9b6771e154c4c53208acb68a03048db59d5a1b3d","takerCurrency":"LTC","makerCurrency":"ETH","takerAmount":300,"makerAmount":10000,"takerUnits":300,"makerUnits":100000000000000,"destination":"indra7NFTNY144ZSUcNXinwaw9ushGtfvvRi4PUf7S6v9tCKNDrargJ","peerPubKey":"02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a","localId":"2626e4a0-e075-11ea-9afa-610bda093e3d","price":0.03,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1597660434424}
17/08/2020 10:33:54.427 [P2P] trace: Sent SwapRequest packet to 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): "{\"body\":{\"orderId\":\"e1c5db90-e074-11ea-b568-59ce54a73c83\",\"pairId\":\"ETH/LTC\",\"proposedQuantity\":10000,\"rHash\":\"64a3272877ab4c0d879d44f77a92ac853ff6295e5c86eedef9f6be3231e4ef69\",\"takerCltvDelta\":576},\"header\":{\"id\":\"26292e90-e075-11ea-9afa-610bda093e3d\"}}"
17/08/2020 10:33:54.427 [SWAPS] debug: Requesting deal: {"takerCltvDelta":576,"rHash":"64a3272877ab4c0d879d44f77a92ac853ff6295e5c86eedef9f6be3231e4ef69","orderId":"e1c5db90-e074-11ea-b568-59ce54a73c83","pairId":"ETH/LTC","proposedQuantity":10000,"rPreimage":"bbddeac34b50ca27168cc6af9b6771e154c4c53208acb68a03048db59d5a1b3d","takerCurrency":"LTC","makerCurrency":"ETH","takerAmount":300,"makerAmount":10000,"takerUnits":300,"makerUnits":100000000000000,"destination":"indra7NFTNY144ZSUcNXinwaw9ushGtfvvRi4PUf7S6v9tCKNDrargJ","peerPubKey":"02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a","localId":"2626e4a0-e075-11ea-9afa-610bda093e3d","price":0.03,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1597660434424}
17/08/2020 10:33:55.169 [P2P] trace: Received SwapFailed packet from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): "{\"body\":{\"errorMessage\":\"Unable to find route to destination\",\"failureReason\":4,\"rHash\":\"64a3272877ab4c0d879d44f77a92ac853ff6295e5c86eedef9f6be3231e4ef69\"},\"header\":{\"id\":\"26579190-e075-11ea-b568-59ce54a73c83\",\"reqId\":\"26292e90-e075-11ea-9afa-610bda093e3d\"}}"
17/08/2020 10:33:55.170 [P2P] debug: received swapFailed due to NoRouteFound from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): {"rHash":"64a3272877ab4c0d879d44f77a92ac853ff6295e5c86eedef9f6be3231e4ef69","errorMessage":"Unable to find route to destination","failureReason":4}
17/08/2020 10:33:55.171 [SWAPS] trace: failing deal 64a3272877ab4c0d879d44f77a92ac853ff6295e5c86eedef9f6be3231e4ef69 in state Active & phase SwapRequested due to NoRouteFound
17/08/2020 10:33:55.172 [SWAPS] debug: deal 64a3272877ab4c0d879d44f77a92ac853ff6295e5c86eedef9f6be3231e4ef69 failed due to NoRouteFound: Unable to find route to destination
17/08/2020 10:33:55.172 [SWAPS] trace: emitting swap.failed event for 64a3272877ab4c0d879d44f77a92ac853ff6295e5c86eedef9f6be3231e4ef69
17/08/2020 10:33:55.173 [ORDERBOOK] error: swap between orders e1c5db90-e074-11ea-b568-59ce54a73c83 & 2626e4a0-e075-11ea-9afa-610bda093e3d failed due to NoRouteFound
17/08/2020 10:33:55.173 [ORDERBOOK] warn: swap for 10000 failed during order matching due to NoRouteFound, will repeat matching routine for failed quantity
17/08/2020 10:33:55.175 [ORDERBOOK] debug: repeating matching routine for 2626e4a0-e075-11ea-9afa-610bda093e3d for failed quantity of 10000
17/08/2020 10:33:55.175 [ORDERBOOK] verbose: no more matches found for order 2626e4a0-e075-11ea-9afa-610bda093e3d, remaining order will be discarded
17/08/2020 10:33:55.176 [ORDERBOOK] verbose: no more matches found for order 2626e4a0-e075-11ea-9afa-610bda093e3d, remaining order will be discarded
17/08/2020 10:33:55.176 [RPC] trace: call /xudrpc.Xud/PlaceOrder succeeded
17/08/2020 10:33:56.929 [CONNEXT] trace: sending request to /balance/0x0000000000000000000000000000000000000000
17/08/2020 10:33:58.306 [P2P] trace: Sent Ping packet to 02c22007d3367713a3f938595d5f9ad4b049c2fc27cad07035fc6b62b2f3a20149 (ApartRange): "{\"header\":{\"id\":\"28791200-e075-11ea-9afa-610bda093e3d\"}}"
17/08/2020 10:33:58.588 [P2P] trace: Received Pong packet from 02c22007d3367713a3f938595d5f9ad4b049c2fc27cad07035fc6b62b2f3a20149 (ApartRange): "{\"header\":{\"id\":\"288ff560-e075-11ea-b139-7bc0fbf70bab\",\"reqId\":\"28791200-e075-11ea-9afa-610bda093e3d\"}}"
17/08/2020 10:33:58.589 [P2P] trace: Received Ping packet from 02c22007d3367713a3f938595d5f9ad4b049c2fc27cad07035fc6b62b2f3a20149 (ApartRange): "{\"header\":{\"id\":\"288ff561-e075-11ea-b139-7bc0fbf70bab\"}}"
17/08/2020 10:33:58.591 [P2P] trace: Sent Pong packet to 02c22007d3367713a3f938595d5f9ad4b049c2fc27cad07035fc6b62b2f3a20149 (ApartRange): "{\"header\":{\"id\":\"28a4b5e0-e075-11ea-9afa-610bda093e3d\",\"reqId\":\"288ff561-e075-11ea-b139-7bc0fbf70bab\"}}"
17/08/2020 10:33:59.366 [P2P] trace: Received OrderInvalidation packet from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): "{\"body\":{\"id\":\"23db46f0-e075-11ea-b568-59ce54a73c83\",\"pairId\":\"ETH/BTC\",\"quantity\":9831227},\"header\":{\"id\":\"290636d0-e075-11ea-b568-59ce54a73c83\"}}"
17/08/2020 10:33:59.367 [P2P] trace: received order invalidation from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): {"id":"23db46f0-e075-11ea-b568-59ce54a73c83","pairId":"ETH/BTC","quantity":9831227}
17/08/2020 10:33:59.368 [ORDERBOOK] trace: order removed: 23db46f0-e075-11ea-b568-59ce54a73c83
17/08/2020 10:33:59.449 [P2P] trace: Received Order packet from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): "{\"body\":{\"id\":\"29065de0-e075-11ea-b568-59ce54a73c83\",\"isBuy\":false,\"pairId\":\"ETH/BTC\",\"price\":0.03714283,\"quantity\":9832045},\"header\":{\"id\":\"290684f0-e075-11ea-b568-59ce54a73c83\"}}"
17/08/2020 10:33:59.450 [P2P] trace: Received OrderInvalidation packet from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): "{\"body\":{\"id\":\"23dd1bb0-e075-11ea-b568-59ce54a73c83\",\"pairId\":\"ETH/BTC\",\"quantity\":269698828},\"header\":{\"id\":\"29072130-e075-11ea-b568-59ce54a73c83\"}}"
17/08/2020 10:33:59.451 [P2P] trace: received order from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): {"id":"29065de0-e075-11ea-b568-59ce54a73c83","pairId":"ETH/BTC","price":0.03714283,"quantity":9832045,"isBuy":false}
17/08/2020 10:33:59.452 [ORDERBOOK] trace: order added: {"id":"29065de0-e075-11ea-b568-59ce54a73c83","pairId":"ETH/BTC","price":0.03714283,"quantity":9832045,"isBuy":false,"peerPubKey":"02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a","createdAt":1597660439451,"initialQuantity":9832045}
17/08/2020 10:33:59.452 [P2P] trace: received order invalidation from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): {"id":"23dd1bb0-e075-11ea-b568-59ce54a73c83","pairId":"ETH/BTC","quantity":269698828}
17/08/2020 10:33:59.453 [ORDERBOOK] trace: order removed: 23dd1bb0-e075-11ea-b568-59ce54a73c83
17/08/2020 10:33:59.490 [P2P] trace: Received Order packet from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): "{\"body\":{\"id\":\"29074840-e075-11ea-b568-59ce54a73c83\",\"isBuy\":true,\"pairId\":\"ETH/BTC\",\"price\":0.03497917,\"quantity\":269721265},\"header\":{\"id\":\"29076f50-e075-11ea-b568-59ce54a73c83\"}}"
17/08/2020 10:33:59.491 [P2P] trace: received order from 02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a (AttitudeErase): {"id":"29074840-e075-11ea-b568-59ce54a73c83","pairId":"ETH/BTC","price":0.03497917,"quantity":269721265,"isBuy":true}
17/08/2020 10:33:59.491 [ORDERBOOK] trace: order added: {"id":"29074840-e075-11ea-b568-59ce54a73c83","pairId":"ETH/BTC","price":0.03497917,"quantity":269721265,"isBuy":true,"peerPubKey":"02799dff47d38da549c9f9e3dcd94388e3a9fe05b4ea50ea0636562b4ba2b4ca4a","createdAt":1597660439491,"initialQuantity":269721265}
@raladev raladev added bug Something isn't working order book P1 top priority swaps labels Aug 17, 2020
sangaman added a commit that referenced this issue Aug 18, 2020
This monitors all swap client payments until their resolution without
putting deals into `SwapRecovery`. Previously, if a call to send payment
failed but the payment was still in pending status (as has been the case
with Connext), then we would fail the swap deal and monitor the payment
in `SwapRecovery`. This had several downsides, namely:

1. Since the deal is marked as having failed in the database, if xud
restarts while payment monitoring is ongoing, it won't resume monitoring
because it sees the swap as having failed in the database. We only
recover swaps that were "active" at the time xud shut down. See #1799.

2. When a deal is failed, the maker order it attempted to swap re-enters
the order book and is available to be matched again. However, since
the payment for the original deal is still pending, it may still go
through, meaning that the order can be "double filled" in such a case.
See #1816.

By monitoring all pending payments to their resolution, we ensure that
we don't fail deals that wind up completing.

Fixes #1799. Fixes #1816.
sangaman added a commit that referenced this issue Aug 19, 2020
This monitors all swap client payments until their resolution without
putting deals into `SwapRecovery`. Previously, if a call to send payment
failed but the payment was still in pending status (as has been the case
with Connext), then we would fail the swap deal and monitor the payment
in `SwapRecovery`. This had several downsides, namely:

1. Since the deal is marked as having failed in the database, if xud
restarts while payment monitoring is ongoing, it won't resume monitoring
because it sees the swap as having failed in the database. We only
recover swaps that were "active" at the time xud shut down. See #1799.

2. When a deal is failed, the maker order it attempted to swap re-enters
the order book and is available to be matched again. However, since
the payment for the original deal is still pending, it may still go
through, meaning that the order can be "double filled" in such a case.
See #1816.

By monitoring all pending payments to their resolution, we ensure that
we don't fail deals that wind up completing.

Fixes #1799. Fixes #1816.
sangaman added a commit that referenced this issue Aug 19, 2020
This monitors all swap client payments until their resolution without
putting deals into `SwapRecovery`. Previously, if a call to send payment
failed but the payment was still in pending status (as has been the case
with Connext), then we would fail the swap deal and monitor the payment
in `SwapRecovery`. This had several downsides, namely:

1. Since the deal is marked as having failed in the database, if xud
restarts while payment monitoring is ongoing, it won't resume monitoring
because it sees the swap as having failed in the database. We only
recover swaps that were "active" at the time xud shut down. See #1799.

2. When a deal is failed, the maker order it attempted to swap re-enters
the order book and is available to be matched again. However, since
the payment for the original deal is still pending, it may still go
through, meaning that the order can be "double filled" in such a case.
See #1816.

By monitoring all pending payments to their resolution, we ensure that
we don't fail deals that wind up completing.

Fixes #1799. Fixes #1816.
sangaman added a commit that referenced this issue Aug 19, 2020
This monitors all swap client payments until their resolution without
putting deals into `SwapRecovery`. Previously, if a call to send payment
failed but the payment was still in pending status (as has been the case
with Connext), then we would fail the swap deal and monitor the payment
in `SwapRecovery`. This had several downsides, namely:

1. Since the deal is marked as having failed in the database, if xud
restarts while payment monitoring is ongoing, it won't resume monitoring
because it sees the swap as having failed in the database. We only
recover swaps that were "active" at the time xud shut down. See #1799.

2. When a deal is failed, the maker order it attempted to swap re-enters
the order book and is available to be matched again. However, since
the payment for the original deal is still pending, it may still go
through, meaning that the order can be "double filled" in such a case.
See #1816.

By monitoring all pending payments to their resolution, we ensure that
we don't fail deals that wind up completing.

Fixes #1799. Fixes #1816.
sangaman added a commit that referenced this issue Aug 19, 2020
This monitors all swap client payments until their resolution without
putting deals into `SwapRecovery`. Previously, if a call to send payment
failed but the payment was still in pending status (as has been the case
with Connext), then we would fail the swap deal and monitor the payment
in `SwapRecovery`. This had several downsides, namely:

1. Since the deal is marked as having failed in the database, if xud
restarts while payment monitoring is ongoing, it won't resume monitoring
because it sees the swap as having failed in the database. We only
recover swaps that were "active" at the time xud shut down. See #1799.

2. When a deal is failed, the maker order it attempted to swap re-enters
the order book and is available to be matched again. However, since
the payment for the original deal is still pending, it may still go
through, meaning that the order can be "double filled" in such a case.
See #1816.

By monitoring all pending payments to their resolution, we ensure that
we don't fail deals that wind up completing.

Fixes #1799. Fixes #1816.
@sangaman
Copy link
Collaborator

I had this issue confused with another one at first, I have been looking into this and I think I just found the root cause. I'll have a PR soon.

sangaman added a commit that referenced this issue Aug 23, 2020
This fixes the functionality of non-strict mode to add peer orders back
to the order book after they were matched but failed to swap. Previously
we would only add back orders that were partially matched, by removing
the remaining order from the order book, adding the partially matched
quantity back to it, and then adding it back to the order book.

This also adds back orders that were fully matched and removed from the
order book during matching after they fail to swap.

Closes #1816.
sangaman added a commit that referenced this issue Aug 24, 2020
This fixes the functionality of non-strict mode to add peer orders back
to the order book after they were matched but failed to swap. Previously
we would only add back orders that were partially matched, by removing
the remaining order from the order book, adding the partially matched
quantity back to it, and then adding it back to the order book.

This also adds back orders that were fully matched and removed from the
order book during matching after they fail to swap.

Closes #1816.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working order book P1 top priority swaps
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants