getbestblockhash is sometimes taking a very long time #32733

Is there an existing issue for this?

• I have searched the existing issues

Current behaviour

I'm running Bitcoin Core v29 on a RPi v4 with 4GB RAM and 2TB SSD. Sometimes when I run "getbestblockhash" it takes a very long time.

admin@raspibolt2:~ $ time bitcoin-cli getbestblockhash
0000000000000000000208fcdfe388b464d7a7ef9c05b2ad2701488f1eedbe70

real    10m21.332s
user    0m0.000s
sys     0m0.026s
admin@raspibolt2:~ $ time bitcoin-cli getbestblockhash
000000000000000000002f0d8fcab1392628ed73aa18848aa44cb53de6dff349

real    11m34.199s
user    0m0.002s
sys     0m0.044s
admin@raspibolt2:~ $ time bitcoin-cli getbestblockhash
0000000000000000000083ac9f1bc7ae399cd89f84c3058e5e7905a66da66394

real    4m40.592s
user    0m0.008s
sys     0m0.019s
admin@raspibolt2:~ $ time bitcoin-cli getbestblockhash
0000000000000000000083ac9f1bc7ae399cd89f84c3058e5e7905a66da66394

real    0m0.144s
user    0m0.007s
sys     0m0.009s

The last entry I ran immediately after the previous call and it returns the same hash which I guess is cached or easier to read on a subsequent call. I don't see anything in the logs but I am running the default log settings.

Is there something that I need to tweak to get this to be more performant? Is there any other information needed to debug this?

Expected behaviour

getbestblockhash should return in seconds instead of minutes

Steps to reproduce

bitcoin-cli getbestblockhash ....I'm not certain what data or environmental issues would cause it to take minutes to return.

Relevant log output

No response

How did you obtain Bitcoin Core

Compiled from source

What version of Bitcoin Core are you using?

v29

Operating system and version

Debian Bullseye Lite

Machine specifications

RPI 4 4GB RAM 2TB SSD connected via USB

• Did you upgrade from 28.x? (https://github.com/bitcoin/bitcoin/issues/32455)
• Other than that, I'd check the debug log via the debug categories bench, blockstorage, lock, prune, validation, and possibly rpc, if there is a background caller?

• Did you upgrade from 28.x? (bitcoind 29.0 much slower than 28.0 on my system: cause found [#32455](/bitcoin-bitcoin/32455/))

I upgraded from v27.x I believe.

* Other than that, I'd check the debug log via the  debug categories `bench, blockstorage, lock, prune, validation`, and possibly `rpc`, if there is a background caller?

I'll add these into the log and see what comes of it.

getbestblockhash() doesn't do much aside from waiting for a lock on cs_main:

https://github.com/bitcoin/bitcoin/blob/5757de4ddd37f9321ee6b338b40888fd3561fc00/src/rpc/blockchain.cpp#L242-L262

I would be curious to see what the logs show the node doing right before returning the result of getbestblockhash, could you maybe also add the coindb logging category?

sure, I'll add that too.

is the cs_main lock used often? I'm assuming it is here to stop the output of an older block hash if it is in the middle of updating to the latest. My CPP skills are about 30 years rusty so I'm just taking an educated guess.

When I restarted the bitcoind it said that "debug=lock" is invalid so I removed it from the configuration.

ok, it looks like when the client is validating a block it is locking and the RPC call is hung until that validation is complete. Here are the logs and the RPC call only returned after this set of logs (or thereabouts). There doesn't seem to be a log statement when the RPC call returns only when it is intiated

2025-06-13T02:23:59Z [validation] NewPoWValidBlock: block hash=00000000000000000000bacaf46dcf6fdb5b874b97c83b3f4905c2fc8494920b
2025-06-13T02:23:59Z [bench]   - Using cached block
2025-06-13T02:23:59Z [bench]   - Load block from disk: 0.10ms
2025-06-13T02:23:59Z [bench]     - Sanity checks: 1.06ms [0.00s (1.06ms/blk)]
2025-06-13T02:23:59Z [bench]     - Fork checks: 8.52ms [0.01s (8.52ms/blk)]
2025-06-13T02:24:34Z [rpc] ThreadRPCServer method=getbestblockhash user=[redacted]
2025-06-13T02:28:41Z Loading addresses from DNS seed seed.bitcoin.jonasschnelli.ch.
2025-06-13T02:28:41Z Loading addresses from DNS seed dnsseed.bluematt.me.
2025-06-13T02:28:41Z Loading addresses from DNS seed seed.btc.petertodd.net.
2025-06-13T02:28:41Z Waiting 300 seconds before querying DNS seeds.
2025-06-13T02:32:39Z [bench]       - Connect 2344 transactions: 519962.12ms (221.827ms/tx, 61.266ms/txin) [519.96s (519962.12ms/blk)]
2025-06-13T02:32:39Z [bench]     - Verify 8487 txins: 519968.86ms (61.267ms/txin) [519.97s (519968.86ms/blk)]
2025-06-13T02:32:39Z [bench]     - Write undo data: 58.16ms [0.06s (58.16ms/blk)]
2025-06-13T02:32:39Z [bench]     - Index writing: 0.11ms [0.00s (0.11ms/blk)]
2025-06-13T02:32:39Z [validation] BlockChecked: block hash=00000000000000000000bacaf46dcf6fdb5b874b97c83b3f4905c2fc8494920b state=Valid
2025-06-13T02:32:39Z [bench]   - Connect total: 520054.64ms [520.05s (520054.64ms/blk)]
2025-06-13T02:32:39Z [bench]   - Flush: 52.74ms [0.05s (52.74ms/blk)]
2025-06-13T02:32:39Z [bench]   - Writing chainstate: 0.50ms [0.00s (0.50ms/blk)]
2025-06-13T02:32:39Z [validation] Enqueuing MempoolTransactionsRemovedForBlock: block height=901009 txs removed=2
2025-06-13T02:32:57Z UpdateTip: new best=00000000000000000000bacaf46dcf6fdb5b874b97c83b3f4905c2fc8494920b height=901009 version=0x36000000 log2_work=95.661865 tx=1201812749 date='2025-06-13T01:37:58Z' progress=0.999987 cache=2.0MiB(15139txo)
2025-06-13T02:32:57Z [bench]   - Connect postprocess: 18236.60ms [18.24s (18236.60ms/blk)]
2025-06-13T02:32:57Z [bench] - Connect block: 538344.57ms [538.34s (538344.57ms/blk)]
2025-06-13T02:32:57Z [validation] Enqueuing BlockConnected: block hash=00000000000000000000bacaf46dcf6fdb5b874b97c83b3f4905c2fc8494920b block height=901009
2025-06-13T02:32:57Z [validation] Enqueuing UpdatedBlockTip: new block hash=00000000000000000000bacaf46dcf6fdb5b874b97c83b3f4905c2fc8494920b fork block hash=0000000000000000000191b79fed06fb8d4689f69893c0a2ab346e9613fde846 (in IBD=false)
2025-06-13T02:32:57Z [validation] ActiveTipChange: new block hash=00000000000000000000bacaf46dcf6fdb5b874b97c83b3f4905c2fc8494920b block height=901009
2025-06-13T02:32:57Z Flushed fee estimates to fee_estimates.dat.
2025-06-13T02:32:57Z [validation] MempoolTransactionsRemovedForBlock: block height=901009 txs removed=2
2025-06-13T02:32:57Z [validation] BlockConnected: block hash=00000000000000000000bacaf46dcf6fdb5b874b97c83b3f4905c2fc8494920b block height=901009
2025-06-13T02:32:57Z [validation] Enqueuing TransactionAddedToMempool: txid=ec76dc39be25bd22af9a3d512f8082d793babcd076fcca7ec8b7dd27e66b5172 wtxid=b00884200b51aeecdef41d21c114ff07a18debf7fee8d1b458791f4d10865cff
2025-06-13T02:32:57Z [validation] Enqueuing TransactionAddedToMempool: txid=035a2de6a38dfc2d5054d3bf56293fa62a21f5c9d97cd81a1077a692812391bd wtxid=aa3cb808772fd3ba1eda0bfa76ecb97ccb22c1085308247f0c7de3fc963ff761
2025-06-13T02:32:57Z [validation] UpdatedBlockTip: new block hash=00000000000000000000bacaf46dcf6fdb5b874b97c83b3f4905c2fc8494920b fork block hash=0000000000000000000191b79fed06fb8d4689f69893c0a2ab346e9613fde846 (in IBD=false)
2025-06-13T02:32:57Z [validation] NewPoWValidBlock: block hash=000000000000000000003bc74d784339a4259f256c1e8084e6001dd971c86fd3
2025-06-13T02:32:57Z [validation] TransactionAddedToMempool: txid=ec76dc39be25bd22af9a3d512f8082d793babcd076fcca7ec8b7dd27e66b5172 wtxid=b00884200b51aeecdef41d21c114ff07a18debf7fee8d1b458791f4d10865cff
2025-06-13T02:32:57Z [validation] TransactionAddedToMempool: txid=035a2de6a38dfc2d5054d3bf56293fa62a21f5c9d97cd81a1077a692812391bd wtxid=aa3cb808772fd3ba1eda0bfa76ecb97ccb22c1085308247f0c7de3fc963ff761
2025-06-13T02:32:57Z [bench]   - Using cached block
2025-06-13T02:32:57Z [bench]   - Load block from disk: 0.09ms
2025-06-13T02:32:57Z [bench]     - Sanity checks: 0.40ms [0.00s (0.73ms/blk)]
2025-06-13T02:32:57Z [bench]     - Fork checks: 0.07ms [0.01s (4.30ms/blk)]

@martinatime is your txindex=0, txindex=1 or not set (the default: txindex=0)?

txindex=1

Looking at these debug logs, it's taking you ~500s to connect a new block to the chaintip, and the cs_main lock would be held for that time, so that explains why getblockhash takes so long.

2025-06-13T02:32:39Z [bench]       - Connect 2344 transactions: 519962.12ms (221.827ms/tx, 61.266ms/txin) [519.96s (519962.12ms/blk)]
2025-06-13T02:32:39Z [bench]     - Verify 8487 txins: 519968.86ms (61.267ms/txin) [519.97s (519968.86ms/blk)]

<details> <summary> From the logs, most of block connection is spent connecting inputs. </summary>

https://github.com/bitcoin/bitcoin/blob/2def85847318513afa7765e042567d13f616c54c/src/validation.cpp#L2598-L2707

</details>

And that the fact that the Verify bench log comes immediately after means that you were probably blocked on fetching inputs from disk (I/O), not script validation (CPU).

This points to the read performance of the disk your chainstate is stored on being quite slow. Although you may have an SSD, you might be bound by the speed of the USB adapter you are using.

A rough estimate of your read speed could be gleaned by doing the following if your debug.log and chainstate are on the same disk:

# It doesn't matter what input file you use, debug.log is just likely
# to be a good candidate because it's probably on the same disk
# and big enough that the result won't be too noisy.
dd if=/path/to/your/debug.log of=/dev/null bs=4M

Running "dd" gave the following

3+1 records in
3+1 records out
13172848 bytes (13 MB, 13 MiB) copied, 0.0638072 s, 206 MB/s

For database performance, I/O operations per second of the disk is more important than bull sequential transfer speed.

Is there a method to test that?

How did you obtain Bitcoin Core

Compiled from source

Could it be that OP simply compiled without optimisations, causing an expected slowdown in block connection which is amplified by running on low-end hardware?

I didn't compile from source. I have always used the pre-compiled release binaries

> 13172848 bytes (13 MB, 13 MiB) copied, 0.0638072 s, 206 MB/s

~13 MiB is probably too small of a file to measure read speed accurately, can you do:~

du -ah /path/to/drive | sort -rh | head -10

To find the largest single file on the drive, and try doing the same dd benchmark as above.

Edit:

The fio tool is probably better suited for measuring disk performance than dd, could you try the following, this will also report disk IOPS:

# you may have to install the `fio` package, e.g. `sudo apt-get install fio`
fio --name=iops_test --ioengine=libaio --iodepth=32 --rw=randread --bs=4k --direct=1 --size=4G --directory=<path-to-datadir>

Does -forcecompactdb improve the situation for you?

I don't think I have tried that. Is there a way I can tell if the db needs to be compacted before I attempt this?

I am running Bitcoin Core v28.0.0 with txindex=1 on an RPi 4 with 8 GB RAM and 1 TB USB-SSD and I have no performance issues at all. I also run LND and some other bitcoin monitoring software that makes RPCs every 1 second.

Just for a sanity check, can you ensure that your bitcoin data directory is being written to external SSD and not the MicroSD card?

I'll update to 29 and continue to monitor

My RPi 4 only has 4GB of RAM and I am only running off of the SSD with no SD card installed.

Running v29 on my Pi4 has been fine so far. Even with 8 available I rarely ever see it use more than 2, and this is with lnd, LndHub, tor, and a few other services. I will note that I am still running the 32-bit PiOS however.

$ free -mh                                                           
                total        used        free      shared  buff/cache   available                                                                            
Mem:           7.7Gi       1.2Gi       490Mi        41Mi       6.0Gi       6.3Gi                                                                            
Swap:           99Mi          0B        99Mi                                                                                                                

$ uname -a          
Linux zippi 6.1.61-v8+ [#1696](/bitcoin-bitcoin/1696/) SMP PREEMPT Thu Nov  2 16:44:46 GMT 2023 aarch64 GNU/Linux 

$ getconf LONG_BIT
  32                                   

I'm using the 64bit version of PiOS and I also seem to have more than half my memory free.

$ free -mh total used free shared buff/cache available Mem: 3.7Gi 1.1Gi 38Mi 0.0Ki 2.5Gi 2.5Gi Swap: 2.0Gi 2.0Gi 0.0Ki

$ uname -a Linux raspibolt2 6.1.21-v8+ #1642 SMP PREEMPT Mon Apr 3 17:24:16 BST 2023 aarch64 GNU/Linux

$ getconf LONG_BIT 64

I can't imagine that the 32/64 bit allocations are the reason for any slowdown. But maybe I'm wrong.