Bisq keeps disconnecting and reconnecting to local Bitcoin node

[Akira45-0]

Description

Bisq connects to local Bitcoin node, then disconnects after a few seconds, then connects again, then disconnects and so on. Number of connected nodes keeps changing from 0 to 1, then from 1 to 0, and so on.

Version

1.9.17

Steps to reproduce

1. Launch your local Bitcoin node with the required options (server=1, prune=0, peerbloomfilters=1 and so on).
2. Launch Bisq, for instance with /opt/bisq/bin/Bisq --rpcUser=user --rpcPassword=pass --rpcPort=8332 --rpcBlockNotificationPort=5120
3. Notice how it keeps connecting and disconnecting from the Bitcoin node.

Expected behaviour

Bisq should stay connected to the local Bitcoin node.

Actual behaviour

Bisq keeps connecting and disconnecting from the Bitcoin node.

Screenshots

Device or machine

Linux

Additional info

From the google search it looks like the disconnections might have something to do with hardcoded setting of the PENDING_TX_DOWNLOADS_LIMIT in the bitcoinj library, see for instance here: https://groups.google.com/g/bitcoinj/c/R14TzTo-yBI or here bitcoinj/bitcoinj#3210

Log:

Oct-25 09:17:19.209 [PeerGroup Thread] INFO  o.b.c.PeerGroup: Localhost peer detected, trying to use it instead of P2P discovery 
Oct-25 09:17:19.216 [PeerGroup Thread] INFO  o.b.c.PeerGroup: Attempting connection to [127.0.0.1]:8333     (0 connected, 1 pending, 0 max) 
Oct-25 09:17:19.222 [NioClientManager] INFO  o.b.n.NioClientManager: Connected to localhost/127.0.0.1:8333 
Oct-25 09:17:19.222 [NioClientManager] INFO  o.b.core.Peer: Announcing to localhost/127.0.0.1:8333 as: /bitcoinj:0.15.10.bisq.16/Bisq:1.9.17/ 
Oct-25 09:17:19.227 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:19, height=867254} 
Oct-25 09:17:19.229 [NioClientManager] INFO  o.b.c.PeerGroup: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:19, height=867254}: New peer      (1 connected, 0 pending, 1 max) 
Oct-25 09:17:19.229 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:19, height=867254}: Sending Bloom filter and querying mempool 
Oct-25 09:17:19.231 [NioClientManager] INFO  o.b.c.PeerGroup: Setting download peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:19, height=867254} 
Oct-25 09:17:19.234 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:19, height=867254}: Announced fee filter: 0.00001 BTC/kB 
Oct-25 09:17:19.558 [JavaFX Application Thread] INFO  b.c.a.BisqSetup: Wallet password required 
Oct-25 09:17:20.232 [PeerGroup Thread] INFO  o.b.c.PeerGroup$ChainDownloadSpeedCalculator: End of sync detected at height 867254. 
Oct-25 09:17:23.299 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:19, height=867254}: Too many pending transactions, disconnecting 
Oct-25 09:17:23.300 [NioClientManager] INFO  o.b.c.PeerGroup: [127.0.0.1]:8333: Peer died      (0 connected, 0 pending, 1 max) 
Oct-25 09:17:23.300 [NioClientManager] INFO  o.b.c.PeerGroup: Download peer died. Picking a new one. 
Oct-25 09:17:23.300 [NioClientManager] INFO  o.b.c.PeerGroup: Unsetting download peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:19, height=867254} 
Oct-25 09:17:23.301 [PeerGroup Thread] INFO  o.b.c.PeerGroup: Waiting 999 ms before next connect attempt to [127.0.0.1]:8333 
Oct-25 09:17:23.304 [NioClientManager] WARN  o.b.n.ConnectionHandler: Error handling SelectionKey: java.nio.channels.CancelledKeyException  java.nio.channels.CancelledKeyException: null
	at java.base/sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:71)
	at java.base/sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:130)
	at java.base/java.nio.channels.SelectionKey.isWritable(SelectionKey.java:377)
	at org.bitcoinj.net.ConnectionHandler.handleKey(ConnectionHandler.java:244)
	at org.bitcoinj.net.NioClientManager.handleKey(NioClientManager.java:86)
	at org.bitcoinj.net.NioClientManager.run(NioClientManager.java:122)
	at com.google.common.util.concurrent.AbstractExecutionThreadService$1$2.run(AbstractExecutionThreadService.java:66)
	at com.google.common.util.concurrent.Callables$4.run(Callables.java:117)
	at org.bitcoinj.utils.ContextPropagatingThreadFactory$1.run(ContextPropagatingThreadFactory.java:51)
	at java.base/java.lang.Thread.run(Thread.java:829)

Oct-25 09:17:23.622 [StartTor] INFO  b.n.p.n.NewTor: 
################################################################
Tor started after 4847 ms. Start publishing hidden service.
################################################################ 
Oct-25 09:17:23.815 [JavaFX Application Thread] INFO  b.n.p.p.g.RequestDataHandler: 

>> We send a PreliminaryGetDataRequest to peer devinsn2teu33efff62bnvwbxmfgbfjlgqsu3ad4b4fudx3a725eqnyd.onion:8000
 
Oct-25 09:17:23.986 [JavaFX Application Thread] INFO  b.n.p.p.g.RequestDataHandler: 

>> We send a PreliminaryGetDataRequest to peer runbtcsd42pwlfna32ibcrrykrcmozgv6x73sxjrdohkm55v5f6nh6ad.onion:8000
 
Oct-25 09:17:24.301 [PeerGroup Thread] INFO  o.b.c.PeerGroup: Attempting connection to [127.0.0.1]:8333     (0 connected, 1 pending, 1 max) 
Oct-25 09:17:24.302 [NioClientManager] INFO  o.b.n.NioClientManager: Connected to localhost/127.0.0.1:8333 
Oct-25 09:17:24.302 [NioClientManager] INFO  o.b.core.Peer: Announcing to localhost/127.0.0.1:8333 as: /bitcoinj:0.15.10.bisq.16/Bisq:1.9.17/ 
Oct-25 09:17:24.303 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:24, height=867254} 
Oct-25 09:17:24.304 [NioClientManager] INFO  o.b.c.PeerGroup: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:24, height=867254}: New peer      (1 connected, 0 pending, 1 max) 
Oct-25 09:17:24.304 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:24, height=867254}: Sending Bloom filter and querying mempool 
Oct-25 09:17:24.306 [NioClientManager] INFO  o.b.c.PeerGroup: Setting download peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:24, height=867254} 
Oct-25 09:17:24.306 [NioClientManager] INFO  o.b.c.l.DownloadProgressTracker: Chain download switched to Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:24, height=867254} 
Oct-25 09:17:24.309 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:24, height=867254}: Announced fee filter: 0.00001 BTC/kB 
Oct-25 09:17:25.679 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:24, height=867254}: Too many pending transactions, disconnecting 
Oct-25 09:17:25.680 [NioClientManager] INFO  o.b.c.PeerGroup: [127.0.0.1]:8333: Peer died      (0 connected, 0 pending, 1 max) 
Oct-25 09:17:25.680 [NioClientManager] INFO  o.b.c.PeerGroup: Download peer died. Picking a new one. 
Oct-25 09:17:25.680 [NioClientManager] INFO  o.b.c.PeerGroup: Unsetting download peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:24, height=867254} 
Oct-25 09:17:25.681 [NioClientManager] WARN  o.b.n.ConnectionHandler: Error handling SelectionKey: java.nio.channels.CancelledKeyException  java.nio.channels.CancelledKeyException: null
	at java.base/sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:71)
	at java.base/sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:130)
	at java.base/java.nio.channels.SelectionKey.isWritable(SelectionKey.java:377)
	at org.bitcoinj.net.ConnectionHandler.handleKey(ConnectionHandler.java:244)
	at org.bitcoinj.net.NioClientManager.handleKey(NioClientManager.java:86)
	at org.bitcoinj.net.NioClientManager.run(NioClientManager.java:122)
	at com.google.common.util.concurrent.AbstractExecutionThreadService$1$2.run(AbstractExecutionThreadService.java:66)
	at com.google.common.util.concurrent.Callables$4.run(Callables.java:117)
	at org.bitcoinj.utils.ContextPropagatingThreadFactory$1.run(ContextPropagatingThreadFactory.java:51)
	at java.base/java.lang.Thread.run(Thread.java:829)

Oct-25 09:17:25.681 [PeerGroup Thread] INFO  o.b.c.PeerGroup: Waiting 1500 ms before next connect attempt to [127.0.0.1]:8333 
Oct-25 09:17:26.789 [Thread-11] INFO  b.n.p.n.TorNetworkNode: 
################################################################
Tor hidden service published after 3167 ms. Socket=HiddenServiceSocket[addr=k6ktzs36vlsvmhacgrbcqitde7faomhtfjp74b6pm376wepnirfpvsyd.onion,port=9999]
################################################################ 
Oct-25 09:17:27.191 [PeerGroup Thread] INFO  o.b.c.PeerGroup: Attempting connection to [127.0.0.1]:8333     (0 connected, 1 pending, 1 max) 
Oct-25 09:17:27.192 [NioClientManager] INFO  o.b.n.NioClientManager: Connected to localhost/127.0.0.1:8333

[Akira45-0]

Update: with a fresh, new data directory the connection is perfectly stable and everything works fine.

So I suspect it is a problem with wallet handling, especially when you consider this part of the logs:

Oct-25 09:17:23.299 [NioClientManager] INFO  o.b.core.Peer: Peer{[127.0.0.1]:8333, version=70016, subVer=/Satoshi:28.0.0/, services=3085 (NETWORK, BLOOM, WITNESS, NETWORK_LIMITED, remaining: 100000000000), time=2024-10-25 09:17:19, height=867254}: Too many pending transactions, disconnecting 
Oct-25 09:17:23.300 [NioClientManager] INFO  o.b.c.PeerGroup: [127.0.0.1]:8333: Peer died      (0 connected, 0 pending, 1 max) 

As of now, my old wallet has 3743 entries in Funds/Transactions.

[Akira45-0]

It is noteworthy that setting the mempoolexpiry parameter to 1 in the Bitcoin Core configuration makes the connection stable even with the old datadir with many transactions.
I'm just not sure if it's a safe, reliable and viable solution.
In my opinion Bisq should be able to handle at least the default mempoolexpiry=336 setting.

Edit: I got back to default mempoolexpiry setting (by removing this option from the conf file) and deleted the mempool.dat file. So far it works. We'll see for how long.

[dutu]

same old #3763 (comment)

[Akira45-0]

I had to restart the machine while having about 46000 transactions in the mempool (mempool size was about 23 MB) and the issue has reappeared. So I deleted the mempool.dat, restarted the Bitcoin node, and the issue has magically disappeared.

So apparently the mempool state while establishing the bisq->btc node connection matters, not the actual mempool size.

Go figure.