[BitcoinJ] Trade deposit tx not detected in wallet after SPV resync

[ghost]

Scenario

As described in #6948, after an SPV resync a trade is reported as "missing deposit transaction" and users sometimes abandon them as failed trades (trade is not failed, but appears to be).

Steps to reproduce (regtest environment)

• Alice creates an offer to sell.
• Bob takes offer. Leave the Tx unconfirmed.
• Do an SPV resync by clicking on the button in Settings -> Network Settings.
• Once the resync has completed, start Bisq and look in Funds -> Transactions. The taker fee tx is there, but the deposit transaction is not present!
• Go to portfolio, trades. The trade pops up a message saying it is missing a deposit tx and provides buttons for moving it to failed.
• Shut down and then restart Bisq.
• Look in Funds -> Transactions. The deposit transaction appears after a delay of several seconds.

Steps to reproduce using bitcoinJ's wallet-tool

• Create a regtest P2WPKH wallet, save the seed phrase.
• Fund the wallet and confirm the tx.
• Send all funds to self, leave the tx unconfirmed.
• Send all funds to a P2WSH address. Leave the tx unconfirmed.
• Delete the wallet and re-create it again from seed phrase.
• Start the wallet and wait. The last tx (sending funds to a P2WSH address) is not present and the wallet balance is incorrect.
• Start the wallet again. The last tx shows up after a delay of several seconds.

Logs:

Start wallet first time:

13:07:50 1 AbstractBlockChain.<init>: chain head is at height 163:
 block: 
   hash: 10a54c7d9502bd633ca22d7fc50b6e5730d3b9a86f9eabbbca05c5b6401dc952
   version: 805306368 (BIP34, BIP66, BIP65)
   previous block: 5bd82a8b5d584d59081f18afda85e475594968dd3876dc8ca33b57713aa64e1b
   time: 1704395167 (2024-01-04T19:06:07Z)
   difficulty target (nBits): 545259519
   nonce: 0

13:07:50 13 PeerGroup$9.run: Starting ...
13:07:50 13 PeerGroup$7.go: Localhost peer detected, trying to use it instead of P2P discovery
13:07:50 13 PeerGroup.connectTo: Attempting connection to [127.0.0.1]:18444     (0 connected, 1 pending, 0 max)
13:07:50 14 NioClientManager.handleKey: Connected to localhost/127.0.0.1:18444
13:07:50 14 Peer.connectionOpened: Announcing to localhost/127.0.0.1:18444 as: /bitcoinj:0.15.10.bisq.16/WalletTool:1.0/
13:07:50 14 Peer.processVersionMessage: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:07:50, height=163}
13:07:50 14 PeerGroup.handleNewPeer: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:07:50, height=163}: New peer      (1 connected, 0 pending, 1 max)
13:07:50 14 Peer.setBloomFilter: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:07:50, height=163}: Sending Bloom filter and querying mempool
13:07:50 14 PeerGroup.setDownloadPeer: Setting download peer: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:07:50, height=163}
13:07:50 14 Peer.processFeeFilter: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:07:50, height=163}: Announced fee filter: 0.00001 BTC/kB
13:07:51 13 PeerGroup$ChainDownloadSpeedCalculator.calculate: End of sync detected at height 163.
13:07:53 14 Peer.downloadDependencies: [127.0.0.1]:18444: Downloading dependencies of 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6
13:07:53 14 Peer.processNotFoundMessage: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:07:50, height=163}: Bottomed out dep tree at ef687d8254ed9f9c074968a2a279639465ff647949bc12a9cc68e1a880e0f073
13:07:53 14 Peer$5.onSuccess: [127.0.0.1]:18444: Dependency download complete!
13:07:53 14 Wallet.receivePending: Received a pending transaction 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6 that spends 0.95629716 BTC from our own wallet, and sends us 0.95625426 BTC
13:07:53 14 Wallet.maybeCommitTx: commitTx of 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6
13:07:53 14 Wallet.updateForSpends:   marked ef687d8254ed9f9c074968a2a279639465ff647949bc12a9cc68e1a880e0f073:0 as spent by 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6
13:07:53 14 Wallet.maybeMovePool:   ef687d8254ed9f9c074968a2a279639465ff647949bc12a9cc68e1a880e0f073 prevtx <-unspent ->spent
13:07:53 14 Wallet.maybeCommitTx: ->pending: 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6
13:07:53 14 Wallet.maybeCommitTx: Estimated balance is now: 0.95625426 BTC
13:07:53 14 WalletFiles.saveNow: Saving wallet; last seen block is height 163, date 2024-01-04T19:06:07Z, hash 10a54c7d9502bd633ca22d7fc50b6e5730d3b9a86f9eabbbca05c5b6401dc952
13:07:53 14 WalletFiles.saveNowInternal: Save completed in 7.810 ms

Start wallet second time:

13:09:07 1 AbstractBlockChain.<init>: chain head is at height 163:
 block: 
   hash: 10a54c7d9502bd633ca22d7fc50b6e5730d3b9a86f9eabbbca05c5b6401dc952
   version: 805306368 (BIP34, BIP66, BIP65)
   previous block: 5bd82a8b5d584d59081f18afda85e475594968dd3876dc8ca33b57713aa64e1b
   time: 1704395167 (2024-01-04T19:06:07Z)
   difficulty target (nBits): 545259519
   nonce: 0

13:09:07 1 Wallet.setTransactionBroadcaster: New broadcaster so uploading waiting tx 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6
13:09:07 1 TransactionBroadcast.broadcast: Waiting for 1 peers required for broadcast, we have 0 ...
13:09:07 13 PeerGroup$9.run: Starting ...
13:09:07 13 PeerGroup$7.go: Localhost peer detected, trying to use it instead of P2P discovery
13:09:07 13 PeerGroup.connectTo: Attempting connection to [127.0.0.1]:18444     (0 connected, 1 pending, 0 max)
13:09:07 14 NioClientManager.handleKey: Connected to localhost/127.0.0.1:18444
13:09:07 14 Peer.connectionOpened: Announcing to localhost/127.0.0.1:18444 as: /bitcoinj:0.15.10.bisq.16/WalletTool:1.0/
13:09:07 14 Peer.processVersionMessage: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:09:07, height=163}
13:09:07 14 PeerGroup.handleNewPeer: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:09:07, height=163}: New peer      (1 connected, 0 pending, 1 max)
13:09:07 14 Peer.setBloomFilter: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:09:07, height=163}: Sending Bloom filter and querying mempool
13:09:07 14 PeerGroup.setDownloadPeer: Setting download peer: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:09:07, height=163}
13:09:07 12 TransactionBroadcast$EnoughAvailablePeers.run: broadcastTransaction: We have 1 peers, adding 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6 to the memory pool
13:09:07 12 TransactionBroadcast$EnoughAvailablePeers.run: Sending to 1 peers, will wait for 0, sending to: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:09:07, height=163}
13:09:07 14 Peer.processFeeFilter: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:09:07, height=163}: Announced fee filter: 0.00001 BTC/kB
13:09:08 13 PeerGroup$ChainDownloadSpeedCalculator.calculate: End of sync detected at height 163.
13:09:16 14 Peer.downloadDependencies: [127.0.0.1]:18444: Downloading dependencies of 6e332b1c5a6a5daf4aadfbe55f6c9c24527426d8b2186199b629e588273c0b59
13:09:16 14 Peer$8.onSuccess: [127.0.0.1]:18444: Downloaded dependency of 6e332b1c5a6a5daf4aadfbe55f6c9c24527426d8b2186199b629e588273c0b59: 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6
13:09:16 14 Peer.processNotFoundMessage: Peer{[127.0.0.1]:18444, version=70016, subVer=/Satoshi:24.0.1/, services=1037 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED), time=2024-01-04 13:09:07, height=163}: Bottomed out dep tree at ef687d8254ed9f9c074968a2a279639465ff647949bc12a9cc68e1a880e0f073
13:09:16 14 Peer$5.onSuccess: [127.0.0.1]:18444: Dependency download complete!
13:09:16 14 Wallet.receivePending: Received a pending transaction 6e332b1c5a6a5daf4aadfbe55f6c9c24527426d8b2186199b629e588273c0b59 that spends 0.95625426 BTC from our own wallet, and sends us 0.00 BTC
13:09:16 14 Wallet.maybeCommitTx: commitTx of 6e332b1c5a6a5daf4aadfbe55f6c9c24527426d8b2186199b629e588273c0b59
13:09:16 14 Wallet.updateForSpends:   marked 86ea4a892f8da454953608110a98d016444333d32ba621cf00640f222e28abc6:0 as spent by 6e332b1c5a6a5daf4aadfbe55f6c9c24527426d8b2186199b629e588273c0b59
13:09:16 14 Wallet.maybeCommitTx: ->pending: 6e332b1c5a6a5daf4aadfbe55f6c9c24527426d8b2186199b629e588273c0b59
13:09:16 14 Wallet.maybeCommitTx: Estimated balance is now: 0.00 BTC
13:09:16 14 WalletFiles.saveNow: Saving wallet; last seen block is height 163, date 2024-01-04T19:06:07Z, hash 10a54c7d9502bd633ca22d7fc50b6e5730d3b9a86f9eabbbca05c5b6401dc952
13:09:16 14 WalletFiles.saveNowInternal: Save completed in 27.77 ms

Additional information:

Chaining tx and sending to P2WPKH does not exhibit the problem.

[pazza83]

Thanks for investigating this.

Hard to know exactly but I think the issue is the cause of a significant number of abandoned trades recently due to a more unpredictable fee environment.

As miner fees have spiking frequently this year, users deposits are often not confirmed for 4 hours.
When this happens the users gets something similar to the following error message:

• User then does an SPV resync
• Trade shows as failed
• User moves trade to failed
• User does not get mediator messages leading to trade going to arbitration
• Arbitrator is also unable to message the effected user

[github-actions]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[github-actions]

This issue has been automatically closed because of inactivity. Feel free to reopen it if you think it is still relevant.