comit-network / xmr-btc-swap

Bitcoin–Monero Cross-chain Atomic Swap
GNU General Public License v3.0
655 stars 83 forks source link

CLI doesn't refund after Alice locks her Monero #929

Open binarybaron opened 2 years ago

binarybaron commented 2 years ago

Describe the bug How to reproduce:

  1. Initiate swap, lock Bitcoin
  2. Wait for Monero to be locked (not fully confirmed with 10 confirmations)
  3. Exit the CLI
  4. Wait for the cancel timelock to expire
  5. Resume the swap -> Error occurs. Swap is not automatically refunded. Bob will get punished and loose his funds.

Lost/trapped Funds Could potentially result in Bob not automatically refunding when the timelock has expired.

Debug logs CLI logs:

./swap --testnet history
+--------------------------------------+-----------------+
| SWAP ID                              | STATE           |
+========================================================+
| 250fccb2-aaf3-4f12-8a01-fde432b8cafb | btc is refunded |
|--------------------------------------+-----------------|
| 550573a2-4745-4d84-ae20-e54016a9795e | xmr is redeemed |
|--------------------------------------+-----------------|
| 59f273c7-2fcc-4ae9-9031-1957e51562e7 | xmr is redeemed |
|--------------------------------------+-----------------|
| 6ecdf44f-0378-4846-a50a-02539a0df02e | xmr is redeemed |
|--------------------------------------+-----------------|
| 6f51811f-765e-4f3c-b02e-e3f00cb7c776 | xmr is locked   |   <--- This one
|--------------------------------------+-----------------|
| 7d83bdc9-5e9c-4d69-96cd-22d735b93597 | btc is redeemed |
|--------------------------------------+-----------------|
| f23f87f7-bf4f-4679-bfa9-b2a66bba30a6 | xmr is redeemed |
+--------------------------------------+-----------------+
{"timestamp":"Jan 27 13:52:33.205","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 27 13:52:33.217","level":"DEBUG","fields":{"message":"Reading in seed from /Users/****/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 27 13:52:35.131","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"60521"}}
{"timestamp":"Jan 27 13:52:43.753","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 27 13:52:44.570","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 27 13:52:44.570","level":"DEBUG","fields":{"message":"Requesting quote"}}
{"timestamp":"Jan 27 13:52:45.011","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 13:52:45.225","level":"INFO","fields":{"message":"Received quote","price":"0.00401200 BTC","minimum_amount":"0.00010000 BTC","maximum_amount":"0.02000000 BTC"}}
{"timestamp":"Jan 27 13:52:45.226","level":"INFO","fields":{"message":"Waiting for Bitcoin deposit","deposit_address":"tb1q757qr2x05wn3ptu6s0q5jdctu3hvut5taqlkqt","max_giveable":"0.00000000 BTC","minimum_amount":"0.00010000 BTC","maximum_amount":"0.02000000 BTC"}}
{"timestamp":"Jan 27 13:53:08.727","level":"INFO","fields":{"message":"Received Bitcoin","new_balance":"0.00013000 BTC","max_giveable":"0.00012878 BTC"}}
{"timestamp":"Jan 27 13:53:08.727","level":"INFO","fields":{"message":"Determined swap amount","amount":"0.00012878 BTC","fees":"0.00000122 BTC"}}
{"timestamp":"Jan 27 13:53:08.736","level":"DEBUG","fields":{"message":"Advancing state","state":"quote has been requested"}}
{"timestamp":"Jan 27 13:53:08.987","level":"DEBUG","fields":{"message":"Estimated fee for transaction","weight":"548","fee_rate":"1","sats_per_vbyte":"137.0"}}
{"timestamp":"Jan 27 13:53:08.987","level":"WARN","fields":{"message":"Estimated fee of 137.0 is smaller than the min relay fee, defaulting to min relay fee 1000"}}
{"timestamp":"Jan 27 13:53:09.233","level":"DEBUG","fields":{"message":"Estimated fee for transaction","weight":"596","fee_rate":"1","sats_per_vbyte":"149.0"}}
{"timestamp":"Jan 27 13:53:09.233","level":"WARN","fields":{"message":"Estimated fee of 149.0 is smaller than the min relay fee, defaulting to min relay fee 1000"}}
{"timestamp":"Jan 27 13:53:13.376","level":"INFO","fields":{"message":"Starting new swap","swap_id":"6f51811f-765e-4f3c-b02e-e3f00cb7c776"}}
{"timestamp":"Jan 27 13:53:13.384","level":"DEBUG","fields":{"message":"Advancing state","state":"execution setup done"}}
{"timestamp":"Jan 27 13:53:13.517","level":"INFO","fields":{"message":"Published Bitcoin transaction","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","kind":"lock"}}
{"timestamp":"Jan 27 13:53:13.520","level":"DEBUG","fields":{"message":"Advancing state","state":"btc is locked"}}
{"timestamp":"Jan 27 13:53:13.521","level":"INFO","fields":{"message":"Waiting for Alice to lock Monero"}}
{"timestamp":"Jan 27 13:53:18.400","level":"DEBUG","fields":{"message":"Found relevant Bitcoin transaction","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","status":"unseen"}}
{"timestamp":"Jan 27 13:53:38.539","level":"DEBUG","fields":{"message":"Got notification for new block","block_height":2137779}}
{"timestamp":"Jan 27 13:53:38.664","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"in mempool","old_status":"unseen"}}
{"timestamp":"Jan 27 13:56:44.282","level":"DEBUG","fields":{"message":"Got notification for new block","block_height":2137780}}
{"timestamp":"Jan 27 13:56:44.410","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"confirmed with 1 blocks","old_status":"in mempool"}}
{"timestamp":"Jan 27 13:59:04.387","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 27 13:59:04.398","level":"DEBUG","fields":{"message":"Reading in seed from /Users/***/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 27 13:59:06.357","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"60633"}}
{"timestamp":"Jan 27 13:59:13.142","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 27 13:59:13.958","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 27 13:59:13.972","level":"DEBUG","fields":{"message":"Advancing state","state":"btc is locked"}}
{"timestamp":"Jan 27 13:59:13.973","level":"INFO","fields":{"message":"Waiting for Alice to lock Monero"}}
{"timestamp":"Jan 27 13:59:14.415","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 13:59:18.977","level":"DEBUG","fields":{"message":"Found relevant Bitcoin transaction","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","status":"unseen"}}
{"timestamp":"Jan 27 14:00:11.678","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"confirmed with 1 blocks","old_status":"unseen"}}
{"timestamp":"Jan 27 14:35:59.115","level":"WARN","fields":{"message":"Lost connection to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD, cause: Connection error: I/O error: connection is closed"}}
{"timestamp":"Jan 27 14:36:01.138","level":"DEBUG","fields":{"message":"Dialling Alice at 12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 14:36:01.622","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 14:36:09.760","level":"DEBUG","fields":{"message":"Got notification for new block","block_height":2137781}}
{"timestamp":"Jan 27 14:36:09.888","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"confirmed with 2 blocks","old_status":"confirmed with 1 blocks"}}
{"timestamp":"Jan 27 14:51:26.672","level":"WARN","fields":{"message":"Lost connection to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD, cause: Connection error: I/O error: connection is closed"}}
{"timestamp":"Jan 27 14:51:28.673","level":"DEBUG","fields":{"message":"Dialling Alice at 12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 14:51:29.071","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 14:51:36.747","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 27 14:51:36.766","level":"DEBUG","fields":{"message":"Reading in seed from /Users/****/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 27 14:51:38.375","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"60899"}}
{"timestamp":"Jan 27 14:51:43.102","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 27 14:51:43.927","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 27 14:51:43.932","level":"DEBUG","fields":{"message":"Advancing state","state":"btc is locked"}}
{"timestamp":"Jan 27 14:51:43.932","level":"INFO","fields":{"message":"Waiting for Alice to lock Monero"}}
{"timestamp":"Jan 27 14:51:44.378","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 14:51:48.931","level":"DEBUG","fields":{"message":"Found relevant Bitcoin transaction","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","status":"unseen"}}
{"timestamp":"Jan 27 14:52:41.597","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"confirmed with 3 blocks","old_status":"unseen"}}
{"timestamp":"Jan 27 14:56:50.121","level":"DEBUG","fields":{"message":"Got notification for new block","block_height":2137783}}
{"timestamp":"Jan 27 14:56:50.242","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"confirmed with 4 blocks","old_status":"confirmed with 3 blocks"}}
{"timestamp":"Jan 27 15:02:01.516","level":"DEBUG","fields":{"message":"Got notification for new block","block_height":2137784}}
{"timestamp":"Jan 27 15:02:01.644","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"confirmed with 5 blocks","old_status":"confirmed with 4 blocks"}}
{"timestamp":"Jan 27 15:03:46.634","level":"WARN","fields":{"message":"Lost connection to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD, cause: Connection error: I/O error: decode error: i/o error: Operation timed out (os error 60)"}}
{"timestamp":"Jan 27 15:03:48.639","level":"DEBUG","fields":{"message":"Dialling Alice at 12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 15:04:15.681","level":"WARN","fields":{"message":"Failed to dial Alice: Pending connection: Transport error: select error: Protocol error: I/O error: Broken pipe (os error 32)","address":"/dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 15:04:15.682","level":"INFO","fields":{"message":"Next redial attempt in 4s"}}
{"timestamp":"Jan 27 15:13:38.670","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 27 15:13:38.690","level":"DEBUG","fields":{"message":"Reading in seed from /Users/****/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 27 15:13:40.494","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"61508"}}
{"timestamp":"Jan 27 15:13:43.493","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 27 15:13:44.175","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 27 15:13:44.182","level":"DEBUG","fields":{"message":"Advancing state","state":"btc is locked"}}
{"timestamp":"Jan 27 15:13:44.182","level":"INFO","fields":{"message":"Waiting for Alice to lock Monero"}}
{"timestamp":"Jan 27 15:13:44.656","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 15:13:44.781","level":"INFO","fields":{"message":"Alice locked Monero","txid":"aa5f8b80e733ed183f3a416daa2e54905b33fcc7a00d43dfd8da79588062640e"}}
{"timestamp":"Jan 27 15:13:44.785","level":"DEBUG","fields":{"message":"Advancing state","state":"XMR lock transaction transfer proof received"}}
{"timestamp":"Jan 27 15:13:44.785","level":"INFO","fields":{"message":"Waiting for Monero transaction finality","txid":"aa5f8b80e733ed183f3a416daa2e54905b33fcc7a00d43dfd8da79588062640e","target_confirmations":"10"}}
{"timestamp":"Jan 27 15:13:44.894","level":"INFO","fields":{"message":"Received new confirmation for Monero lock tx","txid":"aa5f8b80e733ed183f3a416daa2e54905b33fcc7a00d43dfd8da79588062640e","seen_confirmations":"2","needed_confirmations":"10"}}
{"timestamp":"Jan 27 15:13:49.187","level":"DEBUG","fields":{"message":"Found relevant Bitcoin transaction","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","status":"unseen"}}
{"timestamp":"Jan 27 15:14:46.901","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"confirmed with 7 blocks","old_status":"unseen"}}
{"timestamp":"Jan 27 15:15:47.081","level":"DEBUG","fields":{"message":"Got notification for new block","block_height":2137787}}
{"timestamp":"Jan 27 15:15:47.207","level":"DEBUG","fields":{"message":"Bitcoin transaction status changed","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","new_status":"confirmed with 8 blocks","old_status":"confirmed with 7 blocks"}}
{"timestamp":"Jan 27 15:17:56.894","level":"INFO","fields":{"message":"Received new confirmation for Monero lock tx","txid":"aa5f8b80e733ed183f3a416daa2e54905b33fcc7a00d43dfd8da79588062640e","seen_confirmations":"3","needed_confirmations":"10"}}
{"timestamp":"Jan 27 15:18:37.362","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 27 15:18:37.365","level":"DEBUG","fields":{"message":"Reading in seed from /Users/****/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 27 15:18:39.103","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"61616"}}
{"timestamp":"Jan 27 15:18:42.521","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 27 15:18:42.906","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 27 15:18:42.908","level":"DEBUG","fields":{"message":"Advancing state","state":"XMR lock transaction transfer proof received"}}
{"timestamp":"Jan 27 15:18:42.908","level":"INFO","fields":{"message":"Waiting for Monero transaction finality","txid":"aa5f8b80e733ed183f3a416daa2e54905b33fcc7a00d43dfd8da79588062640e","target_confirmations":"10"}}
{"timestamp":"Jan 27 15:18:43.012","level":"INFO","fields":{"message":"Received new confirmation for Monero lock tx","txid":"aa5f8b80e733ed183f3a416daa2e54905b33fcc7a00d43dfd8da79588062640e","seen_confirmations":"3","needed_confirmations":"10"}}
{"timestamp":"Jan 27 15:18:43.320","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 27 15:18:47.912","level":"DEBUG","fields":{"message":"Found relevant Bitcoin transaction","txid":"f3ada7aa6119a908cb40f295ed9fd474f7f29784ec10a12b91470cfc5989b85c","status":"unseen"}}
{"timestamp":"Jan 28 18:33:16.356","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 28 18:33:16.365","level":"DEBUG","fields":{"message":"Reading in seed from /Users/****/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 28 18:33:18.402","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"64599"}}
{"timestamp":"Jan 28 18:33:22.331","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 28 18:33:23.105","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 28 18:33:23.106","level":"DEBUG","fields":{"message":"Advancing state","state":"XMR lock transaction transfer proof received"}}
{"timestamp":"Jan 28 18:33:23.107","level":"INFO","fields":{"message":"Waiting for Monero transaction finality","txid":"aa5f8b80e733ed183f3a416daa2e54905b33fcc7a00d43dfd8da79588062640e","target_confirmations":"10"}}
{"timestamp":"Jan 28 18:33:23.217","level":"INFO","fields":{"message":"Received new confirmation for Monero lock tx","txid":"aa5f8b80e733ed183f3a416daa2e54905b33fcc7a00d43dfd8da79588062640e","seen_confirmations":"1112","needed_confirmations":"10"}}
{"timestamp":"Jan 28 18:33:23.219","level":"DEBUG","fields":{"message":"Advancing state","state":"xmr is locked"}}
{"timestamp":"Jan 28 18:33:23.219","level":"DEBUG","fields":{"message":"Constructed Bitcoin spending transaction","fee":"1000"}}
{"timestamp":"Jan 28 18:33:23.553","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 28 18:33:23.794","level":"WARN","fields":{"message":"Lost connection to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD, cause: Connection error: Handler error: upgrade apply error: EOF while parsing a value"}}
{"timestamp":"Jan 28 18:33:23.794","level":"WARN","fields":{"message":"Communication error: /comit/xmr/btc/encrypted_signature/1.0.0 failed because the connection was closed we received a response","peer":"12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 28 18:33:35.564","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 28 18:33:35.575","level":"DEBUG","fields":{"message":"Reading in seed from /Users/****/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 28 18:33:37.334","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"64610"}}
{"timestamp":"Jan 28 18:33:40.585","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 28 18:33:41.493","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 28 18:33:41.495","level":"DEBUG","fields":{"message":"Advancing state","state":"xmr is locked"}}
{"timestamp":"Jan 28 18:33:41.495","level":"DEBUG","fields":{"message":"Constructed Bitcoin spending transaction","fee":"1000"}}
{"timestamp":"Jan 28 18:33:41.928","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 28 18:33:42.151","level":"WARN","fields":{"message":"Lost connection to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD, cause: Connection error: Handler error: upgrade apply error: EOF while parsing a value"}}
{"timestamp":"Jan 28 18:33:42.151","level":"WARN","fields":{"message":"Communication error: /comit/xmr/btc/encrypted_signature/1.0.0 failed because the connection was closed we received a response","peer":"12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 28 18:35:24.254","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 28 18:35:24.334","level":"DEBUG","fields":{"message":"Reading in seed from /Users/****/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 28 18:35:26.170","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"64725"}}
{"timestamp":"Jan 28 18:35:29.209","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 28 18:35:30.188","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 28 18:35:30.194","level":"DEBUG","fields":{"message":"Advancing state","state":"xmr is locked"}}
{"timestamp":"Jan 28 18:35:30.195","level":"DEBUG","fields":{"message":"Constructed Bitcoin spending transaction","fee":"1000"}}
{"timestamp":"Jan 28 18:35:30.639","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 28 18:35:30.852","level":"WARN","fields":{"message":"Lost connection to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD, cause: Connection error: Handler error: upgrade apply error: EOF while parsing a value"}}
{"timestamp":"Jan 28 18:35:30.852","level":"WARN","fields":{"message":"Communication error: /comit/xmr/btc/encrypted_signature/1.0.0 failed because the connection was closed we received a response","peer":"12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 28 18:38:48.889","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jan 28 18:38:48.924","level":"DEBUG","fields":{"message":"Reading in seed from /Users/***/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jan 28 18:38:52.013","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"64765"}}
{"timestamp":"Jan 28 18:38:54.570","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jan 28 18:38:55.403","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX"}}
{"timestamp":"Jan 28 18:38:55.420","level":"DEBUG","fields":{"message":"Advancing state","state":"xmr is locked"}}
{"timestamp":"Jan 28 18:38:55.425","level":"DEBUG","fields":{"message":"Constructed Bitcoin spending transaction","fee":"1000"}}
{"timestamp":"Jan 28 18:38:55.902","level":"INFO","fields":{"message":"Connected to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}
{"timestamp":"Jan 28 18:38:56.150","level":"WARN","fields":{"message":"Lost connection to Alice at /dns4/unstoppableswap.net/tcp/9939/p2p/12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD, cause: Connection error: Handler error: upgrade apply error: EOF while parsing a value"}}
{"timestamp":"Jan 28 18:38:56.151","level":"WARN","fields":{"message":"Communication error: /comit/xmr/btc/encrypted_signature/1.0.0 failed because the connection was closed we received a response","peer":"12D3KooWJgjeAwsy2834YJfAKsgBAXtoNiyMG3Pe3NXUEsuLNiWD"}}

ASB Logs:

./asb --testnet history
2022-01-28 18:53:33  INFO Initialized tracing level=debug
2022-01-28 18:53:33  INFO Reading config file path=/home/admin/.config/xmr-btc-swap/asb/testnet/config.toml
2022-01-28 18:53:33 DEBUG Using existing sqlite database.
2022-01-28 18:53:33 DEBUG Reading in seed from /home/admin/.local/share/xmr-btc-swap/asb/testnet/seed.pem
+--------------------------------------+-----------------+
| SWAP ID                              | STATE           |
+========================================================+
| 054b7fc2-cd7c-4138-8cb9-c9e7a8a8ccd6 | btc is punished |
|--------------------------------------+-----------------|
| 0dbb0a45-dc0a-430c-a30c-a09ea42ed675 | btc is redeemed |
|--------------------------------------+-----------------|
| 0fc0f2d2-acef-4c63-80b5-c3639076845a | btc is redeemed |
|--------------------------------------+-----------------|
| 1d8ccdb4-5698-466d-9a8b-de3fc8467e10 | btc is punished |
|--------------------------------------+-----------------|
| 250fccb2-aaf3-4f12-8a01-fde432b8cafb | xmr is refunded |
|--------------------------------------+-----------------|
| 39520783-f7f1-4adf-8df6-507a7d7e551f | btc is redeemed |
|--------------------------------------+-----------------|
| 550573a2-4745-4d84-ae20-e54016a9795e | btc is redeemed |
|--------------------------------------+-----------------|
| 59f273c7-2fcc-4ae9-9031-1957e51562e7 | btc is redeemed |
|--------------------------------------+-----------------|
| 5f42595a-3cc8-4639-bd2d-473f96e11ab6 | btc is redeemed |
|--------------------------------------+-----------------|
| 662b4604-d6df-44e5-a7fb-ee0cbd9fb5c3 | btc is redeemed |
|--------------------------------------+-----------------|
| 6c165207-9481-4507-8cc2-b4965ec67dec | xmr is refunded |
|--------------------------------------+-----------------|
| 6ecdf44f-0378-4846-a50a-02539a0df02e | btc is redeemed |
|--------------------------------------+-----------------|
| 6f51811f-765e-4f3c-b02e-e3f00cb7c776 | btc is punished |   <--- This one
|--------------------------------------+-----------------|
| 748ed1b4-7334-44dc-bb33-4b5c6cd5242c | btc is redeemed |
|--------------------------------------+-----------------|
| 75450e10-ebd6-43f2-aa04-a39c6fa00fbc | xmr is refunded |
|--------------------------------------+-----------------|
| 80df34a9-dc40-407b-933f-6020da19e47c | btc is redeemed |
|--------------------------------------+-----------------|
| 92314567-84a6-4247-976b-4951fb44f976 | btc is redeemed |
|--------------------------------------+-----------------|
| 98fccc4b-7c86-4412-b836-f647926da411 | btc is redeemed |
|--------------------------------------+-----------------|
| a29380e3-c3cf-4484-bdb0-d33ebab415c2 | xmr is refunded |
|--------------------------------------+-----------------|
| a9c3817f-cb43-41f7-8f7b-72bdd3a06e65 | btc is redeemed |
|--------------------------------------+-----------------|
| b9c3fc9b-fe72-48b7-af3d-6307c8919514 | btc is redeemed |
|--------------------------------------+-----------------|
| bd63d18b-3ab8-4d7c-a493-a5d5c57ba6c2 | btc is redeemed |
|--------------------------------------+-----------------|
| c59b93a7-1e48-4679-801f-b001bd8978e5 | btc is redeemed |
|--------------------------------------+-----------------|
| ce2b68ae-abf9-42ba-9b27-085873ff965e | btc is redeemed |
|--------------------------------------+-----------------|
| d0e7fb66-5f6e-488e-bf4b-95d716e1d186 | btc is redeemed |
|--------------------------------------+-----------------|
| de11f73e-eb06-4b0e-903d-ef0f83b272c3 | btc is redeemed |
|--------------------------------------+-----------------|
| e077443b-8e9c-4ca0-b782-ded3b1cbc7f7 | btc is redeemed |
+--------------------------------------+-----------------+
2022-01-28 18:52:27 DEBUG New connection established peer=12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX address=/ip4/my.cli.ip/tcp/64827
2022-01-28 18:52:28  WARN No sender for encrypted signature, maybe already handled? swap_id=6f51811f-765e-4f3c-b02e-e3f00cb7c776
2022-01-28 18:52:28 DEBUG Lost connection to peer: Connection error: I/O error: connection is closed peer=12D3KooWCCJ5LZKgZFq3konPNVSQ73vJuUNdstHtMwHh1kegjVMX address=/ip4/my.cli.ip/tcp/64827

Platform (please complete the following information):

binarybaron commented 2 years ago

Possibly related to this https://github.com/comit-network/xmr-btc-swap/issues/828 issue by @rishflab

binarybaron commented 2 years ago

https://github.com/comit-network/xmr-btc-swap/issues/844#issuecomment-966333177

binarybaron commented 2 years ago

The same issue occurs when Bob locks his BTC and Alice then goes offline. Bob will not automatically refund because the cli will crash.

binarybaron commented 2 years ago

Relevant piece of code:

https://github.com/comit-network/xmr-btc-swap/blob/d7a60287f7449a2d0a6218b460e1bfdb3be5b73b/swap/src/protocol/bob/swap.rs#L188-L207

da-kami commented 2 years ago

In the issue description you mention that the CLI is restarted and you

Resume the swap -> Error occurs. Swap is not automatically refunded. Bob will get punished and loose his funds.

Is this a "permanent" error, where both resume and cancel+refund fail and the swap cannot be recovered?

I think the code you linked in https://github.com/comit-network/xmr-btc-swap/issues/929#issuecomment-1102582623 should be fine: If the timelock is expired state.expired_timelock(bitcoin_wallet).await? will evaluate to Some, which will go into the else path and transition to BobState::CancelTimelockExpired(state.cancel()) unless I missed something.


One thing that I can see in the code linked is, that if Bob fails to send the encsig the loop will just exit and a manual refund after the timelock expiry will be necessary (i.e. the user has to ensure to resume/cancel after the cancel timelock expired). But that's not the problem you are referring to.

binarybaron commented 2 years ago

Is this a "permanent" error, where both resume and cancel+refund fail and the swap cannot be recovered?

I suspect that the swap can be recovered using the cancel + refund command. However, in this case Bob has already been punished. Therefore, the swap will never be able to be completed.

$ ./swap --testnet cancel --swap-id 2a3f6f15-862f-440a-8215-a5798a7b9d52
Manually cancelling swap swap_id=2a3f6f15-862f-440a-8215-a5798a7b9d52
Error: Failed to broadcast Bitcoin cancel transaction 947da247f8589a6e4162bee6426106b1de1093e5fc88ad036ae38c2c0d33506f

Caused by:
    Electrum(Protocol(String("sendrawtransaction RPC error: {\"code\":-25,\"message\":\"bad-txns-inputs-missingorspent\"}")))
$ ./swap --testnet refund --swap-id 2a3f6f15-862f-440a-8215-a5798a7b9d52
Error: Failed to broadcast Bitcoin refund transaction 74514eaa8040c57934784be50d64151c3e46a336913b387eed2d443728a2b1dd

Caused by:
    Electrum(Protocol(String("sendrawtransaction RPC error: {\"code\":-25,\"message\":\"bad-txns-inputs-missingorspent\"}")))

One thing that I can see in the code linked is, that if Bob fails to send the encsig the loop will just exit and a manual refund > after the timelock expiry will be necessary (i.e. the user has to ensure to resume/cancel after the cancel timelock expired). But that's not the problem you are referring to.

No, I think you are correct. This is the problem here. I've added the error message that is thrown to the log above. When Bob sends the "encsig", Alice ignores it because she has already punished Bob and in her view the swap has been completed. Bob will error out, bail and exit the cli.

If the timelock is expired state.expired_timelock(bitcoin_wallet).await? will evaluate to Some, which will go into the else path and transition to BobState::CancelTimelockExpired(state.cancel()) unless I missed something.

This should happen, but apparently doesn't. There must be a problem with the detection of the confirmations. I don't have a record of it, but I remember when debugging this issue, I set a breakpoint somewhere and found that the timelock state was reported as ExpiredTimelocks::None, which caused the CLI to not cancel and refund.

If you could give me some guidance on how to tackle this, I would be happy to try to file a PR to fix this problem. It seems very important to me, because we don't want users to lose funds (even if they could refund manually).

binarybaron commented 2 years ago

https://github.com/comit-network/xmr-btc-swap/issues/1063 is probably related. There seems to be an underlying issue with how we detect expired timelocks.

binarybaron commented 2 years ago

https://github.com/comit-network/xmr-btc-swap/blob/d7a60287f7449a2d0a6218b460e1bfdb3be5b73b/swap/src/protocol/bob/swap.rs#L127-L146

Same issue here. If the CLI can't receive the transfer proof it will bail and not refund automatically.

{"timestamp":"Jul 26 16:42:43.052","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"Jul 26 16:42:43.057","level":"DEBUG","fields":{"message":"Reading in seed from /Users/***/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"Jul 26 16:42:45.188","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"55810"}}
{"timestamp":"Jul 26 16:42:48.717","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"Jul 26 16:42:48.723","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWSQLCbtoDWAQzo11JwKmsp3EXfVygZDv7sgdu6sns65tQ"}}
{"timestamp":"Jul 26 16:42:48.723","level":"DEBUG","fields":{"message":"Requesting quote"}}
{"timestamp":"Jul 26 16:42:48.819","level":"INFO","fields":{"message":"Connected to Alice at /dns4/asb.unstoppableswap.net/tcp/9939/p2p/12D3KooWJS3D2aN2Y4MNbDm66jCfkUSVpqW1u2TdURSqriny2CfX"}}
{"timestamp":"Jul 26 16:42:48.842","level":"INFO","fields":{"message":"Received quote","price":"0.00705942 BTC","minimum_amount":"0.00010000 BTC","maximum_amount":"0.04647365 BTC"}}
{"timestamp":"Jul 26 16:42:48.842","level":"INFO","fields":{"message":"Waiting for Bitcoin deposit","deposit_address":"tb1qvs45emcmahelyu3ewuks5kccc0fm0a6aeu7acz","max_giveable":"0.00000000 BTC","minimum_amount":"0.00010000 BTC","maximum_amount":"0.04647365 BTC"}}
{"timestamp":"Jul 26 16:43:09.645","level":"INFO","fields":{"message":"Received Bitcoin","new_balance":"0.00011000 BTC","max_giveable":"0.00010878 BTC"}}
{"timestamp":"Jul 26 16:43:09.646","level":"INFO","fields":{"message":"Determined swap amount","amount":"0.00010878 BTC","fees":"0.00000122 BTC"}}
{"timestamp":"Jul 26 16:43:09.651","level":"DEBUG","fields":{"message":"Advancing state","state":"quote has been requested"}}
{"timestamp":"Jul 26 16:43:09.899","level":"DEBUG","fields":{"message":"Estimated fee for transaction","weight":"548","fee_rate":"1","sats_per_vbyte":"137.0"}}
{"timestamp":"Jul 26 16:43:09.899","level":"WARN","fields":{"message":"Estimated fee of 137.0 is smaller than the min relay fee, defaulting to min relay fee 1000"}}
{"timestamp":"Jul 26 16:43:10.151","level":"DEBUG","fields":{"message":"Estimated fee for transaction","weight":"596","fee_rate":"1","sats_per_vbyte":"149.0"}}
{"timestamp":"Jul 26 16:43:10.151","level":"WARN","fields":{"message":"Estimated fee of 149.0 is smaller than the min relay fee, defaulting to min relay fee 1000"}}
{"timestamp":"Jul 26 16:43:12.161","level":"INFO","fields":{"message":"Starting new swap","swap_id":"c9186b1b-a363-489b-8842-99ab1c4cbd6d"}}
{"timestamp":"Jul 26 16:43:12.163","level":"DEBUG","fields":{"message":"Advancing state","state":"execution setup done"}}
{"timestamp":"Jul 26 16:43:12.292","level":"INFO","fields":{"message":"Published Bitcoin transaction","txid":"e1250965ed0c77dda92d883152d83061bc5b9bebbcbd34f1829e9a0a359c2994","kind":"lock"}}
{"timestamp":"Jul 26 16:43:12.293","level":"DEBUG","fields":{"message":"Advancing state","state":"btc is locked"}}
{"timestamp":"Jul 26 16:43:12.293","level":"INFO","fields":{"message":"Waiting for Alice to lock Monero"}}
{"timestamp":"Jul 26 16:43:17.169","level":"DEBUG","fields":{"message":"Found relevant Bitcoin transaction","txid":"e1250965ed0c77dda92d883152d83061bc5b9bebbcbd34f1829e9a0a359c2994","status":"unseen"}}
{"timestamp":"2022-07-27 13:51:15","level":"DEBUG","fields":{"message":"Using existing sqlite database."}}
{"timestamp":"2022-07-27 13:51:15","level":"DEBUG","fields":{"message":"Reading in seed from /Users/***/Library/Application Support/xmr-btc-swap/cli/testnet/seed.pem"}}
{"timestamp":"2022-07-27 13:51:17","level":"DEBUG","fields":{"message":"Starting monero-wallet-rpc","port":"60629"}}
{"timestamp":"2022-07-27 13:51:20","level":"DEBUG","fields":{"message":"Opened Monero wallet","monero_wallet_name":"swap-tool-blockchain-monitoring-wallet"}}
{"timestamp":"2022-07-27 13:51:20","level":"DEBUG","fields":{"message":"Network layer initialized","peer_id":"12D3KooWSQLCbtoDWAQzo11JwKmsp3EXfVygZDv7sgdu6sns65tQ"}}
{"timestamp":"2022-07-27 13:51:20","level":"DEBUG","fields":{"message":"Advancing state","state":"btc is locked"}}
{"timestamp":"2022-07-27 13:51:20","level":"INFO","fields":{"message":"Waiting for Alice to lock Monero"}}
{"timestamp":"2022-07-27 13:51:20","level":"INFO","fields":{"message":"Connected to Alice at /dns4/asb.unstoppableswap.net/tcp/9939/p2p/12D3KooWJS3D2aN2Y4MNbDm66jCfkUSVpqW1u2TdURSqriny2CfX"}}
{"timestamp":"2022-07-27 13:51:25","level":"DEBUG","fields":{"message":"Found relevant Bitcoin transaction","txid":"e1250965ed0c77dda92d883152d83061bc5b9bebbcbd34f1829e9a0a359c2994","status":"unseen"}}
{"timestamp":"2022-07-27 13:51:30","level":"WARN","fields":{"message":"Communication error: /comit/xmr/btc/bid-quote/1.0.0 failed because of an inbound timeout","peer":"12D3KooWJS3D2aN2Y4MNbDm66jCfkUSVpqW1u2TdURSqriny2CfX"}}
Error: Failed to receive transfer proof

Caused by:
    request channel closed