Swaps failed without sending a transfer proof
Hi there,
I've been running on mainnet and so far have had two swaps fail completely.
Here are the relevant logs (AFAICT) on both:
Swap dbf32b87-2a14-4848-a1a5-9bddd3e752da:
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=started rate=0.00569700 BTC
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=bitcoin lock transaction in mempool rate=0.00569700 BTC
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Waiting for Bitcoin transaction finality txid=redacted required_confirmation=2
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Waiting for Bitcoin transaction finality txid=redacted seen_confirmations=1 needed_confirmations=2
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Waiting for Bitcoin transaction finality txid=redacted seen_confirmations=2 needed_confirmations=2
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=btc is locked rate=0.00570300 BTC
DEBUG swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Successfully initiated Monero transfer amount=0.117310280264 XMR to=redacted tx_id=redacted
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=xmr lock transaction sent rate=0.00570300 BTC
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Waiting for Monero transaction finality txid=redacted target_confirmations=1
DEBUG swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Failed to retrieve tx from blockchain: JSON-RPC request failed with code -1: Failed to get transaction from daemon: JSON-RPC request failed with code -1: Failed to get transaction from daemon txid=redacted
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Received new confirmation for Monero lock tx txid=redacted seen_confirmations=1 needed_confirmations=1
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=xmr is locked rate=0.00570100 BTC
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=xmr lock transfer proof sent rate=0.00570100 BTC
WARN Failed to get status of script: Failed to subscribe to header notifications: Made one or multiple attempts, all errored:
- CloseNotify alert received
txid=redacted
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=xmr lock transfer proof sent rate=0.00568200 BTC
WARN Failed to get status of script: Failed to subscribe to header notifications: Made one or multiple attempts, all errored:
- CloseNotify alert received
txid=redacted
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=cancel timelock is expired rate=0.00567700 BTC
DEBUG swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Assuming cancel transaction is already broadcasted because: Failed to broadcast Bitcoin cancel transaction redacted: Electrum(Protocol(String("sendrawtransaction RPC error: {\"code\":-26,\"message\":\"non-BIP68-final\"}")))
INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=btc is cancelled rate=0.00567700 BTC
DEBUG Found relevant Bitcoin transaction txid=redacted status=unseen
DEBUG Found relevant Bitcoin transaction txid=redacted status=unseen
WARN Failed to get status of script: Failed to subscribe to header notifications: Made one or multiple attempts, all errored:
- CloseNotify alert received
txid=redacted
WARN Failed to get status of script: Failed to subscribe to header notifications: Made one or multiple attempts, all errored:
- CloseNotify alert received
txid=redacted
ERROR swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: error=Failed to monitor refund transaction
ERROR Swap failed: Failed to monitor refund transaction: Failed while waiting for next status update: channel closed swap_id=dbf32b87-2a14-4848-a1a5-9bddd3e752da
DEBUG A swap stopped without sending a transfer proof: request channel closed
Swap 2c5487d-e29d-4753-9a19-49a64e40cb20:
(For further context on this swap, see https://github.com/comit-network/xmr-btc-swap/issues/648)
INFO Resuming swap swap_id=f2c5487d-e29d-4753-9a19-49a64e40cb20
INFO swap{id=f2c5487d-e29d-4753-9a19-49a64e40cb20}: Advancing state state=btc is cancelled rate=0.00564200 BTC
ERROR swap{id=f2c5487d-e29d-4753-9a19-49a64e40cb20}: error=Failed to monitor refund transaction
ERROR Swap failed: Failed to monitor refund transaction: Failed while waiting for next status update: channel closed swap_id=f2c5487d-e29d-4753-9a19-49a64e40cb20
INFO Resuming swap swap_id=f2c5487d-e29d-4753-9a19-49a64e40cb20
INFO swap{id=f2c5487d-e29d-4753-9a19-49a64e40cb20}: Advancing state state=btc is cancelled rate=0.00568200 BTC
INFO swap{id=f2c5487d-e29d-4753-9a19-49a64e40cb20}: Advancing state state=btc is punishable rate=0.00567700 BTC
WARN swap{id=f2c5487d-e29d-4753-9a19-49a64e40cb20}: Failed to publish punish transaction: Failed to broadcast Bitcoin punish transaction redacted: Electrum(Protocol(String("sendrawtransaction RPC error: {\"code\":-25,\"message\":\"bad-txns-inputs-missingorspent\"}")))
INFO swap{id=f2c5487d-e29d-4753-9a19-49a64e40cb20}: Falling back to refund
ERROR swap{id=f2c5487d-e29d-4753-9a19-49a64e40cb20}: error=Electrum(Protocol(String("missing transaction")))
ERROR Swap failed: Electrum(Protocol(String("missing transaction"))) swap_id=f2c5487d-e29d-4753-9a19-49a64e40cb20
My ASB was up and reachable AFAICT throughout both swaps, though I saw similar lines to the below for each swap:
WARN Failed to get status of script: Failed to subscribe to header notifications: Made one or multiple attempts, all errored:
- CloseNotify alert received
txid=redacted
Let me know if there is any other data I can gather or provide around this.
Version: running the x86_64 artifact from https://github.com/comit-network/xmr-btc-swap/actions/runs/1141616002 to test the fix in https://github.com/comit-network/xmr-btc-swap/pull/649.
Screenshots from the f2c5487d-e29d-4753-9a19-49a64e40cb20 swap partner:

Swap 2c5487d-e29d-4753-9a19-49a64e40cb20 was able to refund properly:
DEBUG Swap completed swap_id=f2c5487d-e29d-4753-9a19-49a64e40cb20 final_state=xmr is refunded
Swap dbf32b87-2a14-4848-a1a5-9bddd3e752da was able to refund properly as well:
2021-08-19 14:25:50 WARN swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Failed to publish punish transaction: Failed to broadcast Bitcoin punish transaction REDACTED: Electrum(Protocol(String("sendrawtransaction RPC error: {\"code\":-25,\"message\":\"bad-txns-inputs-missingorspent\"}")))
2021-08-19 14:25:50 INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Falling back to refund
2021-08-19 14:25:50 INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Advancing state state=btc is refunded rate=0.00570600 BTC
2021-08-19 14:25:50 INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Waiting for Monero transaction finality txid=REDACTED target_confirmations=10
2021-08-19 14:25:50 INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Received new confirmation for Monero lock tx txid=REDACTED seen_confirmations=589 needed_confirmations=10
2021-08-19 14:25:55 DEBUG Found relevant Bitcoin transaction txid=REDACTED status=unseen
2021-08-19 14:26:05 INFO swap{id=dbf32b87-2a14-4848-a1a5-9bddd3e752da}: Monero transferred back to default wallet tx=REDACTED monero_address=REDACTED
2021-08-19 14:26:06 DEBUG Swap completed swap_id=dbf32b87-2a14-4848-a1a5-9bddd3e752da final_state=xmr is refunded
Important note I just realized -- both only refunded (or were seen by the ASB as refunded) after restarting the ASB client.
Unsure what to do about this, we may want to configure the electron client to do more retries in case the connection gets closed.
We added more retried to the electrum client in 0.8.2. Has the issue been resolved after upgrading. Would like to close this issue if so.
We added more retried to the electrum client in 0.8.2. Has the issue been resolved after upgrading. Would like to close this issue if so.
I unfortunately cannot test ATM, but retries should correct the issue as it was always resolved after an ASB restart (forcing a reconnection attempt to Electrum).