Xud: Swap failed

[offerm]

xud-simnet-native.

using the script xud-simnet-check-swaps.
5 swapAccepted received from peer but only 2 invoices created. This cause the other swap not to progress and to fail with timeout.

check for rHash 49d3729d1f0e75bac9810a34f6e4a446a706fbf7e03845c14f582672712dfb1b

The taker log:

26/08/2019 23:54:25.494 [SWAPS] debug: New deal: {"takerCltvDelta":100,"rHash":"49d3729d1f0e75bac9810a34f6e4a446a706fbf7e03845c14f582672712dfb1b","orderId":"c25cc980-c815-11e9-8eeb-b1a5f3e667ad","pairId":
"BTC/DAI","proposedQuantity":10000000,"rPreimage":"d93f21e6580551ad99f525c6c93940996f134a7329723072e21ec93c76306d2c","takerCurrency":"DAI","makerCurrency":"BTC","takerAmount":99980000000,"makerAmount":100
00000,"takerUnits":999800000000000000000,"makerUnits":10000000,"destination":"03a0bdf210dcecebb2d6f092b47fb7753af8114261888a365dfcb0d4548bbbdd2a","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2
938e132b52cab0a0d9cfc6","localId":"b01b8b70-c843-11e9-8b25-6d96ce5f243f","price":9998,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1566852865494}
26/08/2019 23:54:25.495 [SWAPS] debug: New deal: {"takerCltvDelta":40,"rHash":"e3318438b5d6c48981a19f5edc570034ea104a4bab7732fc14dd24db9817595a","orderId":"c26973b0-c815-11e9-8eeb-b1a5f3e667ad","pairId":"
LTC/BTC","proposedQuantity":10000000,"rPreimage":"9225920be1a537fae5073b2e365b6477bc3367546ebaf986a0b19b137b90a64b","takerCurrency":"BTC","makerCurrency":"LTC","takerAmount":77000,"makerAmount":10000000,"
takerUnits":77000,"makerUnits":10000000,"destination":"0270e8254e07649cdde230c9e09de6ff63c28a6d275c30b0a6863028d9db0e7c6f","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6"
,"localId":"b01bb280-c843-11e9-8b25-6d96ce5f243f","price":0.0077,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1566852865495}
26/08/2019 23:54:25.497 [SWAPS] debug: New deal: {"takerCltvDelta":100,"rHash":"27dc6be2f69f1c63286cbb47b2e6e7b96b5c5570da288fd1c42098b58226df3d","orderId":"c2702a70-c815-11e9-8eeb-b1a5f3e667ad","pairId":
"LTC/DAI","proposedQuantity":10000000,"rPreimage":"9720099c9a6ba1f4f1e343eb5c131544b8498b79b06533e7bb070bc7aed8e0d7","takerCurrency":"DAI","makerCurrency":"LTC","takerAmount":980000000,"makerAmount":10000
000,"takerUnits":9800000000000000000,"makerUnits":10000000,"destination":"0270e8254e07649cdde230c9e09de6ff63c28a6d275c30b0a6863028d9db0e7c6f","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e
132b52cab0a0d9cfc6","localId":"b01b6460-c843-11e9-8b25-6d96ce5f243f","price":98,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1566852865496}
26/08/2019 23:54:25.501 [SWAPS] debug: Requesting deal: {"takerCltvDelta":100,"rHash":"49d3729d1f0e75bac9810a34f6e4a446a706fbf7e03845c14f582672712dfb1b","orderId":"c25cc980-c815-11e9-8eeb-b1a5f3e667ad","p
airId":"BTC/DAI","proposedQuantity":10000000,"rPreimage":"d93f21e6580551ad99f525c6c93940996f134a7329723072e21ec93c76306d2c","takerCurrency":"DAI","makerCurrency":"BTC","takerAmount":99980000000,"makerAmou
nt":10000000,"takerUnits":999800000000000000000,"makerUnits":10000000,"destination":"03a0bdf210dcecebb2d6f092b47fb7753af8114261888a365dfcb0d4548bbbdd2a","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f
160fee2938e132b52cab0a0d9cfc6","localId":"b01b8b70-c843-11e9-8b25-6d96ce5f243f","price":9998,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1566852865494}
26/08/2019 23:54:25.502 [SWAPS] debug: Requesting deal: {"takerCltvDelta":40,"rHash":"e3318438b5d6c48981a19f5edc570034ea104a4bab7732fc14dd24db9817595a","orderId":"c26973b0-c815-11e9-8eeb-b1a5f3e667ad","pa
irId":"LTC/BTC","proposedQuantity":10000000,"rPreimage":"9225920be1a537fae5073b2e365b6477bc3367546ebaf986a0b19b137b90a64b","takerCurrency":"BTC","makerCurrency":"LTC","takerAmount":77000,"makerAmount":100
00000,"takerUnits":77000,"makerUnits":10000000,"destination":"0270e8254e07649cdde230c9e09de6ff63c28a6d275c30b0a6863028d9db0e7c6f","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0
d9cfc6","localId":"b01bb280-c843-11e9-8b25-6d96ce5f243f","price":0.0077,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1566852865495}
26/08/2019 23:54:25.502 [SWAPS] debug: Requesting deal: {"takerCltvDelta":100,"rHash":"27dc6be2f69f1c63286cbb47b2e6e7b96b5c5570da288fd1c42098b58226df3d","orderId":"c2702a70-c815-11e9-8eeb-b1a5f3e667ad","p
airId":"LTC/DAI","proposedQuantity":10000000,"rPreimage":"9720099c9a6ba1f4f1e343eb5c131544b8498b79b06533e7bb070bc7aed8e0d7","takerCurrency":"DAI","makerCurrency":"LTC","takerAmount":980000000,"makerAmount
":10000000,"takerUnits":9800000000000000000,"makerUnits":10000000,"destination":"0270e8254e07649cdde230c9e09de6ff63c28a6d275c30b0a6863028d9db0e7c6f","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160f
ee2938e132b52cab0a0d9cfc6","localId":"b01b6460-c843-11e9-8b25-6d96ce5f243f","price":98,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1566852865496}
26/08/2019 23:54:25.503 [LND-BTC] debug: got 1 route(s) to destination 03a0bdf210dcecebb2d6f092b47fb7753af8114261888a365dfcb0d4548bbbdd2a: 74881,1,79001,81478209664778240,2500000000,79000,1,74841,79000000
,1079,036f9b004f047283b33a640bc4afdd26e2eb82e73938f8ac0796641ad20dc5bdd4,17109500441133056,2500000000,79000,,74841,79000000,,03a0bdf210dcecebb2d6f092b47fb7753af8114261888a365dfcb0d4548bbbdd2a,1079,7900107
9, finalCltvDelta: 144
26/08/2019 23:54:25.504 [SWAPS] debug: New deal: {"takerCltvDelta":160,"rHash":"68796bb61bf5d7d77ca97b007f3663a615dec365e410feef41cd62ea10168869","orderId":"c26cf620-c815-11e9-8eeb-b1a5f3e667ad","pairId":"LTC/BTC","proposedQuantity":10000000,"rPreimage":"7cabd5b2aeba62a99e8dba97856414c541d5c3881cb7435d26802c9594ae22ee","takerCurrency":"LTC","makerCurrency":"BTC","takerAmount":10000000,"makerAmount":79000,"takerUnits":10000000,"makerUnits":79000,"destination":"03a0bdf210dcecebb2d6f092b47fb7753af8114261888a365dfcb0d4548bbbdd2a","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6","localId":"b01bd990-c843-11e9-8b25-6d96ce5f243f","price":0.0079,"isBuy":false,"phase":0,"state":0,"role":0,"createTime":1566852865504}
26/08/2019 23:54:25.504 [SWAPS] debug: Requesting deal: {"takerCltvDelta":160,"rHash":"68796bb61bf5d7d77ca97b007f3663a615dec365e410feef41cd62ea10168869","orderId":"c26cf620-c815-11e9-8eeb-b1a5f3e667ad","pairId":"LTC/BTC","proposedQuantity":10000000,"rPreimage":"7cabd5b2aeba62a99e8dba97856414c541d5c3881cb7435d26802c9594ae22ee","takerCurrency":"LTC","makerCurrency":"BTC","takerAmount":10000000,"makerAmount":79000,"takerUnits":10000000,"makerUnits":79000,"destination":"03a0bdf210dcecebb2d6f092b47fb7753af8114261888a365dfcb0d4548bbbdd2a","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6","localId":"b01bd990-c843-11e9-8b25-6d96ce5f243f","price":0.0079,"isBuy":false,"phase":0,"state":0,"role":0,"createTime":1566852865504}
26/08/2019 23:54:25.975 [P2P] debug: received swapAccepted from 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6: {"rHash":"e3318438b5d6c48981a19f5edc570034ea104a4bab7732fc14dd24db9817595a","quantity":10000000,"makerCltvDelta":896}
26/08/2019 23:54:25.978 [P2P] debug: received swapAccepted from 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6: {"rHash":"68796bb61bf5d7d77ca97b007f3663a615dec365e410feef41cd62ea10168869","quantity":10000000,"makerCltvDelta":328}
26/08/2019 23:54:25.998 [LND-BTC] debug: added invoice of 77000 for e3318438b5d6c48981a19f5edc570034ea104a4bab7732fc14dd24db9817595a with cltvExpiry 40
26/08/2019 23:54:26.004 [LND-LTC] debug: added invoice of 10000000 for 68796bb61bf5d7d77ca97b007f3663a615dec365e410feef41cd62ea10168869 with cltvExpiry 160
26/08/2019 23:54:26.117 [P2P] debug: received swapAccepted from 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6: {"rHash":"9f08f1122fbf9e300e93f71f91ea64d7d188d1ef29a0e0c99385dfb9b1e31136","quantity":10000000,"makerCltvDelta":147}
26/08/2019 23:54:26.181 [P2P] debug: received swapAccepted from 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6: {"rHash":"49d3729d1f0e75bac9810a34f6e4a446a706fbf7e03845c14f582672712dfb1b","quantity":10000000,"makerCltvDelta":147}
26/08/2019 23:54:26.236 [P2P] debug: received swapAccepted from 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6: {"rHash":"27dc6be2f69f1c63286cbb47b2e6e7b96b5c5570da288fd1c42098b58226df3d","quantity":10000000,"makerCltvDelta":586}
26/08/2019 23:54:27.552 [SWAPS] debug: Executing taker code to resolve hash
26/08/2019 23:54:27.567 [LND-LTC] debug: settled invoice for 68796bb61bf5d7d77ca97b007f3663a615dec365e410feef41cd62ea10168869
26/08/2019 23:54:27.567 [SWAPS] debug: Payment received for deal with payment hash 7cabd5b2aeba62a99e8dba97856414c541d5c3881cb7435d26802c9594ae22ee
26/08/2019 23:54:27.568 [LND-LTC] debug: deleted invoice subscription for 68796bb61bf5d7d77ca97b007f3663a615dec365e410feef41cd62ea10168869
26/08/2019 23:54:27.602 [ORDERBOOK] info: match executed on taker b01bd990-c843-11e9-8b25-6d96ce5f243f and maker c26cf620-c815-11e9-8eeb-b1a5f3e667ad for 10000000 with peer 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6
26/08/2019 23:54:27.696 [SWAPS] debug: Executing taker code to resolve hash
26/08/2019 23:54:27.720 [LND-BTC] debug: settled invoice for e3318438b5d6c48981a19f5edc570034ea104a4bab7732fc14dd24db9817595a
26/08/2019 23:54:27.720 [SWAPS] debug: Payment received for deal with payment hash 9225920be1a537fae5073b2e365b6477bc3367546ebaf986a0b19b137b90a64b
26/08/2019 23:54:27.721 [LND-BTC] debug: deleted invoice subscription for e3318438b5d6c48981a19f5edc570034ea104a4bab7732fc14dd24db9817595a
26/08/2019 23:54:27.754 [ORDERBOOK] info: match executed on taker b01bb280-c843-11e9-8b25-6d96ce5f243f and maker c26973b0-c815-11e9-8eeb-b1a5f3e667ad for 10000000 with peer 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6
26/08/2019 23:54:27.834 [SWAPS] debug: Swap completed. preimage = 7cabd5b2aeba62a99e8dba97856414c541d5c3881cb7435d26802c9594ae22ee
26/08/2019 23:54:27.845 [SWAPS] debug: Sending swap complete to peer: {"rHash":"68796bb61bf5d7d77ca97b007f3663a615dec365e410feef41cd62ea10168869"}
26/08/2019 23:54:27.994 [SWAPS] debug: Swap completed. preimage = 9225920be1a537fae5073b2e365b6477bc3367546ebaf986a0b19b137b90a64b
26/08/2019 23:54:28.002 [SWAPS] debug: Sending swap complete to peer: {"rHash":"e3318438b5d6c48981a19f5edc570034ea104a4bab7732fc14dd24db9817595a"}
26/08/2019 23:54:56.119 [SWAPS] debug: deal 9f08f1122fbf9e300e93f71f91ea64d7d188d1ef29a0e0c99385dfb9b1e31136 failed due to SwapTimedOut: undefined
26/08/2019 23:54:56.123 [ORDERBOOK] error: swap between orders c2795230-c815-11e9-8eeb-b1a5f3e667ad & b0171ea0-c843-11e9-8b25-6d96ce5f243f failed due to SwapTimedOut
26/08/2019 23:54:56.126 [ORDERBOOK] warn: swap for 10000000 failed during order matching due to SwapTimedOut, will repeat matching routine for failed quantity
26/08/2019 23:54:56.127 [ORDERBOOK] debug: repeating matching routine for b0171ea0-c843-11e9-8b25-6d96ce5f243f for failed quantity of 10000000
26/08/2019 23:54:56.127 [ORDERBOOK] debug: placeOrder max time exceeded. order ({"pairId":"WETH/BTC","price":0.023,"quantity":10000000,"isBuy":true,"localId":"b0171ea0-c843-11e9-8b25-6d96ce5f243f","hold":0,"id":"b0171ea0-c843-11e9-8b25-6d96ce5f243f","initialQuantity":10000000,"createdAt":1566852865418}) won't be fully matched
26/08/2019 23:54:56.127 [ORDERBOOK] debug: order added: {"pairId":"WETH/BTC","price":0.023,"quantity":10000000,"isBuy":true,"localId":"b0171ea0-c843-11e9-8b25-6d96ce5f243f","hold":0,"id":"b0171ea0-c843-11e9-8b25-6d96ce5f243f","initialQuantity":10000000,"createdAt":1566852865418}
26/08/2019 23:54:56.184 [SWAPS] debug: deal 49d3729d1f0e75bac9810a34f6e4a446a706fbf7e03845c14f582672712dfb1b failed due to SwapTimedOut: undefined
26/08/2019 23:54:56.187 [ORDERBOOK] error: swap between orders c25cc980-c815-11e9-8eeb-b1a5f3e667ad & b01b8b70-c843-11e9-8b25-6d96ce5f243f failed due to SwapTimedOut
26/08/2019 23:54:56.187 [ORDERBOOK] warn: swap for 10000000 failed during order matching due to SwapTimedOut, will repeat matching routine for failed quantity
26/08/2019 23:54:56.188 [ORDERBOOK] debug: repeating matching routine for b01b8b70-c843-11e9-8b25-6d96ce5f243f for failed quantity of 10000000
26/08/2019 23:54:56.188 [ORDERBOOK] debug: placeOrder max time exceeded. order ({"pairId":"BTC/DAI","price":9998,"quantity":10000000,"isBuy":false,"localId":"b01b8b70-c843-11e9-8b25-6d96ce5f243f","hold":0,"id":"b01b8b70-c843-11e9-8b25-6d96ce5f243f","initialQuantity":10000000,"createdAt":1566852865447}) won't be fully matched
26/08/2019 23:54:56.189 [ORDERBOOK] debug: order added: {"pairId":"BTC/DAI","price":9998,"quantity":10000000,"isBuy":false,"localId":"b01b8b70-c843-11e9-8b25-6d96ce5f243f","hold":0,"id":"b01b8b70-c843-11e9-8b25-6d96ce5f243f","initialQuantity":10000000,"createdAt":1566852865447}
26/08/2019 23:54:56.193 [SWAPS] debug: deal 27dc6be2f69f1c63286cbb47b2e6e7b96b5c5570da288fd1c42098b58226df3d failed due to SendPaymentFailure
26/08/2019 23:54:56.196 [ORDERBOOK] error: swap between orders c2702a70-c815-11e9-8eeb-b1a5f3e667ad & b01b6460-c843-11e9-8b25-6d96ce5f243f failed due to SendPaymentFailure
26/08/2019 23:54:56.195 [SWAPS] debug: Sending swap error to peer: {"rHash":"27dc6be2f69f1c63286cbb47b2e6e7b96b5c5570da288fd1c42098b58226df3d","failureReason":7,"errorMessage":"the recipient rejected our payment for the swap"}
26/08/2019 23:54:56.199 [ORDERBOOK] warn: swap for 10000000 failed during order matching due to SendPaymentFailure, will repeat matching routine for failed quantity
26/08/2019 23:54:56.200 [ORDERBOOK] debug: repeating matching routine for b01b6460-c843-11e9-8b25-6d96ce5f243f for failed quantity of 10000000
26/08/2019 23:54:56.200 [ORDERBOOK] debug: placeOrder max time exceeded. order ({"pairId":"LTC/DAI","price":98,"quantity":10000000,"isBuy":false,"localId":"b01b6460-c843-11e9-8b25-6d96ce5f243f","hold":0,"id":"b01b6460-c843-11e9-8b25-6d96ce5f243f","initialQuantity":10000000,"createdAt":1566852865446}) won't be fully matched
26/08/2019 23:54:56.200 [ORDERBOOK] debug: order added: {"pairId":"LTC/DAI","price":98,"quantity":10000000,"isBuy":false,"localId":"b01b6460-c843-11e9-8b25-6d96ce5f243f","hold":0,"id":"b01b6460-c843-11e9-8b25-6d96ce5f243f","initialQuantity":10000000,"createdAt":1566852865446}
26/08/2019 23:54:56.214 [SWAPS] debug: new deal error message for 9f08f1122fbf9e300e93f71f91ea64d7d188d1ef29a0e0c99385dfb9b1e31136: + the recipient rejected our payment for the swap
26/08/2019 23:54:56.216 [SWAPS] debug: Sending swap error to peer: {"rHash":"9f08f1122fbf9e300e93f71f91ea64d7d188d1ef29a0e0c99385dfb9b1e31136","failureReason":7,"errorMessage":"the recipient rejected our payment for the swap"}
26/08/2019 23:54:56.722 [SWAPS] debug: new deal error message for 49d3729d1f0e75bac9810a34f6e4a446a706fbf7e03845c14f582672712dfb1b: + the recipient rejected our payment for the swap
26/08/2019 23:54:56.722 [SWAPS] debug: Sending swap error to peer: {"rHash":"49d3729d1f0e75bac9810a34f6e4a446a706fbf7e03845c14f582672712dfb1b","failureReason":7,"errorMessage":"the recipient rejected our payment for the swap"}
26/08/2019 23:55:11.376 [RPC] debug: received call /xudrpc.Xud/ListOrders

[sangaman]

Thanks for the bug report, I will look into this tomorrow.

[sangaman]

The reason not every swap gets an invoice is because several of them involve receiving a payment via raiden where invoices are not a thing, so I don't think the fact that only two invoices were added for 5 accepted swaps is a concern.

Of the 3 swaps that failed, two failed due to timeout and one failed due to the maker's lnd rejecting our payment (likely due to the fact that their send payment call to us failed). It's hard to tell why that is without the logs from the maker's end, though.

Does the check-swaps script fail for you consistently?

[sangaman]

Fyi, here's what I get now when I run the swap check script.

[offerm]

Taker's view:

07/09/2019 11:46:40.560 [SWAPS] debug: New deal: {"takerCltvDelta":160,"rHash":"e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a","orderId":"5be7de10-cfea-11e9-a395-71ad4cd88264","pairId":"LTC/DAI","proposedQuantity":10000000,"rPreimage":"c9766235e0373d797150c28e562cd67473cfb73b88987740ce8f780cf927a466","takerCurrency":"LTC","makerCurrency":"DAI","takerAmount":10000000,"makerAmount":1000000000,"takerUnits":10000000,"makerUnits":10000000000000000000,"destination":"0x7ed0299Fa1ADA71D10536B866231D447cDFa48b9","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6","localId":"02c25280-d14c-11e9-b605-097a5c07bedd","price":100,"isBuy":false,"phase":0,"state":0,"role":0,"createTime":1567846000559}
07/09/2019 11:46:40.561 [SWAPS] debug: Requesting deal: {"takerCltvDelta":160,"rHash":"e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a","orderId":"5be7de10-cfea-11e9-a395-71ad4cd88264","pairId":"LTC/DAI","proposedQuantity":10000000,"rPreimage":"c9766235e0373d797150c28e562cd67473cfb73b88987740ce8f780cf927a466","takerCurrency":"LTC","makerCurrency":"DAI","takerAmount":10000000,"makerAmount":1000000000,"takerUnits":10000000,"makerUnits":10000000000000000000,"destination":"0x7ed0299Fa1ADA71D10536B866231D447cDFa48b9","peerPubKey":"02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6","localId":"02c25280-d14c-11e9-b605-097a5c07bedd","price":100,"isBuy":false,"phase":0,"state":0,"role":0,"createTime":1567846000559}
07/09/2019 11:46:40.778 [P2P] debug: received swapAccepted from 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6: {"rHash":"e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a","quantity":10000000,"makerCltvDelta":7360}
07/09/2019 11:46:40.790 [LND-LTC] debug: added invoice of 10000000 for e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a with cltvExpiry 160
07/09/2019 11:47:10.779 [SWAPS] debug: deal e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a failed due to SwapTimedOut: undefined

Maker's view:

07/09/2019 08:46:40.635 [P2P] debug: received swapRequest from 03fe6f2bcb02759d6523a65ad16248d6042bf502ca2ef054773d0ed65ce4fb3a62: {"proposedQuantity":10000000,"pairId":"LTC/DAI","orderId":"5be7de10-cfea-11e9-a395-71ad4cd88264","rHash":"e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a","takerCltvDelta":160}
07/09/2019 08:46:40.636 [ORDERBOOK] debug: added hold of 10000000 on order 5be7de10-cfea-11e9-a395-71ad4cd88264
07/09/2019 08:46:40.638 [SWAPS] debug: trying to accept deal: {"quantity":10000000,"localId":"5be7de10-cfea-11e9-a395-71ad4cd88264","price":100,"isBuy":false} from xudPubKey: 03fe6f2bcb02759d6523a65ad16248d6042bf502ca2ef054773d0ed65ce4fb3a62
07/09/2019 08:46:40.639 [SWAPS] debug: New deal: {"proposedQuantity":10000000,"pairId":"LTC/DAI","orderId":"5be7de10-cfea-11e9-a395-71ad4cd88264","rHash":"e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a","takerCltvDelta":160,"price":100,"isBuy":false,"quantity":10000000,"makerAmount":1000000000,"takerAmount":10000000,"makerCurrency":"DAI","takerCurrency":"LTC","makerUnits":10000000000000000000,"takerUnits":10000000,"takerPubKey":"03be2638e86f87c06304de012a1775eccda7d52b6ae5ec6276f3e588cdb60c7dd0","destination":"03be2638e86f87c06304de012a1775eccda7d52b6ae5ec6276f3e588cdb60c7dd0","peerPubKey":"03fe6f2bcb02759d6523a65ad16248d6042bf502ca2ef054773d0ed65ce4fb3a62","localId":"5be7de10-cfea-11e9-a395-71ad4cd88264","phase":0,"state":0,"role":1,"createTime":1567846000638}
07/09/2019 08:46:40.642 [LND-LTC] debug: got 1 route(s) to destination 03be2638e86f87c06304de012a1775eccda7d52b6ae5ec6276f3e588cdb60c7dd0: 73302,,10000000,77721178432667649,225000000000,10000000,,73302,10000000000,,03be2638e86f87c06304de012a1775eccda7d52b6ae5ec6276f3e588cdb60c7dd0,,10000000000, finalCltvDelta: 160
07/09/2019 08:46:40.656 [SWAPS] debug: got LTC block height of 73142
07/09/2019 08:46:40.657 [SWAPS] debug: found route to taker with total lock duration of 160 LTC blocks (~64h)
07/09/2019 08:46:40.657 [SWAPS] debug: maker client lock buffer: 5760 DAI blocks (~23040h)
07/09/2019 08:46:40.657 [SWAPS] debug: block time factor of DAI to LTC: 10
07/09/2019 08:46:40.658 [SWAPS] debug: calculated lock delta for final hop to maker: 7360 DAI blocks (~29440h)
07/09/2019 08:46:40.674 [SWAPS] debug: sending swap accepted packet: {"makerCltvDelta":7360,"rHash":"e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a","quantity":10000000} to peer: 03fe6f2bcb02759d6523a65ad16248d6042bf502ca2ef054773d0ed65ce4fb3a62
07/09/2019 08:46:41.951 [HTTP] debug: http server request json: {"token":"0x4115652c9025d99512e9026b8f11c3e265bfecd7","secrethash":"0xe460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a","amount":10000000000000000000,"payment_identifier":8584193380489335,"payment_sender":"0x47bf7e2dcff44f83e5f6ef53f46c474c97710a09","expiration":5102018,"payment_recipient":"0x7ed0299fa1ada71d10536b866231d447cdfa48b9","chain_id":4321,"chain_height":5094659}
07/09/2019 08:46:41.952 [SWAPS] debug: handleResolveRequest starting with hash e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a
07/09/2019 08:46:41.952 [ORDERBOOK] debug: removed hold of 10000000 on order 5be7de10-cfea-11e9-a395-71ad4cd88264
07/09/2019 08:46:41.952 [SWAPS] error: cltvDelta of 7359 does not meet 7360 minimum
07/09/2019 08:46:41.952 [SWAPS] debug: deal e460b5a9610e4aaf2e0c9746e435a85edb7edc1a358ea6478901ba7a695b377a failed due to InvalidResolveRequest
07/09/2019 08:46:57.232 [RPC] debug: received call /xudrpc.Xud/ListPeers

This problem started when @erkarl change fix(swaps): validate Raiden's resolve request was merged into master.

The change does not take into account that a new block may be created and arrived to the maker before the payment but to the taker after the payment. In this case we will see:

07/09/2019 08:46:41.952 [SWAPS] error: cltvDelta of 7359 does not meet 7360 minimum

I think I mentioned this before:

• the taker should provide it's cltv delta (160 in this case)
• the maker should add its own cltv delta - the same value that it is using when being a taker.
• on top of that we need to add a buffer - few blocks to allow slippage

when getting a payment, the maker should check
if (deal.makerCltvDelta! > lockExpirationDelta) - slippage

and not

if (deal.makerCltvDelta! > lockExpirationDelta)

The reason we see it on simnet is due to the low difficulty we are using which allow very fast mining and creation of multiple blocks at a very short time. on top of that, there is a problem that one of the geth instances is getting into mining mode and keeps creating blocks. On top of that, the xud1 test server is very close to the geth(s) nodes and gets the new blocks much faster than my server (taker) which is far.

This can happen in testnet and mainnet but probability of having it is small.

[erkarl]

Very nice debugging @offerm. I'm wondering what should the value for slippage be?

I'd like to add a failing simulation to this scenario. As a quick fix for simnet we can add a static value.

[sangaman]

@erkarl Should we close this issue? We have a separate issue for the simulation test.

[erkarl]

@sangaman yes, definitely.