Xud: SwapTimeOut/SendPaymentFailure errors when user have no enough ETH for trade

[raladev]

Background

When user have no enough ETH for the trade one of the errors appears depending on side of user with fund problem - SwapTimeOut error appears when maker have no enough ETH, and SendPaymentFailure when taker have no enough ETH

---

SwapTimeOut Case

1. maker has 8,2 ETH is the channel
2. he places sell 11 ETH/BTC 0.0111 order
3. taker places buy 12 ETH/BTC mkt order

Actual behaviour

1. Swap timeout error
2. Maker tries to recover swap deal each 5 mins, but taker xud have no reaction on this action

Screenshot 2020-06-10 19:37:21
Screenshot 2020-06-10 19:37:29

Screenshot from 2020-06-10 19-49-51
Screenshot from 2020-06-10 19-49-44

Expected result

1. (Not enough channel balance error OR partial fill) + No swap recovery + No order removing from orderbook

---

SendPaymentFailure Case

1. taker has 11 eth in the channel
2. place buy 20 ETH/BTC 0.00001 order as a maker
3. place sell 20 ETH/BTC mkt

Actual result

SendPaymentFailure during the swap
Screenshot 2020-06-10 19:58:05
Screenshot 2020-06-10 19:56:51

Expected result

1. Not enough channel balance error

---

Logs

Time of first swap is ~16:35:55
Time of second swap is ~16:56:28

right_user.zip
left_user.zip

Indra logs (contains all indra+nats logs from 4 pm to 5 pm) - it would be better to use logdna interface, but I saved it for the history.

export_2020-06-10-18-32-43-744_cf38be08-a22a-4442-aa3d-671b8f53af22.jsonl.gz
export_2020-06-10-18-30-30-497_05781a1b-6aaf-4981-a8a0-627c350ab24e.jsonl.gz
export_2020-06-10-18-25-55-526_3e86b8b5-4aa9-43f5-a343-2a51909326d2.jsonl.gz

Note

Both cases can be partially solved by https://github.com/ExchangeUnion/xud/issues/1609

[kilrau]

Two issues to be fixed as I see it:

1. https://github.com/ExchangeUnion/xud/issues/1609 which will prevent situations like this to happen, caught by xud
2. Indra/connext client returning an "insufficient balance error" which we in turn can display (not sure but is this the issue asking for precisely this error code: https://github.com/connext/rest-api-client/issues/23)? @erkarl

[erkarl]

Indra/connext client returning an "insufficient balance error" which we in turn can display (not sure but is this the issue asking for precisely this error code: connext/rest-api-client#23)? @erkarl

Yep, https://github.com/connext/rest-api-client/issues/23 should handle it so we can display a better error message.

[raladev]

Current state:

1. SendPaymentFailure Case fixed by #1609

1. SwapTimeOut Case still can be reproduced, but with another error:

SwapTimeOut (Unknown error) Case

1. maker has 8,2 ETH is the channel
2. he places sell 2.2 ETH/BTC 0.01 order
3. he places sell 8 ETH/BTC 0.0111 order
4. taker places buy 2.2 ETH/BTC mkt order
5. taker places buy 9 ETH/BTC mkt order

Actual behaviour

1. Unknown err in xud and insufficient balance error in connext client.
2. Maker tries to recover swap deal each 5 mins, but taker xud have no reaction on this action

Screenshot from 2020-07-13 13-16-46
Screenshot from 2020-07-13 13-19-59
Screenshot from 2020-07-13 13-20-59
Screenshot from 2020-07-13 13-22-53

taker_connext_conb.log
maker_connext_conb.log
taker_xud_conb.log
maker_xud_conb.log

[raladev]

UPD for 7.0.0, nothing changed, we still need handle this error on xud side.
Screenshot from 2020-07-27 14-25-55

[kilrau]

Ok, thx

[kilrau]

Still want to look into this one? @rsercano

[rsercano]

Yes I do as much as I find time :)

[rsercano]

I can't reproduce this due to other issues;

• maker has 30 ETH in the channel
• puts 29 ETH sell
• puts 2 ETH sell
• taker tries to buy 29 ETH with market order
• taker gets SwapTimeout and all maker's orders are removed from orderbook (dunno why)

➜  xud git:(master) ✗ bin/xucli buy 29 ETH/BTC mkt
matched 29 ETH @ 0.1 with peer RavenSaddle order e90a1d20-e1f6-11ea-a408-fbb72f1fb227, attempting swap...
failed to swap 29 ETH due to NoRouteFound with peer order e90a1d20-e1f6-11ea-a408-fbb72f1fb227, continuing with matching routine...
matched 2 ETH @ 0.1 with peer RavenSaddle order ff3836e0-e1f6-11ea-a408-fbb72f1fb227, attempting swap...
failed to swap 2 ETH due to SwapTimedOut with peer order ff3836e0-e1f6-11ea-a408-fbb72f1fb227, continuing with matching routine...
no more matches found, 29 qty will be discarded

Taker logs;

19/08/2020 11:36:28.301 [ORDERBOOK] debug: removed order e90a1d20-e1f6-11ea-a408-fbb72f1fb227 while matching order 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09
19/08/2020 11:36:28.302 [ORDERBOOK] debug: matched with peer 02ea79f3a2a26deaee328839638df9dc8e2886ec863485f9ebb65c7f3de52400d7 (RavenSaddle), executing swap on taker 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09 and maker e90a1d20-e1f6-11ea-a408-fbb72f1fb227 for 2900000000
19/08/2020 11:36:28.316 [LND-BTC] debug: could not find a route to 037f93c23f36f8aec380f5cd105c948598ac4c237164cce06227f3688b648e074c for 290000000 units with finalCltvDelta 40
19/08/2020 11:36:28.316 [ORDERBOOK] error: swap between orders e90a1d20-e1f6-11ea-a408-fbb72f1fb227 & 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09 failed due to NoRouteFound
19/08/2020 11:36:28.316 [ORDERBOOK] warn: swap for 2900000000 failed during order matching due to NoRouteFound, will repeat matching routine for failed quantity
19/08/2020 11:36:28.317 [ORDERBOOK] debug: repeating matching routine for 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09 for failed quantity of 2900000000
19/08/2020 11:36:28.317 [ORDERBOOK] debug: removed order ff3836e0-e1f6-11ea-a408-fbb72f1fb227 while matching order 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09
19/08/2020 11:36:28.318 [ORDERBOOK] debug: matched with peer 02ea79f3a2a26deaee328839638df9dc8e2886ec863485f9ebb65c7f3de52400d7 (RavenSaddle), executing swap on taker 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09 and maker ff3836e0-e1f6-11ea-a408-fbb72f1fb227 for 200000000
19/08/2020 11:36:28.337 [LND-BTC] debug: found a route to 037f93c23f36f8aec380f5cd105c948598ac4c237164cce06227f3688b648e074c for 20000000 units with finalCltvDelta 40: 77329,21,20000021,83484818385469440,500000000,20000000,21,77289,20000000000,21000,0252f366111259996a101c5a82c880e9c95c8278d7e668c40163c0db656161cbbf,true,82188494176321540,,20000000,,77289,20000000000,,037f93c23f36f8aec380f5cd105c948598ac4c237164cce06227f3688b648e074c,true,21000,20000021000
19/08/2020 11:36:28.337 [SWAPS] debug: New deal: {"takerCltvDelta":200,"rHash":"b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c","orderId":"ff3836e0-e1f6-11ea-a408-fbb72f1fb227","pairId":"ETH/BTC","proposedQuantity":200000000,"rPreimage":"f06282d5c7ab124a0d562eb6d207f39e5259537ce0ca458c5b0f2d62fd31bb43","takerCurrency":"ETH","makerCurrency":"BTC","takerAmount":200000000,"makerAmount":20000000,"takerUnits":2000000000000000000,"makerUnits":20000000,"destination":"037f93c23f36f8aec380f5cd105c948598ac4c237164cce06227f3688b648e074c","peerPubKey":"02ea79f3a2a26deaee328839638df9dc8e2886ec863485f9ebb65c7f3de52400d7","localId":"132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09","price":0.1,"isBuy":false,"phase":0,"state":0,"role":0,"createTime":1597826188337}
19/08/2020 11:36:28.339 [SWAPS] debug: Requesting deal: {"takerCltvDelta":200,"rHash":"b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c","orderId":"ff3836e0-e1f6-11ea-a408-fbb72f1fb227","pairId":"ETH/BTC","proposedQuantity":200000000,"rPreimage":"f06282d5c7ab124a0d562eb6d207f39e5259537ce0ca458c5b0f2d62fd31bb43","takerCurrency":"ETH","makerCurrency":"BTC","takerAmount":200000000,"makerAmount":20000000,"takerUnits":2000000000000000000,"makerUnits":20000000,"destination":"037f93c23f36f8aec380f5cd105c948598ac4c237164cce06227f3688b648e074c","peerPubKey":"02ea79f3a2a26deaee328839638df9dc8e2886ec863485f9ebb65c7f3de52400d7","localId":"132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09","price":0.1,"isBuy":false,"phase":0,"state":0,"role":0,"createTime":1597826188337}
19/08/2020 11:36:28.464 [P2P] debug: received swapAccepted from 02ea79f3a2a26deaee328839638df9dc8e2886ec863485f9ebb65c7f3de52400d7 (RavenSaddle): {"rHash":"b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c","quantity":200000000,"makerCltvDelta":62}
19/08/2020 11:36:28.464 [SWAPS] debug: Setting SendingPayment phase for deal b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c
19/08/2020 11:36:28.471 [LND-BTC] debug: sending payment of 20000000 with hash b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c to 037f93c23f36f8aec380f5cd105c948598ac4c237164cce06227f3688b648e074c
19/08/2020 11:36:31.123 [LND-BTC] debug: new channel maximum outbound capacity: 245000000
19/08/2020 11:36:31.123 [LND-BTC] debug: new channel total outbound capacity: 245000000


19/08/2020 11:37:58.466 [SWAPS] debug: deal b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c failed due to SwapTimedOut
19/08/2020 11:37:58.468 [CONNEXT] warn: could not find paymentId for incoming transfer with hash b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c
19/08/2020 11:37:58.469 [SWAPS] debug: Sending SwapTimedOut error to peer: {"rHash":"b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c","failureReason":10}
19/08/2020 11:37:58.469 [ORDERBOOK] error: swap between orders ff3836e0-e1f6-11ea-a408-fbb72f1fb227 & 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09 failed due to SwapTimedOut
19/08/2020 11:37:58.470 [ORDERBOOK] warn: swap for 200000000 failed during order matching due to SwapTimedOut, will repeat matching routine for failed quantity
19/08/2020 11:37:58.470 [ORDERBOOK] debug: repeating matching routine for 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09 for failed quantity of 200000000
19/08/2020 11:37:58.471 [ORDERBOOK] debug: placeOrder max time exceeded. order ({"pairId":"ETH/BTC","price":null,"quantity":200000000,"isBuy":true,"localId":"132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09","id":"132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09","initialQuantity":2900000000,"hold":0,"createdAt":1597826188301}) won't be fully matched
19/08/2020 11:37:58.471 [ORDERBOOK] verbose: no more matches found for order 132b7bd0-e1f7-11ea-96e0-2b2afa5d3a09, remaining order will be discarded
19/08/2020 11:38:01.406 [P2P] debug: received swapFailed due to UnknownError from 02ea79f3a2a26deaee328839638df9dc8e2886ec863485f9ebb65c7f3de52400d7 (RavenSaddle): {"rHash":"b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c","errorMessage":"Timeout has occurred","failureReason":12}
19/08/2020 11:38:01.414 [SWAPS] warn: received unexpected swap failed packet for deal with payment hash b34d144bd44f79a82dc25068afd33d7e3eb26b20406e71b455803d4e6d840e1c
19/08/2020 11:38:05.086 [ORDERBOOK] verbose: no more matches found for order 4cdbb3e0-e1f7-11ea-96e0-2b2afa5d3a09, remaining order will be discarded

Please let me know if there's any other case that I can reproduce this.

[kilrau]

Once the connext team implemented https://github.com/connext/rest-api-client/issues/23 and we did https://github.com/ExchangeUnion/xud/issues/1628 in xud, this should be fixed. I am closing for now.