Bisq disconnected from local btc node

[iljah]

Found this in my log:

[PeerGroup Thread] WARN  o.b.c.PeerGroup: Chain download stalled: received 0.91 KB/sec for 10 seconds, require average of 1.56 KB/sec, disconnecting [127.0.0.1]:8333                                 
[PeerGroup Thread] INFO  o.b.c.PeerGroup: [127.0.0.1]:8333: Peer died      (0 connected, 0 pending, 1 max)                                                                                            
[PeerGroup Thread] INFO  o.b.c.PeerGroup: Download peer died. Picking a new one.      
[PeerGroup Thread] INFO  o.b.c.PeerGroup: Unsetting download peer: [127.0.0.1]:8333

after which bisq seemed to be stuck with UI not reacting to anything. I'm guessing bisq doesn't need protection from "bad" local btc node...

[ManfredKarrer]

Seems you had a local BTC node. Maybe you restarted BTC core or the like... Reconnection in such a case does not work (with normal nodes it reconnects).

[iljah]

Didn't touch btc node. Disconnect reason seems pretty clear to me: Chain download stalled: received 0.91 KB/sec for 10 seconds, require average of 1.56 KB/sec, disconnecting [127.0.0.1]:8333

[iljah]

Happened again on another machine with freshly compiled bisq from yesterday. Btc chain download was at 99 % when bisq disconnected due to stalled download. UI became stuck afterwards for at least two min, had to ctrl+c and start bisq again. And now it looks like bisq remembers that localhost btc node was banned and doesn't want to connect to it or anything else, making bisq unusable...

[ManfredKarrer]

@iljah Did you use other port for Bitcoin Core than the standard 8333?

[ManfredKarrer]

Did you run master or the release branch?

[ManfredKarrer]

I just could reproduce it on testnet. It downloaded 90 MB from BitcoinCoin Core and then gets disconnected and fails to continue download after reconnect. After restart it does not download anything anymore (even it was stuck at 5% - prob. wrong value) and is fully connected then.

At a second try with a deleted data dir I got again 90 MB then it was stuck (thought after a while it was recovering and startup was complete).
I assume Bitcoin core has some ddos protection here and likely that was changed in the latest releases, I have not observed such issues earlier.

@oscarguindzberg Do you have an idea?

[iljah]

I'm using port 8333, master branch at bitcoin/bitcoin@efaf2d8

[iljah]

By default upload doesn't seem to be limited and I haven't limited it either: https://github.com/bitcoin/bitcoin/blob/master/src/net.h#L76

[ManfredKarrer]

Maybe its something on the BitcoinJ side, but we did not have any bigger changes here.... so thats strange...

[ManfredKarrer]

Fixed with #1823

[ManfredKarrer]

Actually the disconnect it not fixed but that seems to be not a critical issue...

[iljah]

"Fixed with" above points to this issue, shouldn't it point to something else?

[oscarguindzberg]

I think Manfred means "Fixed with 9389a8e"

[oscarguindzberg]

• I have looked at this issue a couple of weeks ago, I will leave my comments here in case anyone wants to revisit this problem.
• About “It looks like bisq remembers that localhost btc node was banned”:
  • I don’t think so and I don’t think bitcoin core is banning bitcoinj either.
  • I searched “DoS” and “Denial of Service” in bitcoin core release notes and mailing list: nothing relevant found.
  • I did not find any signs of DoS detected nor that bitcoinJ peer was disconnected by core on bitcoin core logs.
• Steps to reproduce the problem
  • Start a bisq node (code previous Manfred’s update of checkpoints) on a mac from intellij with an empty data dir connected to a local bitcoin core 0.17.0.1 testnet.
  • That makes bisq CPU consumption to skyrocket (over 100%). It also takes as much RAM as it can. That takes 2 to 3 minutes during and after bitcoinj blockchain sync.
  • I think this might cause some/all the problems I will describe later.
  • Debug from intellij makes things even worse... OutOfMemoryError and desktop freezing.
  • The problem was not reproduced connecting to random peers on the bitcoin testnet network.
• I think updating the checkpoints is a patch, probably a good patch. But the problem is still there.
  • If a new version of bisq with updated checkpoints is not released often or a user uses an old bisq version, the problem will show up again.
  • If a user uses the “recover from seed” feature with an old seed the problem will show up no matter she is using the latest bisq version.
• The real cause of the CPU/RAM spike is yet to be discovered.
  • Here are some ideas to explore...
  • jdk 10. I know Manfred says he could reproduce the bug with old bisq releases before the upgrade to jdk 10 and the problem is still there. I would double check bisq executable isn’t using operating system default jdk (ie 10) instead of the jdk embedded in the executable (ie 8).
  • Bad thread management. I am not saying deadlock, but there might be stuff on hold that should not be on hold (maybe waiting for chain sync complete when it should not).
• Then I detected other problems...
• UI chain sync progress tracker is behind bitcoinj log progress tracker. 
  • When command line log progress tracker reaches 100%, UI tracker shows a smaller % and after a “while” it says to be fully synced.
  • Theories:
    • UI tracker is updated when a new block is received
    • UI trackeris updated when bisq cpu consumption goes down and the UI thread can refresh the screen.
• “Block does not connect” printed on the logs.
  • log shows
    • AbstractBlockChain.add: Block does not connect: ...
    • AbstractBlockChain.tryConnectingOrphans: Connected orphan …
    • AbstractBlockChain.tryConnectingOrphans: Connected 1 orphan blocks.
  • Those log messages were printed because bitcoinj blockchain processed the child block first and then its parent.
  • Theories
    • bitcoinj received them on the opposite order. Then the question would be why core is sending blocks not in the right order. One thing to investigate is: during bitcoinj chain sync, if core receives a new block, does it forward it to bitcoinj?
    • bitcoinj node receives the blocks in order but somehow it passes them to the Blockchain class in the wrong order.
    • Something related to the cpu/ram spike.
  • I have seen this behavior before on other projects that use bitcoinj too (last block processed before its parent) but I have never paid too much attention because it was harmless to my use case at the time.
• When block download completes localhost peer is disconnected and reconnected
  • This is what @iljah originally reported as a problem. Log shows “Download peer died. Picking a new one.”
  • After the chain is fully synced PeerGroup.ChainDownloadSpeedCalculator keeps running once per second.
  • For some reason (to be found out) "behindPeers" variable is still true, so it makes ChainDownloadSpeedCalculator keep running.
  • After a while, since no new blocks are received (because the blockchain is in sync) ChainDownloadSpeedCalculator thinks the peer is not sending blocks at the speed it should, prints “Chain download stalled” and disconnects the peer
  • Later, bitcoinj reconnects to the same peer.
  • Theories of why "behindPeers" variable is still true after blockchain sync is complete:
    • Nonproblematic random race conditions.
    • Something related to the cpu/ram spike.
  • Again, I remember my bitcoinj node disconnecting and reconnecting to my local QT on other projects and did not pay much attention to it at the time.

[iljah]

I suspected that bisq remembers disconnecting from local btc node because when it first disconnected its UI froze and I had to ctrl+c bisq from command line. After starting it again it didn't connect to local or any other node and just sat there with nothing happening, don't remember for how long (several minutes at least). After restarting again one or more times it finally started connecting to local btc node again and everything returned to normal. I haven't restarted bisq recently and/so haven't seen this behavior since.

[ManfredKarrer]

@oscarguindzberg
Re "I would double check bisq executable isn’t using operating system default jdk (ie 10) instead of the jdk embedded in the executable": Yes it use for sure the embedded JDK.

[ManfredKarrer]

Add a few comments from my testing:

• I tested diff. versions of original BitcoinJ releases (0.14.4. up to 0.14.7) with the WalletAppKit and could reproduce the issue (with localhost testnet) with version 0.14.4 but not with higher ones. Found out that the new checkpoint file was the relevant change causing it.

I agree with @oscarguindzberg that the real cause will be something else, but it seems to be triggered when the app needs to download more blockheaders from the past in case the checkpoint file is old. I have not tested with connection to public network. It might be related to the localhost setup and not causing the problems when connected to several nodes.

[iljah]

triggered when the app needs to download more blockheaders from the past in case the checkpoint file is old. I have not tested with

This might be what happened also to me. I vaguely remember seeing this e.g. after removing all cached data from bisq in order to fix my stuck order.