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.

Sign up for GitHub

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

Jump to bottom

xud crashing after a failed swap #1701

Closed
ghost opened this issue Jun 30, 2020 · 3 comments · Fixed by #1705
Closed

xud crashing after a failed swap #1701

ghost opened this issue Jun 30, 2020 · 3 comments · Fixed by #1705
Assignees
@sangaman
Labels
bug Something isn't working P1 top priority

Comments

@ghost
Copy link

ghost commented Jun 30, 2020

Off-shoot from: #1691 (comment)
@ghost ghost added bug Something isn't working P1 top priority labels Jun 30, 2020
@ghost ghost assigned sangaman Jun 30, 2020
@ghost ghost mentioned this issue Jun 30, 2020
Open
@ghost
Copy link
Author

ghost commented Jun 30, 2020

Relevant maker logs:

30/06/2020 11:43:12.606 [RPC] debug: received call /xudrpc.Xud/GetBalance
30/06/2020 11:43:14.928 [P2P] debug: received swapRequest from 0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6 (ChangeTurn): {"proposedQuantity":300000,"pairId":"ETH/BTC","orderId":"e01b2df0-bac6-11ea-8579-af2cf3d85191","rHash":"e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72","takerCltvDelta":200}
30/06/2020 11:43:14.928 [ORDERBOOK] debug: added hold of 300000 on order e01b2df0-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:14.932 [SWAPS] debug: trying to accept deal: {"quantity":300000,"localId":"4a098298-a03c-4ddd-86ff-4ae92ef76970","price":0.02634206,"isBuy":false} from xudPubKey: 0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6
30/06/2020 11:43:14.933 [SWAPS] debug: New deal: {"rHash":"e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72","pairId":"ETH/BTC","proposedQuantity":300000,"orderId":"e01b2df0-bac6-11ea-8579-af2cf3d85191","price":0.02634206,"isBuy":false,"quantity":300000,"makerAmount":7903,"takerAmount":300000,"makerCurrency":"BTC","takerCurrency":"ETH","makerUnits":7903,"takerUnits":3000000000000000,"takerCltvDelta":200,"takerPubKey":"indra62JM1LTtvMkfqXWcKVTJQMKNuDVcZVzkLrjxwmja1hADq9iHQb","destination":"indra62JM1LTtvMkfqXWcKVTJQMKNuDVcZVzkLrjxwmja1hADq9iHQb","peerPubKey":"0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6","localId":"4a098298-a03c-4ddd-86ff-4ae92ef76970","phase":0,"state":0,"role":1,"createTime":1593517394933}
30/06/2020 11:43:14.933 [SWAPS] debug: got ETH block height of 1
30/06/2020 11:43:14.933 [SWAPS] debug: found route to taker with total lock duration of 100 ETH blocks (~0h)
30/06/2020 11:43:14.933 [SWAPS] debug: calculated lock buffer for first leg: 22 BTC blocks (~4h)
30/06/2020 11:43:14.933 [SWAPS] debug: lock delta for final hop to maker: 166 BTC blocks (~28h)
30/06/2020 11:43:14.935 [LND-BTC] debug: added invoice of 7903 for e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72 with cltvExpiry 166
30/06/2020 11:43:14.936 [SWAPS] debug: Setting SwapAccepted phase for deal e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72
30/06/2020 11:43:14.937 [SWAPS] debug: sending swap accepted packet: {"rHash":"e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72","makerCltvDelta":166,"quantity":300000} to peer: 0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6
30/06/2020 11:43:15.076 [LND-BTC] debug: accepted htlc for invoice e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72
30/06/2020 11:43:15.076 [SWAPS] debug: Executing maker code to resolve hash
30/06/2020 11:43:15.076 [SWAPS] debug: Setting SendingPayment phase for deal e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72
30/06/2020 11:43:15.082 [CONNEXT] debug: sending payment of 3000000000000000 with hash 0xe22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72 to indra62JM1LTtvMkfqXWcKVTJQMKNuDVcZVzkLrjxwmja1hADq9iHQb
30/06/2020 11:43:17.316 [RPC] debug: received call /xudrpc.Xud/ListOrders
30/06/2020 11:43:17.329 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:17.330 [ORDERBOOK] debug: order removed: e01b5500-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:17.331 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:17.332 [ORDERBOOK] debug: order quantity reduced by 252731274: e01b2df0-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:17.351 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:17.351 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.02634736,"quantity":252980375,"isBuy":false,"localId":"41db00a6-51d5-405c-8952-c873146a5b66","id":"e3a14770-bac6-11ea-8579-af2cf3d85191","initialQuantity":252980375,"hold":0,"createdAt":1593517397351}
30/06/2020 11:43:17.352 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:17.353 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.02336464,"quantity":385324405,"isBuy":true,"localId":"ff546b58-8e32-44a6-bf39-3f4bbe84a330","id":"e3a19590-bac6-11ea-8579-af2cf3d85191","initialQuantity":385324405,"hold":0,"createdAt":1593517397353}
30/06/2020 11:43:21.521 [CONNEXT] error: connext server error 500: Internal Server Error
30/06/2020 11:43:21.522 [SWAPS] debug: sendPayment in resolveHash failed due to connext server error
30/06/2020 11:43:21.661 [CONNEXT] error: connext server error 500: Internal Server Error
30/06/2020 11:43:21.668 [CONNEXT] error: connext server error
30/06/2020 11:43:21.669 [SWAPS] error: could not resolve hash for deal e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72: 8.5 - connext server error
30/06/2020 11:43:23.463 [RPC] debug: received call /xudrpc.Xud/GetBalance
30/06/2020 11:43:24.031 [RPC] debug: received call /xudrpc.Xud/ListOrders
30/06/2020 11:43:24.038 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:24.038 [ORDERBOOK] debug: order removed: e3a19590-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:24.040 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:24.041 [ORDERBOOK] debug: order removed: e3a14770-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:24.060 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:24.062 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.02633994,"quantity":253051639,"isBuy":false,"localId":"8d734fee-8c9b-40cd-990d-1bad99d5d657","id":"e7a124d0-bac6-11ea-8579-af2cf3d85191","initialQuantity":253051639,"hold":0,"createdAt":1593517404061}
30/06/2020 11:43:24.064 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:24.066 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.02335806,"quantity":385432951,"isBuy":true,"localId":"2f465124-f99b-4dcc-9b7f-718c25f9c840","id":"e7a1c110-bac6-11ea-8579-af2cf3d85191","initialQuantity":385432951,"hold":0,"createdAt":1593517404065}
30/06/2020 11:43:25.104 [RPC] debug: received call /xudrpc.Xud/ListOrders
30/06/2020 11:43:25.111 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:25.112 [ORDERBOOK] debug: order removed: e7a1c110-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:25.114 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:25.115 [ORDERBOOK] debug: order removed: e7a124d0-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:25.130 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:25.140 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.02634418,"quantity":253010912,"isBuy":false,"localId":"c1061db8-4527-4f60-959e-1fcf99cc057e","id":"e845a230-bac6-11ea-8579-af2cf3d85191","initialQuantity":253010912,"hold":0,"createdAt":1593517405139}
30/06/2020 11:43:25.142 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:25.143 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.02336182,"quantity":385370917,"isBuy":true,"localId":"9ef666c2-2127-41eb-9730-e72d3a6e7070","id":"e8461760-bac6-11ea-8579-af2cf3d85191","initialQuantity":385370917,"hold":0,"createdAt":1593517405142}
30/06/2020 11:43:32.169 [RPC] debug: received call /xudrpc.Xud/GetBalance
30/06/2020 11:43:32.174 [RPC] debug: received call /xudrpc.Xud/TradingLimits
30/06/2020 11:43:32.194 [LND-BTC] debug: new channel inbound capacity: 6657462
30/06/2020 11:43:32.741 [RPC] debug: received call /xudrpc.Xud/ListOrders
30/06/2020 11:43:32.749 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:32.750 [ORDERBOOK] debug: order removed: e8461760-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:32.753 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:32.754 [ORDERBOOK] debug: order removed: e845a230-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:32.774 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:32.775 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.02634418,"quantity":252710921,"isBuy":false,"localId":"9c30fb38-a40f-459f-a85a-e16f8bf2aaeb","id":"ecd2a460-bac6-11ea-8579-af2cf3d85191","initialQuantity":252710921,"hold":0,"createdAt":1593517412774}
30/06/2020 11:43:32.777 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:32.778 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.02336182,"quantity":385370917,"isBuy":true,"localId":"4ba60dfe-e6f4-4656-b7c0-3569ef62a473","id":"ecd31990-bac6-11ea-8579-af2cf3d85191","initialQuantity":385370917,"hold":0,"createdAt":1593517412778}
30/06/2020 11:43:34.283 [RPC] debug: received call /xudrpc.Xud/GetBalance
30/06/2020 11:43:38.310 [RPC] debug: received call /xudrpc.Xud/ListOrders
30/06/2020 11:43:38.317 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:38.318 [ORDERBOOK] debug: order removed: ecd31990-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:38.319 [RPC] debug: received call /xudrpc.Xud/RemoveOrder
30/06/2020 11:43:38.319 [ORDERBOOK] debug: order removed: ecd2a460-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:38.331 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:38.332 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.026341,"quantity":252741430,"isBuy":false,"localId":"f3e2b3a4-5072-4f99-8656-a18c13eb12b9","id":"f02292b0-bac6-11ea-8579-af2cf3d85191","initialQuantity":252741430,"hold":0,"createdAt":1593517418331}
30/06/2020 11:43:38.333 [RPC] debug: received call /xudrpc.Xud/PlaceOrderSync
30/06/2020 11:43:38.333 [ORDERBOOK] debug: order added: {"pairId":"ETH/BTC","price":0.023359,"quantity":385417441,"isBuy":true,"localId":"9172c4ff-4f62-43f7-9065-accffcee9301","id":"f022e0d0-bac6-11ea-8579-af2cf3d85191","initialQuantity":385417441,"hold":0,"createdAt":1593517418333}
30/06/2020 11:43:45.044 [RPC] debug: received call /xudrpc.Xud/GetBalance
30/06/2020 11:43:49.968 [P2P] debug: received swapFailed due to SwapTimedOut from 0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6 (ChangeTurn): {"rHash":"e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72","failureReason":10}
30/06/2020 11:43:49.977 [SWAPS] debug: deal e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72 failed due to SwapTimedOut
30/06/2020 11:43:50.031 [P2P] debug: received swapRequest from 0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6 (ChangeTurn): {"proposedQuantity":300000,"pairId":"ETH/BTC","orderId":"f02292b0-bac6-11ea-8579-af2cf3d85191","rHash":"f489edb7c21d6e6ca2720563da97f0f8cb853ced1dd47f126c2f2dcb10aa0906","takerCltvDelta":200}
30/06/2020 11:43:50.032 [ORDERBOOK] debug: added hold of 300000 on order f02292b0-bac6-11ea-8579-af2cf3d85191
30/06/2020 11:43:50.038 [SWAPS-RECOVERY] info: recovering swap deal e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72
30/06/2020 11:43:50.038 [SWAPS-RECOVERY] debug: checking outgoing payment status for swap e22faf0a146accd6abe05950cf1e11a328e3128bec217ebf51969218b5c31d72
30/06/2020 11:43:50.045 [SWAPS] debug: trying to accept deal: {"quantity":300000,"localId":"f3e2b3a4-5072-4f99-8656-a18c13eb12b9","price":0.026341,"isBuy":false} from xudPubKey: 0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6
30/06/2020 11:43:50.045 [SWAPS] debug: New deal: {"rHash":"f489edb7c21d6e6ca2720563da97f0f8cb853ced1dd47f126c2f2dcb10aa0906","pairId":"ETH/BTC","proposedQuantity":300000,"orderId":"f02292b0-bac6-11ea-8579-af2cf3d85191","price":0.026341,"isBuy":false,"quantity":300000,"makerAmount":7902,"takerAmount":300000,"makerCurrency":"BTC","takerCurrency":"ETH","makerUnits":7902,"takerUnits":3000000000000000,"takerCltvDelta":200,"takerPubKey":"indra62JM1LTtvMkfqXWcKVTJQMKNuDVcZVzkLrjxwmja1hADq9iHQb","destination":"indra62JM1LTtvMkfqXWcKVTJQMKNuDVcZVzkLrjxwmja1hADq9iHQb","peerPubKey":"0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6","localId":"f3e2b3a4-5072-4f99-8656-a18c13eb12b9","phase":0,"state":0,"role":1,"createTime":1593517430045}
30/06/2020 11:43:50.046 [SWAPS] debug: got ETH block height of 1
30/06/2020 11:43:50.046 [SWAPS] debug: found route to taker with total lock duration of 100 ETH blocks (~0h)
30/06/2020 11:43:50.046 [SWAPS] debug: calculated lock buffer for first leg: 22 BTC blocks (~4h)
30/06/2020 11:43:50.046 [SWAPS] debug: lock delta for final hop to maker: 166 BTC blocks (~28h)
30/06/2020 11:43:50.050 [LND-BTC] debug: added invoice of 7902 for f489edb7c21d6e6ca2720563da97f0f8cb853ced1dd47f126c2f2dcb10aa0906 with cltvExpiry 166
30/06/2020 11:43:50.050 [SWAPS] debug: Setting SwapAccepted phase for deal f489edb7c21d6e6ca2720563da97f0f8cb853ced1dd47f126c2f2dcb10aa0906
30/06/2020 11:43:50.051 [SWAPS] debug: sending swap accepted packet: {"rHash":"f489edb7c21d6e6ca2720563da97f0f8cb853ced1dd47f126c2f2dcb10aa0906","makerCltvDelta":166,"quantity":300000} to peer: 0322db0bfd11f708500d1db613b094332b641977c62c63e91fbc3024ea656cb3a6
30/06/2020 11:43:50.140 [CONNEXT] error: connext server error 500: Internal Server Error
30/06/2020 11:43:50.143 [CONNEXT] error: connext server error
{
  message: 'connext server error',
  code: '8.5',
  level: 'error',
  [Symbol(level)]: 'error',
  [Symbol(message)]: '{"message":"connext server error","code":"8.5","level":"error"}'
}

/home/ar/xud/dist/bootstrap.js:13
        throw err;
        ^
{
  message: 'connext server error',
  code: '8.5',
  level: 'error',
  [Symbol(level)]: 'error',
  [Symbol(message)]: '{"message":"connext server error","code":"8.5","level":"error"}'
}
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! xud@1.0.0-beta.4 start: `node dist/Xud.js`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the xud@1.0.0-beta.4 start script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /home/ar/.npm/_logs/2020-06-30T11_43_50_207Z-debug.log
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! xud@1.0.0-beta.4 dev: `npm run compile:dev && npm start`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the xud@1.0.0-beta.4 dev script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /home/ar/.npm/_logs/2020-06-30T11_43_50_224Z-debug.log

sangaman added a commit that referenced this issue Jul 1, 2020
@sangaman
fix(swaps): lookupPayment return Pending on error
3d78a55 
This catches any errors within the `lookupPayment` swap client method
and returns a "pending" status - since we weren't able to determine a
resolution for the payment - rather than throwing an error. The error
was not being handled in the Swaps module.

Fixes #1701.
@sangaman
Copy link
Collaborator

sangaman commented Jul 1, 2020

I believe this crash is a result of the call to lookup the payment status from the first swap in the logs above failing. When lookupPayment throws an error we don't currently handle it everywhere.

@sangaman sangaman mentioned this issue Jul 1, 2020
Merged
@ghost
Copy link
Author

ghost commented Jul 1, 2020

I believe this crash is a result of the call to lookup the payment status from the first swap in the logs above failing. When lookupPayment throws an error we don't currently handle it everywhere.

Yep, looks like it.

@ghost ghost closed this as completed in #1705 Jul 1, 2020
This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@sangaman sangaman

Labels
bug Something isn't working P1 top priority
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

fix(swaps): lookupPayment return Pending on error ExchangeUnion/xud
1 participant
@sangaman