Recover from LND crashes while swapping #1126

kilrau · 2019-08-05T14:09:49Z

Enhancement of #1081

Currently #1081 only deals with xud crashing somewhere between SwapCreated and SwapCompleted: This is about dealing with LND crashing in these swap phases and restoring from it.

Open new issue to do the same for connext/c-lightning.

The text was updated successfully, but these errors were encountered:

kilrau · 2019-08-29T15:08:45Z

Colorful.

kilrau · 2019-10-09T17:51:22Z

Do you want to discuss an implementation proposal? @sangaman

kilrau · 2019-12-05T15:50:18Z

.

kilrau · 2020-01-21T11:38:52Z

As discussed with @sangaman , this is a simulation test task. LND/Raiden crashed need to be simulated in different phases of the swap. @LePremierHomme

kilrau · 2020-03-31T11:10:13Z

Updates? @LePremierHomme

sangaman · 2020-03-31T16:27:12Z

@LePremierHomme To elaborate on what this would entail, we want to simulate scenarios where LND abruptly shuts down or freezes in the middle of a swap. This would be part of our instability test suite. We could perhaps do this by subscribing to an invoice on lnd that's involved in a swap and immediately issuing a sigkill when we detect its status changing, then on the xud side we want to make sure that we can recover from the crash gracefully and not lose any funds.

LePremierHomme · 2020-04-09T19:44:32Z

@sangaman thanks for the details.
Few more questions:

Subscribing to an invoice on lnd involves using the swap rHash - is there a straightforward way to get it via xud RPC, before the swap started? otherwise we might need to trigger lnd kill via xud (using a custom branch).
Should lnd crash after it's streaming to subscribeSingleInvoice , and before xud is calling settleInvoice?
After lnd crashes, should it lauch immediately?
Is xud expected to recover the swap while staying up and running?
Should we implement this test for both the make and the taker sides?

sangaman · 2020-04-10T19:26:39Z

@sangaman thanks for the details.
Few more questions:

1. Subscribing to an invoice on `lnd` involves using the swap `rHash` - is there a straightforward way to get it via `xud` RPC, before the swap started? otherwise we might need to trigger `lnd` kill via `xud` (using a custom branch).

2. Should `lnd` crash after its streaming to `subscribeSingleInvoice` , and before `xud` is calling `settleInvoice`?

3. After `lnd` crashes, should it lauch immediately?

4. Is `xud` expected to recover the swap while staying up and running?

5. Should we implement this test for both the make and the taker sides?

Currently there is not, we have a SubscribeSwaps call but it only notifies for completed swaps. I think it would probably be easiest to trigger a kill via custom branch (probably can reuse the instability branch).
Yes. There are a couple ways to do it but I think ideally we would simulate being the maker (who is settling the invoice only after the taker settles), having subscribeSingleInvoice notify us that we have an incoming htlc for the swap, paying the taker, getting back the preimage, and then having lnd for the incoming payment crash before we can settleInvoice. What should happen after lnd comes back on is that xud will automatically settle the invoice for us.
Yes, I think that is fine, it should just be offline when we try to settleInvoice
Yes, xud should recover it automatically.
I think we only really need to focus on the maker because that's where funds are at risk.

LePremierHomme · 2020-04-11T15:26:22Z

After implemented the test scenario i'm see the following behaviour.
LMK is this is acceptable.

Maker

11/04/2020 14:58:45.655 [P2P] trace: Received SwapRequest packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"body\":{\"orderId\":\"f1281230-7c04-11ea-ac0c-4fc140aceb48\",\"pairId\":\"LTC/BTC\",\"proposedQuantity\":1000000,\"rHash\":\"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594\",\"takerCltvDelta\":40},\"header\":{\"id\":\"f131fd40-7c04-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:58:45.656 [ORDERBOOK] debug: added hold of 1000000 on order f1281230-7c04-11ea-ac0c-4fc140aceb48
11/04/2020 14:58:45.663 [DB] trace: Executing (default): INSERT INTO `orders` (`id`,`localId`,`initialQuantity`,`pairId`,`price`,`isBuy`,`createdAt`) VALUES ('f1281230-7c04-11ea-ac0c-4fc140aceb48','maker_order_id',1000000,'LTC/BTC',0.02,1,1586617125587);
11/04/2020 14:58:45.655 [P2P] debug: received swapRequest from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): {"proposedQuantity":1000000,"pairId":"LTC/BTC","orderId":"f1281230-7c04-11ea-ac0c-4fc140aceb48","rHash":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","takerCltvDelta":40}
11/04/2020 14:58:45.670 [SWAPS] debug: trying to accept deal: {"quantity":1000000,"localId":"maker_order_id","price":0.02,"isBuy":true} from xudPubKey: 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157
11/04/2020 14:58:45.671 [SWAPS] debug: New deal: {"proposedQuantity":1000000,"pairId":"LTC/BTC","orderId":"f1281230-7c04-11ea-ac0c-4fc140aceb48","rHash":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","takerCltvDelta":40,"price":0.02,"isBuy":true,"quantity":1000000,"makerAmount":1000000,"takerAmount":20000,"makerCurrency":"LTC","takerCurrency":"BTC","makerUnits":1000000,"takerUnits":20000,"takerPubKey":"03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb","destination":"03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb","peerPubKey":"03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157","localId":"maker_order_id","phase":0,"state":0,"role":1,"createTime":1586617125671}
11/04/2020 14:58:45.679 [LND-BTC] debug: found a route to 03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb for 20000 units with finalCltvDelta 40: 406,,20000,396923697692672,15000000,20000,,406,20000000,,03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb,true,,20000000
11/04/2020 14:58:45.684 [SWAPS] debug: got BTC block height of 366
11/04/2020 14:58:45.684 [SWAPS] debug: found route to taker with total lock duration of 40 BTC blocks (~7h)
11/04/2020 14:58:45.686 [SWAPS] debug: calculated lock buffer for first leg: 542 LTC blocks (~23h)
11/04/2020 14:58:45.687 [SWAPS] debug: lock delta for final hop to maker: 1118 LTC blocks (~47h)
11/04/2020 14:58:45.696 [LND-LTC] debug: added invoice of 1000000 for 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594 with cltvExpiry 1118
11/04/2020 14:58:45.701 [DB] trace: Executing (default): SELECT `id`, `nodePubKey`, `addressesText`, `lastAddressText`, `banned`, `createdAt`, `updatedAt` FROM `nodes` AS `Node` WHERE `Node`.`nodePubKey` = '03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157';
11/04/2020 14:58:45.710 [DB] trace: Executing (default): INSERT OR IGNORE INTO `swapdeals` (`rHash`,`role`,`state`,`phase`,`nodeId`,`orderId`,`localId`,`proposedQuantity`,`quantity`,`takerAmount`,`takerCurrency`,`takerPubKey`,`takerCltvDelta`,`makerCltvDelta`,`makerAmount`,`makerCurrency`,`createTime`) VALUES ('334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',1,0,2,1,'f1281230-7c04-11ea-ac0c-4fc140aceb48','maker_order_id',1000000,1000000,20000,'BTC','03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb',40,1118,1000000,'LTC',1586617125671); UPDATE `swapdeals` SET `proposedQuantity`=1000000,`orderId`='f1281230-7c04-11ea-ac0c-4fc140aceb48',`rHash`='334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',`takerCltvDelta`=40,`quantity`=1000000,`makerAmount`=1000000,`takerAmount`=20000,`makerCurrency`='LTC',`takerCurrency`='BTC',`takerPubKey`='03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb',`localId`='maker_order_id',`phase`=2,`state`=0,`role`=1,`createTime`=1586617125671,`makerCltvDelta`=1118,`nodeId`=1 WHERE (`rHash` = '334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594')
11/04/2020 14:58:45.717 [SWAPS] debug: sending swap accepted packet: {"makerCltvDelta":1118,"rHash":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","quantity":1000000} to peer: 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157
11/04/2020 14:58:45.719 [P2P] trace: Sent SwapAccepted packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"body\":{\"makerCltvDelta\":1118,\"quantity\":1000000,\"rHash\":\"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594\"},\"header\":{\"id\":\"f13c0f60-7c04-11ea-ac0c-4fc140aceb48\",\"reqId\":\"f131fd40-7c04-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:58:45.925 [SWAPS] debug: Executing maker code to resolve hash
11/04/2020 14:58:45.927 [DB] trace: Executing (default): SELECT `id`, `nodePubKey`, `addressesText`, `lastAddressText`, `banned`, `createdAt`, `updatedAt` FROM `nodes` AS `Node` WHERE `Node`.`nodePubKey` = '03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157';
11/04/2020 14:58:45.931 [DB] trace: Executing (default): INSERT OR IGNORE INTO `swapdeals` (`rHash`,`role`,`state`,`phase`,`nodeId`,`orderId`,`localId`,`proposedQuantity`,`quantity`,`takerAmount`,`takerCurrency`,`takerPubKey`,`takerCltvDelta`,`makerCltvDelta`,`makerAmount`,`makerCurrency`,`createTime`,`executeTime`) VALUES ('334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',1,0,3,1,'f1281230-7c04-11ea-ac0c-4fc140aceb48','maker_order_id',1000000,1000000,20000,'BTC','03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb',40,1118,1000000,'LTC',1586617125671,1586617125925); UPDATE `swapdeals` SET `proposedQuantity`=1000000,`orderId`='f1281230-7c04-11ea-ac0c-4fc140aceb48',`rHash`='334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',`takerCltvDelta`=40,`quantity`=1000000,`makerAmount`=1000000,`takerAmount`=20000,`makerCurrency`='LTC',`takerCurrency`='BTC',`takerPubKey`='03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb',`localId`='maker_order_id',`phase`=3,`state`=0,`role`=1,`createTime`=1586617125671,`makerCltvDelta`=1118,`executeTime`=1586617125925,`nodeId`=1 WHERE (`rHash` = '334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594')
11/04/2020 14:58:45.937 [LND-BTC] trace: sending payment with {"dest":"","destString":"03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb","amt":20000,"paymentHash":"","paymentHashString":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","paymentRequest":"","finalCltvDelta":40,"feeLimit":{"fixed":600,"percent":0},"outgoingChanId":0,"cltvLimit":83,"destTlvMap":[]}
11/04/2020 14:58:45.937 [LND-BTC] trace: sending payment of 20000 for 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594
11/04/2020 14:58:46.133 [SWAPS] info: #CUSTOM CODE# BREAKSWAP: MAKER_LND_CRASHED_BEFORE_SETTLE
11/04/2020 14:58:46.133 [SWAPS] info: #CUSTOM CODE# LNDLTC_PID: 3988 (kill)
11/04/2020 14:58:46.453 [LND-LTC] debug: deleted invoice subscription for 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594
11/04/2020 14:58:47.432 [LND-LTC] info: LndClient status: Disconnected
11/04/2020 14:58:47.433 [LND-LTC] trace: error on channelBalance: 14 UNAVAILABLE: failed to connect to all addresses
11/04/2020 14:58:47.434 [LND-LTC] error: failed to update total outbound capacity: Error: 14 UNAVAILABLE: failed to connect to all addresses
    at Object.exports.createStatusError (/custom-xud-vol/instability_draft/node_modules/grpc/src/common.js:91:15)
    at Object.onReceiveStatus (/custom-xud-vol/instability_draft/node_modules/grpc/src/client_interceptors.js:1209:28)
    at InterceptingListener._callNext (/custom-xud-vol/instability_draft/node_modules/grpc/src/client_interceptors.js:568:42)
    at InterceptingListener.onReceiveStatus (/custom-xud-vol/instability_draft/node_modules/grpc/src/client_interceptors.js:618:8)
    at callback (/custom-xud-vol/instability_draft/node_modules/grpc/src/client_interceptors.js:847:24)
11/04/2020 14:58:47.434 [LND-BTC] debug: new total outbound capacity: 7470950
11/04/2020 14:58:49.433 [LND-LTC] info: trying to verify connection to lnd at 127.0.0.1:40695
11/04/2020 14:58:51.135 [SWAPS] error: could not settle invoice: 4.2 - lnd-LTC is Disconnected
11/04/2020 14:58:55.435 [LND-LTC] trace: error on getInfo: 14 UNAVAILABLE: failed to connect to all addresses
11/04/2020 14:58:55.435 [LND-LTC] error: could not verify connection at 127.0.0.1:40695, error: {"code":14,"metadata":{"_internal_repr":{},"flags":0},"details":"failed to connect to all addresses"}, retrying in 5000 ms
11/04/2020 14:59:00.436 [LND-LTC] info: trying to verify connection to lnd at 127.0.0.1:40695
11/04/2020 14:59:09.733 [LND-LTC] debug: new total outbound capacity: 7455200
11/04/2020 14:59:09.736 [LND-LTC] info: LndClient status: ConnectionVerified
11/04/2020 14:59:15.531 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"030102a0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:15.534 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"030129b0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:59:15.535 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"030150c0-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"030102a0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:15.536 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"03019ee0-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"030129b0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:59:15.672 [SWAPS] debug: deal 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594 failed due to SwapTimedOut
11/04/2020 14:59:15.675 [ORDERBOOK] debug: removed hold of 1000000 on order f1281230-7c04-11ea-ac0c-4fc140aceb48
11/04/2020 14:59:15.675 [SWAPS] debug: Sending swap error to peer: {"rHash":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","failureReason":10}
11/04/2020 14:59:15.677 [P2P] trace: Sent SwapFailed packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"body\":{\"failureReason\":10,\"rHash\":\"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594\"},\"header\":{\"id\":\"031749c0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:15.684 [DB] trace: Executing (default): SELECT `id`, `nodePubKey`, `addressesText`, `lastAddressText`, `banned`, `createdAt`, `updatedAt` FROM `nodes` AS `Node` WHERE `Node`.`nodePubKey` = '03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157';
11/04/2020 14:59:15.685 [DB] trace: Executing (default): SELECT `SwapDeal`.`rHash`, `SwapDeal`.`role`, `SwapDeal`.`state`, `SwapDeal`.`phase`, `SwapDeal`.`failureReason`, `SwapDeal`.`errorMessage`, `SwapDeal`.`rPreimage`, `SwapDeal`.`nodeId`, `SwapDeal`.`orderId`, `SwapDeal`.`localId`, `SwapDeal`.`proposedQuantity`, `SwapDeal`.`quantity`, `SwapDeal`.`takerAmount`, `SwapDeal`.`takerCurrency`, `SwapDeal`.`takerPubKey`, `SwapDeal`.`takerCltvDelta`, `SwapDeal`.`makerCltvDelta`, `SwapDeal`.`makerAmount`, `SwapDeal`.`makerCurrency`, `SwapDeal`.`createTime`, `SwapDeal`.`executeTime`, `SwapDeal`.`completeTime`, `Node`.`id` AS `Node.id`, `Node`.`nodePubKey` AS `Node.nodePubKey`, `Node`.`addressesText` AS `Node.addressesText`, `Node`.`lastAddressText` AS `Node.lastAddressText`, `Node`.`banned` AS `Node.banned`, `Node`.`createdAt` AS `Node.createdAt`, `Node`.`updatedAt` AS `Node.updatedAt`, `Order`.`id` AS `Order.id`, `Order`.`nodeId` AS `Order.nodeId`, `Order`.`localId` AS `Order.localId`, `Order`.`initialQuantity` AS `Order.initialQuantity`, `Order`.`pairId` AS `Order.pairId`, `Order`.`price` AS `Order.price`, `Order`.`isBuy` AS `Order.isBuy`, `Order`.`createdAt` AS `Order.createdAt` FROM `swapdeals` AS `SwapDeal` LEFT OUTER JOIN `nodes` AS `Node` ON `SwapDeal`.`nodeId` = `Node`.`id` LEFT OUTER JOIN `orders` AS `Order` ON `SwapDeal`.`orderId` = `Order`.`id` WHERE `SwapDeal`.`rHash` = '334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594';
11/04/2020 14:59:15.688 [DB] trace: Executing (default): INSERT INTO `reputationEvents` (`id`,`event`,`nodeId`,`createdAt`) VALUES (NULL,7,1,'2020-04-11 14:59:15.673 +00:00');
11/04/2020 14:59:15.688 [DB] trace: Executing (default): INSERT INTO `reputationEvents` (`id`,`event`,`nodeId`,`createdAt`) VALUES (NULL,6,1,'2020-04-11 14:59:15.673 +00:00');
11/04/2020 14:59:15.697 [DB] trace: Executing (default): INSERT OR IGNORE INTO `swapdeals` (`rHash`,`role`,`state`,`phase`,`failureReason`,`rPreimage`,`nodeId`,`orderId`,`localId`,`proposedQuantity`,`quantity`,`takerAmount`,`takerCurrency`,`takerPubKey`,`takerCltvDelta`,`makerCltvDelta`,`makerAmount`,`makerCurrency`,`createTime`,`executeTime`,`completeTime`) VALUES ('334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',1,1,3,10,'e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d',1,'f1281230-7c04-11ea-ac0c-4fc140aceb48','maker_order_id',1000000,1000000,20000,'BTC','03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb',40,1118,1000000,'LTC',1586617125671,1586617125925,1586617155674); UPDATE `swapdeals` SET `proposedQuantity`=1000000,`orderId`='f1281230-7c04-11ea-ac0c-4fc140aceb48',`rHash`='334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',`takerCltvDelta`=40,`quantity`=1000000,`makerAmount`=1000000,`takerAmount`=20000,`makerCurrency`='LTC',`takerCurrency`='BTC',`takerPubKey`='03c31fa3de5378fbf11b76671ac482e75549d9ea53ea20d9f0cde96d6594e9c9cb',`localId`='maker_order_id',`phase`=3,`state`=1,`role`=1,`createTime`=1586617125671,`makerCltvDelta`=1118,`executeTime`=1586617125925,`rPreimage`='e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d',`completeTime`=1586617155674,`failureReason`=10,`nodeId`=1 WHERE (`rHash` = '334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594')
11/04/2020 14:59:45.535 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"14e31ad0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:45.538 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"14e341e0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:59:45.539 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"14e3b710-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"14e31ad0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:45.540 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"14e3de20-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"14e341e0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:00:15.534 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"26c496c0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:00:15.536 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"26c4bdd0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:00:15.537 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"26c50bf0-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"26c496c0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:00:15.538 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"26c53300-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"26c4bdd0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:00:45.535 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"38a6aef0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:00:45.538 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"38a6aef0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:00:45.538 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"38a6fd10-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"38a6aef0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:00:45.539 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"38a72420-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"38a6aef0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:15.524 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"4a865620-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:15.526 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"4a867d30-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:01:15.526 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"4a86cb50-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"4a865620-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:15.528 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"4a86f260-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"4a867d30-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:01:45.522 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"5c6783f0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:45.523 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"5c67d210-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:01:45.524 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"5c682030-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"5c6783f0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:45.526 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"5c684740-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"5c67d210-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:02:15.534 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"6e49c330-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:02:15.537 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"6e494e00-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:02:15.538 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"6e4be610-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"6e494e00-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:02:15.547 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"6e4d1e90-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"6e49c330-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:02:45.523 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"802b3f20-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:02:45.524 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"802b6630-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"802b3f20-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:02:45.525 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"802b8d40-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:02:45.527 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"802bdb60-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"802b8d40-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:03:15.530 [P2P] trace: Received Ping packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"920d3040-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:03:15.532 [P2P] trace: Sent Pong packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"920e1aa0-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"920d3040-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:03:15.533 [P2P] trace: Sent Ping packet to 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"920e41b0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:03:15.535 [P2P] trace: Received Pong packet from 03d571e2bfb02fc32dad1f81c04fa008f8da982022b2a0181a0fc7ebd22b67e157 (BrassCaptain): "{\"header\":{\"id\":\"920eb6e0-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"920e41b0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:03:44.472 [SWAPS] info: recovering swap deal 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594
11/04/2020 15:03:44.508 [SWAPS] info: recovered LTC swap payment of 1000000 using preimage e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d
11/04/2020 15:03:44.520 [DB] trace: Executing (default): UPDATE `swapdeals` SET `state`=3,`rPreimage`='e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d' WHERE `rHash` = '334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594'
11/04/2020 15:03:44.565 [LND-LTC] debug: new total outbound capacity: 8463800

maker is trying to resolve hash, sending his payment and getting the preimage in return
maker's lnd-ltc crashed
maker is unable to settle invoice
maker is failing the swap due to SwapTimedOut (although lnd-ltc was already restarted and connection was verified).
after 5 min, the LTC swap payment was recovered

Taker

11/04/2020 14:58:45.628 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
11/04/2020 14:58:45.631 [ORDERBOOK] debug: matched with peer 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit), executing swap on taker f12e7ad0-7c04-11ea-892d-913faa0b9b31 and maker f1281230-7c04-11ea-ac0c-4fc140aceb48 for 1000000
11/04/2020 14:58:45.635 [DB] trace: Executing (default): INSERT INTO `orders` (`id`,`initialQuantity`,`pairId`,`price`,`isBuy`,`createdAt`) VALUES ('f1281230-7c04-11ea-ac0c-4fc140aceb48',1000000,'LTC/BTC',0.02,1,1586617125596);
11/04/2020 14:58:45.649 [LND-LTC] debug: found a route to 03b696167f1adc170597e2c23f3a12afc707491fbda2d0e8aa441e5d9ce3f6bad5 for 1000000 units with finalCltvDelta 576: 942,,1000000,396923697692672,15000000,1000000,,942,1000000000,,03b696167f1adc170597e2c23f3a12afc707491fbda2d0e8aa441e5d9ce3f6bad5,true,,1000000000
11/04/2020 14:58:45.651 [SWAPS] debug: New deal: {"takerCltvDelta":40,"rHash":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","orderId":"f1281230-7c04-11ea-ac0c-4fc140aceb48","pairId":"LTC/BTC","proposedQuantity":1000000,"rPreimage":"e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d","takerCurrency":"BTC","makerCurrency":"LTC","takerAmount":20000,"makerAmount":1000000,"takerUnits":20000,"makerUnits":1000000,"destination":"03b696167f1adc170597e2c23f3a12afc707491fbda2d0e8aa441e5d9ce3f6bad5","peerPubKey":"03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf","localId":"taker_order_id","price":0.02,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1586617125650}
11/04/2020 14:58:45.654 [P2P] trace: Sent SwapRequest packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"body\":{\"orderId\":\"f1281230-7c04-11ea-ac0c-4fc140aceb48\",\"pairId\":\"LTC/BTC\",\"proposedQuantity\":1000000,\"rHash\":\"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594\",\"takerCltvDelta\":40},\"header\":{\"id\":\"f131fd40-7c04-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:58:45.655 [SWAPS] debug: Requesting deal: {"takerCltvDelta":40,"rHash":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","orderId":"f1281230-7c04-11ea-ac0c-4fc140aceb48","pairId":"LTC/BTC","proposedQuantity":1000000,"rPreimage":"e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d","takerCurrency":"BTC","makerCurrency":"LTC","takerAmount":20000,"makerAmount":1000000,"takerUnits":20000,"makerUnits":1000000,"destination":"03b696167f1adc170597e2c23f3a12afc707491fbda2d0e8aa441e5d9ce3f6bad5","peerPubKey":"03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf","localId":"taker_order_id","price":0.02,"isBuy":true,"phase":0,"state":0,"role":0,"createTime":1586617125650}
11/04/2020 14:58:45.720 [P2P] trace: Received SwapAccepted packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"body\":{\"makerCltvDelta\":1118,\"quantity\":1000000,\"rHash\":\"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594\"},\"header\":{\"id\":\"f13c0f60-7c04-11ea-ac0c-4fc140aceb48\",\"reqId\":\"f131fd40-7c04-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:58:45.720 [P2P] debug: received swapAccepted from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): {"rHash":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","quantity":1000000,"makerCltvDelta":1118}
11/04/2020 14:58:45.728 [LND-BTC] debug: added invoice of 20000 for 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594 with cltvExpiry 40
11/04/2020 14:58:45.732 [DB] trace: Executing (default): SELECT `id`, `nodePubKey`, `addressesText`, `lastAddressText`, `banned`, `createdAt`, `updatedAt` FROM `nodes` AS `Node` WHERE `Node`.`nodePubKey` = '03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf';
11/04/2020 14:58:45.741 [DB] trace: Executing (default): INSERT OR IGNORE INTO `swapdeals` (`rHash`,`role`,`state`,`phase`,`rPreimage`,`nodeId`,`orderId`,`localId`,`proposedQuantity`,`quantity`,`takerAmount`,`takerCurrency`,`takerCltvDelta`,`makerCltvDelta`,`makerAmount`,`makerCurrency`,`createTime`,`executeTime`) VALUES ('334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',0,0,3,'e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d',1,'f1281230-7c04-11ea-ac0c-4fc140aceb48','taker_order_id',1000000,1000000,20000,'BTC',40,1118,1000000,'LTC',1586617125650,1586617125729); UPDATE `swapdeals` SET `takerCltvDelta`=40,`rHash`='334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',`orderId`='f1281230-7c04-11ea-ac0c-4fc140aceb48',`proposedQuantity`=1000000,`rPreimage`='e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d',`takerCurrency`='BTC',`makerCurrency`='LTC',`takerAmount`=20000,`makerAmount`=1000000,`localId`='taker_order_id',`phase`=3,`state`=0,`role`=0,`createTime`=1586617125650,`makerCltvDelta`=1118,`quantity`=1000000,`executeTime`=1586617125729,`nodeId`=1 WHERE (`rHash` = '334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594')
11/04/2020 14:58:45.749 [LND-LTC] trace: sending payment with {"dest":"","destString":"03b696167f1adc170597e2c23f3a12afc707491fbda2d0e8aa441e5d9ce3f6bad5","amt":1000000,"paymentHash":"","paymentHashString":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","paymentRequest":"","finalCltvDelta":1118,"feeLimit":{"fixed":30000,"percent":0},"outgoingChanId":0,"cltvLimit":0,"destTlvMap":[]}
11/04/2020 14:58:45.749 [LND-LTC] trace: sending payment of 1000000 for 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594
11/04/2020 14:58:46.099 [SWAPS] debug: Executing taker code to resolve hash
11/04/2020 14:58:46.103 [LND-BTC] debug: settled invoice for 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594
11/04/2020 14:58:46.104 [SWAPS] debug: Payment received for deal with payment hash e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d
11/04/2020 14:58:46.106 [LND-BTC] debug: deleted invoice subscription for 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594
11/04/2020 14:58:46.107 [DB] trace: Executing (default): SELECT `id`, `nodePubKey`, `addressesText`, `lastAddressText`, `banned`, `createdAt`, `updatedAt` FROM `nodes` AS `Node` WHERE `Node`.`nodePubKey` = '03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf';
11/04/2020 14:58:46.111 [DB] trace: Executing (default): INSERT OR IGNORE INTO `swapdeals` (`rHash`,`role`,`state`,`phase`,`rPreimage`,`nodeId`,`orderId`,`localId`,`proposedQuantity`,`quantity`,`takerAmount`,`takerCurrency`,`takerCltvDelta`,`makerCltvDelta`,`makerAmount`,`makerCurrency`,`createTime`,`executeTime`) VALUES ('334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',0,0,4,'e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d',1,'f1281230-7c04-11ea-ac0c-4fc140aceb48','taker_order_id',1000000,1000000,20000,'BTC',40,1118,1000000,'LTC',1586617125650,1586617125729); UPDATE `swapdeals` SET `takerCltvDelta`=40,`rHash`='334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',`orderId`='f1281230-7c04-11ea-ac0c-4fc140aceb48',`proposedQuantity`=1000000,`rPreimage`='e7eb90fd8089fc2726df04a96ef0dd2d85b093b51c4e89ed6a21758b8d2e579d',`takerCurrency`='BTC',`makerCurrency`='LTC',`takerAmount`=20000,`makerAmount`=1000000,`localId`='taker_order_id',`phase`=4,`state`=0,`role`=0,`createTime`=1586617125650,`makerCltvDelta`=1118,`quantity`=1000000,`executeTime`=1586617125729,`nodeId`=1 WHERE (`rHash` = '334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594')
11/04/2020 14:58:46.123 [DB] trace: Executing (default): INSERT INTO `orders` (`id`,`initialQuantity`,`pairId`,`price`,`isBuy`,`createdAt`) VALUES ('f1281230-7c04-11ea-ac0c-4fc140aceb48',1000000,'LTC/BTC',0.02,1,1586617125596);
11/04/2020 14:58:46.124 [DB] trace: Executing (default): INSERT INTO `orders` (`id`,`localId`,`initialQuantity`,`pairId`,`price`,`isBuy`,`createdAt`) VALUES ('f12e7ad0-7c04-11ea-892d-913faa0b9b31','taker_order_id',1000000,'LTC/BTC',0.02,0,1586617125629);
11/04/2020 14:58:46.137 [DB] trace: Executing (default): INSERT INTO `trades` (`id`,`makerOrderId`,`takerOrderId`,`rHash`,`quantity`,`createdAt`) VALUES (NULL,'f1281230-7c04-11ea-ac0c-4fc140aceb48','f12e7ad0-7c04-11ea-892d-913faa0b9b31','334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594',1000000,'2020-04-11 14:58:46.132 +00:00');
11/04/2020 14:58:46.145 [ORDERBOOK] info: match executed on taker f12e7ad0-7c04-11ea-892d-913faa0b9b31 and maker f1281230-7c04-11ea-ac0c-4fc140aceb48 for 1000000 with peer 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit)
11/04/2020 14:58:46.147 [RPC] trace: call /xudrpc.Xud/PlaceOrderSync succeeded
11/04/2020 14:58:46.428 [LND-BTC] debug: new total outbound capacity: 7520000
11/04/2020 14:58:46.432 [LND-LTC] debug: new total outbound capacity: 6500000
11/04/2020 14:59:15.532 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"030102a0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:15.533 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"030129b0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:59:15.534 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"030150c0-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"030102a0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:15.537 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"03019ee0-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"030129b0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:59:15.678 [P2P] trace: Received SwapFailed packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"body\":{\"failureReason\":10,\"rHash\":\"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594\"},\"header\":{\"id\":\"031749c0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:15.680 [SWAPS] debug: deal 334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594 failed due to SwapTimedOut
11/04/2020 14:59:15.686 [DB] trace: Executing (default): SELECT `id`, `nodePubKey`, `addressesText`, `lastAddressText`, `banned`, `createdAt`, `updatedAt` FROM `nodes` AS `Node` WHERE `Node`.`nodePubKey` = '03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf';
11/04/2020 14:59:15.679 [P2P] debug: received swapFailed from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): {"rHash":"334a23f10fa871bb63f72cd13b9ebd0e1ab5338e6a90e38fb776f3c4cdbb0594","failureReason":10}
11/04/2020 14:59:15.689 [DB] trace: Executing (default): INSERT INTO `reputationEvents` (`id`,`event`,`nodeId`,`createdAt`) VALUES (NULL,7,1,'2020-04-11 14:59:15.681 +00:00');
11/04/2020 14:59:15.690 [DB] trace: Executing (default): INSERT INTO `reputationEvents` (`id`,`event`,`nodeId`,`createdAt`) VALUES (NULL,6,1,'2020-04-11 14:59:15.681 +00:00');
11/04/2020 14:59:15.706 [DB] trace: Executing (default): INSERT OR IGNORE INTO `swapdeals` (`rHash`,`role`,`state`,`phase`,`failureReas
11/04/2020 14:59:45.536 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"14e31ad0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:45.537 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"14e341e0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 14:59:45.538 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"14e3b710-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"14e31ad0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 14:59:45.540 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"14e3de20-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"14e341e0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:00:15.534 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"26c496c0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:00:15.536 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"26c4bdd0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:00:15.536 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"26c50bf0-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"26c496c0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:00:15.538 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"26c53300-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"26c4bdd0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:00:45.537 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"38a6aef0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:00:45.537 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"38a6aef0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:00:45.538 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"38a6fd10-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"38a6aef0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:00:45.539 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"38a72420-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"38a6aef0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:15.523 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"4a865620-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:15.526 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"4a867d30-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:01:15.527 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"4a86cb50-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"4a865620-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:15.527 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"4a86f260-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"4a867d30-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:01:45.521 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"5c6783f0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:45.524 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"5c67d210-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:01:45.525 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"5c682030-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"5c6783f0-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:01:45.525 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"5c684740-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"5c67d210-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:02:15.539 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"6e494e00-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:02:15.544 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"6e49c330-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:02:15.544 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"6e4be610-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"6e494e00-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:02:15.546 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"6e4d1e90-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"6e49c330-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:02:45.523 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"802b3f20-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:02:45.525 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"802b6630-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"802b3f20-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:02:45.526 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"802b8d40-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:02:45.527 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"802bdb60-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"802b8d40-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:03:15.527 [P2P] trace: Sent Ping packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"920d3040-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:03:15.532 [P2P] trace: Received Pong packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"920e1aa0-7c05-11ea-ac0c-4fc140aceb48\",\"reqId\":\"920d3040-7c05-11ea-892d-913faa0b9b31\"}}"
11/04/2020 15:03:15.533 [P2P] trace: Received Ping packet from 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"920e41b0-7c05-11ea-ac0c-4fc140aceb48\"}}"
11/04/2020 15:03:15.534 [P2P] trace: Sent Pong packet to 03f7ea342b64b0e4e88a2535e9b840963c4e5b6362572a9726dd2a250c119031bf (IssueQuit): "{\"header\":{\"id\":\"920eb6e0-7c05-11ea-892d-913faa0b9b31\",\"reqId\":\"920e41b0-7c05-11ea-ac0c-4fc140aceb48\"}}"

swap was triggered and completed successfully
SwapFailed packet was received afterwards, and the deal was marked as such

sangaman · 2020-04-14T06:44:09Z

Yes that looks exactly correct, thank you. If you want to reduce the wait time down from 5 minutes for the modified branch code, you can look into changing or replacing this value https://github.com/ExchangeUnion/xud/blob/master/lib/swaps/SwapRecovery.ts#L18.

LePremierHomme · 2020-04-14T15:40:54Z

Just want to make sure that we don't want to consider these improvements:

maker to verify the ability to complete the swap before timing out (step 4)
taker to ignore swap packets after it already completed locally (if that can potentially corrupt the trading history)

kilrau · 2020-04-15T10:30:31Z

maker to verify the ability to complete the swap before timing out (step 4)

This sounds like a very reasonable improvement to our swap logic. wdyt? @sangaman If you agree, let's open an issue.

taker to ignore swap packets after it already completed locally (if that can potentially corrupt the trading history)

Your example above indeed shows that this trade should be marked as "SwapCompleted" for the taker. Nevertheless I would not simply ignore the Makers SwapFailed Message, but store it somewhere in addition. The trade history should show if the other party reported a different state than we have locally. wdyt? @sangaman

kilrau · 2020-04-15T10:33:59Z

Also afai understand it you implemented one scenario with the maker lnd crashing after sending the second payment. I agree this is the most critical scenario. Did you come up with any other relevant scenarios we should cover here? @LePremierHomme

LePremierHomme · 2020-04-15T11:38:41Z

It might worth having a scenario where xud crashes as well, in addition to lnd.

Besides that, we can simulate the same things on the taker side - more for testing the functionality, as the funds are less at risk.

kilrau · 2020-04-15T15:15:38Z

Lets wait for @sangaman to chime in

LePremierHomme · 2020-05-08T13:27:08Z

Closed by #1484

kilrau added question/tbd Further information or discussion needed P1 top priority labels Aug 5, 2019

kilrau assigned ghost and sangaman Aug 5, 2019

kilrau removed the P1 top priority label Aug 5, 2019

kilrau added P1 top priority lightning Lightning network & lnd integration raiden security securing xud from unauthorized actions swaps labels Aug 29, 2019

kilrau changed the title ~~Handle Raiden/LND crashes~~ Recover from Raiden/LND crashes while swapping Aug 29, 2019

kilrau unassigned ghost Oct 9, 2019

kilrau assigned LePremierHomme Jan 21, 2020

kilrau added the automated tests label Jan 21, 2020

kilrau unassigned sangaman Jan 21, 2020

LePremierHomme mentioned this issue Feb 28, 2020

Simulation tests dev roadmap - beta.4 #1356

Closed

16 tasks

kilrau changed the title ~~Recover from Raiden/LND crashes while swapping~~ Recover from LND crashes while swapping Apr 3, 2020

LePremierHomme mentioned this issue Apr 17, 2020

test(sim): maker lnd to crash before order settlement #1484

Merged

LePremierHomme closed this as completed May 8, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Recover from LND crashes while swapping #1126

Recover from LND crashes while swapping #1126

kilrau commented Aug 5, 2019 •

edited

Loading

kilrau commented Aug 29, 2019

kilrau commented Oct 9, 2019

kilrau commented Dec 5, 2019

kilrau commented Jan 21, 2020

kilrau commented Mar 31, 2020

sangaman commented Mar 31, 2020

LePremierHomme commented Apr 9, 2020 •

edited

Loading

sangaman commented Apr 10, 2020

LePremierHomme commented Apr 11, 2020 •

edited

Loading

sangaman commented Apr 14, 2020

LePremierHomme commented Apr 14, 2020

kilrau commented Apr 15, 2020

kilrau commented Apr 15, 2020

LePremierHomme commented Apr 15, 2020

kilrau commented Apr 15, 2020

LePremierHomme commented May 8, 2020

Recover from LND crashes while swapping #1126

Recover from LND crashes while swapping #1126

Comments

kilrau commented Aug 5, 2019 • edited Loading

kilrau commented Aug 29, 2019

kilrau commented Oct 9, 2019

kilrau commented Dec 5, 2019

kilrau commented Jan 21, 2020

kilrau commented Mar 31, 2020

sangaman commented Mar 31, 2020

LePremierHomme commented Apr 9, 2020 • edited Loading

sangaman commented Apr 10, 2020

LePremierHomme commented Apr 11, 2020 • edited Loading

Maker

Taker

sangaman commented Apr 14, 2020

LePremierHomme commented Apr 14, 2020

kilrau commented Apr 15, 2020

kilrau commented Apr 15, 2020

LePremierHomme commented Apr 15, 2020

kilrau commented Apr 15, 2020

LePremierHomme commented May 8, 2020

kilrau commented Aug 5, 2019 •

edited

Loading

LePremierHomme commented Apr 9, 2020 •

edited

Loading

LePremierHomme commented Apr 11, 2020 •

edited

Loading