Bitcoin Core not using configured database cache size and taking way too long to sync #10647

Describe the issue

My bitcoin core wallet is taking a ridiculously long time to catch up to the blockchain. I've been running it on and off for a MONTH now, and I'm still 41 weeks behind. Looking at my Task Manager, I see that my network is being almost totally unutilized at 0.1Mbps, tho my disk is being used at 1.5 MBps. It also says the Bitcoin Core (GUI node for Bitcoin) is only using 280 MB of memory, even tho I have -dbcache=700 set in the config (which I can see it recognizes in the options since it lists it under "Active command-line options that override above options").

I have also tried removing -dbcache=700 from my bitcoin.conf and instead setting 1000 MB as the database cache option in the GUI options window (and restarting of course). Neither the bitcoin.conf nor the database cache size option in the options seem to affect how much memory is allocated to bitcoin core, even tho I have at least 800MB free.

What version of bitcoin-core are you using?

Bitcoin Core version v0.14.1 (64-bit), official

Machine specs:

• OS: Windows 8.1 64-bit
• CPU: Intel Core i7-4702HQ @ 2.2 GHz
• RAM: 8 GB
• Disk size: 4TB HD for the blockchain, 250 GB SSD for the program and other (smaller) data
• Network Speed: 50 Mbps

Any extra information that might be useful in the debugging process.

My debug.log (note the weird whitespace is verbatim):

2017-06-21 19:59:18 



















2017-06-21 19:59:18 Bitcoin version v0.14.2
2017-06-21 19:59:18 InitParameterInteraction: parameter interaction: -whitelistforcerelay=1 -> setting -whitelistrelay=1
2017-06-21 19:59:18 Assuming ancestors of block 00000000000000000013176bf8d7dfeab4e1db31dc93bc311b436e82ab226b90 have valid signatures.
2017-06-21 19:59:18 GUI: "registerShutdownBlockReason: Successfully registered: Bitcoin Core didn't yet exit safely..."
2017-06-21 19:59:18 Default data directory C:\Users\fresheneesz\AppData\Roaming\Bitcoin
2017-06-21 19:59:18 Using data directory H:\Bitcoin
2017-06-21 19:59:18 Using config file H:\Bitcoin\bitcoin.conf
2017-06-21 19:59:18 Using at most 125 automatic connections (2048 file descriptors available)
2017-06-21 19:59:18 Using 32 MiB out of 32 requested for signature cache, able to store 1048576 elements
2017-06-21 19:59:18 Using 4 threads for script verification
2017-06-21 19:59:18 Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2017-06-21 19:59:18 Using wallet wallet.dat
2017-06-21 19:59:18 scheduler thread start
2017-06-21 19:59:18 init message: Verifying wallet...
2017-06-21 19:59:18 CDBEnv::Open: LogDir=H:\Bitcoin\database ErrorFile=H:\Bitcoin\db.log
2017-06-21 19:59:18 Bound to [::]:8333
2017-06-21 19:59:18 Bound to 0.0.0.0:8333
2017-06-21 19:59:18 Cache configuration:
2017-06-21 19:59:18 * Using 2.0MiB for block index database
2017-06-21 19:59:18 * Using 8.0MiB for chain state database
2017-06-21 19:59:18 * Using 990.0MiB for in-memory UTXO set (plus up to 286.1MiB of unused mempool space)
2017-06-21 19:59:18 init message: Loading block index...
2017-06-21 19:59:18 Opening LevelDB in H:\Bitcoin\blocks\index
2017-06-21 19:59:18 Opened LevelDB successfully
2017-06-21 19:59:18 Using obfuscation key for H:\Bitcoin\blocks\index: 0000000000000000
2017-06-21 19:59:18 Opening LevelDB in H:\Bitcoin\chainstate
2017-06-21 19:59:19 Opened LevelDB successfully
2017-06-21 19:59:19 Using obfuscation key for H:\Bitcoin\chainstate: 2e24172acafd25a5
2017-06-21 19:59:24 LoadBlockIndexDB: last block file = 614
2017-06-21 19:59:24 LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=156, size=118252833, heights=427663...428149, time=2016-08-31...2016-09-03)
2017-06-21 19:59:24 Checking all blk files are present...
2017-06-21 19:59:24 LoadBlockIndexDB: transaction index disabled
2017-06-21 19:59:24 LoadBlockIndexDB: hashBestChain=000000000000000000784ef695fdd8651da8810ee6864155b45858d987bb8ab6 height=428092 date=2016-09-03 13:35:38 progress=0.664512
2017-06-21 19:59:24 init message: Rewinding blocks...
2017-06-21 19:59:26 init message: Verifying blocks...
2017-06-21 19:59:26 Verifying last 6 blocks at level 3
2017-06-21 19:59:26 [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
2017-06-21 19:59:31 No coin database inconsistencies in last 7 blocks (15977 transactions)
2017-06-21 19:59:31  block index           12566ms
2017-06-21 19:59:31 init message: Loading wallet...
2017-06-21 19:59:31 nFileVersion = 140200
2017-06-21 19:59:31 Keys: 102 plaintext, 0 encrypted, 102 w/ metadata, 102 total
2017-06-21 19:59:31  wallet                  309ms
2017-06-21 19:59:31 setKeyPool.size() = 100
2017-06-21 19:59:31 mapWallet.size() = 0
2017-06-21 19:59:31 mapAddressBook.size() = 1
2017-06-21 19:59:31 mapBlockIndex.size() = 472291
2017-06-21 19:59:31 nBestHeight = 428092
2017-06-21 19:59:31 torcontrol thread start
2017-06-21 19:59:31 AddLocal([2001:0:9d38:90d7:204a:599:b399:e59e]:8333,1)
2017-06-21 19:59:31 Discover: btbot - 2001:0:9d38:90d7:204a:599:b399:e59e
2017-06-21 19:59:31 init message: Loading addresses...
2017-06-21 19:59:31 Loaded 59991 addresses from peers.dat  307ms
2017-06-21 19:59:31 init message: Loading banlist...
2017-06-21 19:59:31 init message: Starting network threads...
2017-06-21 19:59:31 net thread start
2017-06-21 19:59:31 init message: Done loading
2017-06-21 19:59:31 addcon thread start
2017-06-21 19:59:31 msghand thread start
2017-06-21 19:59:31 opencon thread start
2017-06-21 19:59:31 dnsseed thread start
2017-06-21 19:59:42 Loading addresses from DNS seeds (could take a while)
2017-06-21 19:59:48 95 addresses found from DNS seeds
2017-06-21 19:59:48 dnsseed thread exit
2017-06-21 20:01:42 UpdateTip: new best=000000000000000003f1d2605ca6630a0060acc0c888ddccad3d6d4125e82cd6 height=428093 version=0x20000000 log2_work=85.219583 tx=153653276 date='2016-09-03 13:38:30' progress=0.664519 cache=6.8MiB(5297tx)
2017-06-21 20:01:42 GUI: Platform customization: "windows"
2017-06-21 20:01:42 GUI: PaymentServer::LoadRootCAs: Loaded  37  root certificates
2017-06-21 20:02:09 UpdateTip: new best=0000000000000000045ee23efcc1c09475d57eefa22c67c27b38f39cfc3c34e0 height=428094 version=0x20000000 log2_work=85.219613 tx=153655485 date='2016-09-03 13:49:02' progress=0.664529 cache=21.0MiB(11163tx)
2017-06-21 20:02:44 version handshake timeout from 1
2017-06-21 20:03:11 UpdateTip: new best=000000000000000003f7dcc2461a28778770029276ee304f3eb13fba6b1cea2f height=428095 version=0x20000000 log2_work=85.219643 tx=153658301 date='2016-09-03 14:12:24' progress=0.664540 cache=27.4MiB(16845tx)
2017-06-21 20:03:11 receive version message: /Satoshi:0.14.1/UASF-Segwit:0.3(BIP148)/: version 70015, blocks=472293, us=76.102.26.97:57474, peer=1
2017-06-21 20:04:06 UpdateTip: new best=0000000000000000022ac5bddcee7c811e7a0e6e5a89429acf1d58d3e8539320 height=428096 version=0x20000000 log2_work=85.219674 tx=153659848 date='2016-09-03 14:14:18' progress=0.664547 cache=31.4MiB(21399tx)
2017-06-21 20:04:06 version handshake timeout from 2
2017-06-21 20:04:06 receive version message: /Satoshi:0.14.1(UASF-SegWit-BIP148)/: version 70015, blocks=472293, us=76.102.26.97:57528, peer=2
2017-06-21 20:04:31 UpdateTip: new best=0000000000000000043ed79f2ffb751e3728f78664afad371e4500e10762b484 height=428097 version=0x20000000 log2_work=85.219704 tx=153661418 date='2016-09-03 14:19:31' progress=0.664553 cache=34.5MiB(25507tx)
2017-06-21 20:04:31 version handshake timeout from 3
2017-06-21 20:04:31 receive version message: /Satoshi:0.14.0/: version 70015, blocks=472293, us=76.102.26.97:57617, peer=3
2017-06-21 20:05:09 UpdateTip: new best=000000000000000002595133c1941973fcc9c1a8ce9c6fda28b8e0e344d03032 height=428098 version=0x20000000 log2_work=85.219734 tx=153662935 date='2016-09-03 14:24:49' progress=0.664559 cache=37.1MiB(29873tx)
2017-06-21 20:05:09 receive version message: /Satoshi:0.14.1/: version 70015, blocks=472293, us=76.102.26.97:57711, peer=4
2017-06-21 20:05:30 Pre-allocating up to position 0xb00000 in rev00614.dat
2017-06-21 20:05:31 UpdateTip: new best=00000000000000000361dcadc5ce630cabbe7636c5a62440273821f86f3bc95d height=428099 version=0x20000000 log2_work=85.219765 tx=153663979 date='2016-09-03 14:28:16' progress=0.664564 cache=50.8MiB(32801tx)
2017-06-21 20:05:52 GUI:   OpenType support missing for script 11
2017-06-21 20:05:52 GUI:   OpenType support missing for script 11
2017-06-21 20:05:52 GUI:   OpenType support missing for script 11
2017-06-21 20:05:52 GUI:   OpenType support missing for script 11
2017-06-21 20:05:52 GUI:   OpenType support missing for script 11
2017-06-21 20:05:52 GUI:   OpenType support missing for script 11
2017-06-21 20:05:52 GUI:   OpenType support missing for script 16
2017-06-21 20:05:52 GUI:   OpenType support missing for script 16
2017-06-21 20:05:52 GUI:   OpenType support missing for script 16
2017-06-21 20:05:52 GUI:   OpenType support missing for script 16
2017-06-21 20:05:52 GUI:   OpenType support missing for script 16
2017-06-21 20:05:52 GUI:   OpenType support missing for script 16
2017-06-21 20:05:54 UpdateTip: new best=0000000000000000033987fb36873b88b55f486379f69fadcaf75b9aaa3af305 height=428100 version=0x20000000 log2_work=85.219795 tx=153666230 date='2016-09-03 14:42:09' progress=0.664573 cache=56.1MiB(36737tx)
2017-06-21 20:06:19 UpdateTip: new best=000000000000000002e37eb2991f40b37be13c387f3fe7c8ba757c5914b731f8 height=428101 version=0x20000000 log2_work=85.219826 tx=153667728 date='2016-09-03 14:49:17' progress=0.664579 cache=65.6MiB(40254tx)
2017-06-21 20:06:19 receive version message: /Satoshi:0.14.0/UASF-Segwit:0.3(BIP148)/: version 70015, blocks=472293, us=76.102.26.97:57850, peer=7
2017-06-21 20:06:46 UpdateTip: new best=000000000000000002c4a8db38b8e5d5c64f375029fd9831f2227edce35990d2 height=428102 version=0x20000000 log2_work=85.219856 tx=153669727 date='2016-09-03 15:38:00' progress=0.664588 cache=75.5MiB(44108tx)
2017-06-21 20:07:28 version handshake timeout from 8
2017-06-21 20:07:40 UpdateTip: new best=00000000000000000127105f5c7acd04fe94c9b72ff5b4df838f418dfb640d1d height=428103 version=0x20000000 log2_work=85.219886 tx=153671822 date='2016-09-03 15:41:00' progress=0.664596 cache=99.1MiB(49248tx)
2017-06-21 20:08:11 UpdateTip: new best=00000000000000000243fb7f67177714cb56bc3f060df96ddb363b2ac3549645 height=428104 version=0x20000000 log2_work=85.219917 tx=153674491 date='2016-09-03 15:42:50' progress=0.664608 cache=102.3MiB(53947tx)
2017-06-21 20:08:11 version handshake timeout from 9
2017-06-21 20:08:11 receive version message: /Satoshi:0.14.1(UASF-SegWit-BIP148)/: version 70015, blocks=472293, us=76.102.26.97:58008, peer=9
2017-06-21 20:08:30 UpdateTip: new best=0000000000000000026df6ad986b718f2f326700d7c49ba4ceac08ddb5a1de8c height=428105 version=0x20000000 log2_work=85.219947 tx=153676187 date='2016-09-03 15:46:25' progress=0.664615 cache=103.4MiB(56761tx)
2017-06-21 20:08:30 receive version message: /Satoshi:0.14.1/: version 70015, blocks=472293, us=[2001:0:9d38:90d7:204a:599:b399:e59e]:58087, peer=10

I ran bitcoin core all day today, for 12 hours. It went from saying eta was 2 weeks to being 5 weeks. It only progressed maybe from 68% to 71.25% complete.

I downloaded and validated the 20GB monero blockchain in just 3 hours. Why is it taking weeks to download and verify bitcoin's blockchain that is only 5 times as large?

Hmm, your system looks incredibly slow (are you running anything else which might be using disk IOPS and/or CPU in the background?). At 20:02:44 your node marked peer 1 as "timed out, disconnect" and at 20:03:11 you processed a message from it, which is likely an indication that your disk was pegged making the import thread take a while.

I assume the Monero chain's ringsigs make it more CPU intensive than Bitcoin's (especially with assumevalid), so its not hugely surprising that Bitcoin may be slower to sync. You might try running on the SSD with -prune enabled.

Note that -dbcache also has an overhead to flush, and so you may notice that its mostly "not used" during normal runtime except for brief spikes, this should be fixed in 0.15, which should be much less disk intensive during initial sync.

@TheBlueMatt I hope my system specs don't already look incredibly slow.. At this moment, ugh.. its saying "Progress increase per hous: -0.00%" - faaaantastic. And estimated time left until synced: "%n second". Its using 1.4MB/s of my disk (my total disk usage says 25%), about .8% cpu (total being 11%), and 45MB (total used being 86%). I don't have enough space on my SSD, unfortunately, to store the blockchain.

So would you guess that 0.15 will fix my problems? This has been a huge problem for me - I wouldn't have been able to use any bitcoin for the last month if I didn't accidentally leave a few in my coinbase account. This really makes me want to just switch to electrum or something.

You say you don't have enough space on your SSD. What are you using to store the blockchain and chainstate on? Anything USB connected will likely be painfully slow, for example.

So would you guess that 0.15 will fix my problems?

No, it most likely won't. 0.15 will improve memory usage and I/O performance a bit, but it's not going to make validation suddenly 100x faster. There seems to be something fundamentally broken here that makes it so slow.

Could you run with -debug=bench? That may teach us something about where the wasted time goes.

@sipa I mentioned my 4TB external HD in my OP. It is USB connected, but copying from one USB drive to another (while they're both connected to the same hub) gives me over 20 MB/s transfer speed. Bitcoin Core isn't even using 1.5MB/s, so my hard drive transfer speed shouldn't be the issue here.

Here's my debug log after starting with -debug=bench: http://btetrud.com/files/bitcoinDebug.log

@fresheneesz The problem with USB disks is not bandwidth, but operations per second. Copying files only needs a small number of operations (each accessing large blobs of sequential bytes on disk). Block validation needs to access 1000s of small pieces, each of which results in a separate operation. USB disks are very limited in their number of operations per second, regardless of how many bytes are affected. This is also what your debug information shows; it's the fetching of inputs (the connect step in the log) which takes long, while signature validation is instant after that.

I would strongly suggest running database on an internal disk, and either run in pruning mode, or just put the blocks on the external disk, but not the database.

@sipa Hmm, some of that doesn't quite make sense to me.

USB disks are very limited in their number of operations per second

This doesn't describe latency. Why would USB disks be limited to operations per second? I get the feeling that either you're dumbing this down for me, or its just not accurate. The closest thing I can think you mean is that each disk access on a hard disk (regardless of whether its USB or not) requires moving the read head, which is kind of a geological-time operation in comparison to your CPU. Is this what you mean?

Block validation needs to access 1000s of small pieces

Ya, but I would have thought the software would store it so it can still grab large blocks to put into memory, then grab each small piece from memory, rather than trying to random-access every little bit from the disk.

just put the blocks on the external disk, but not the database.

How do I do this?

I don't have a full explanation for you, but it's very commonly observed that the operations per second is much lower for USB disks (much worse than internal spinning disks). In general, any database system running on USB tends to have terrible performance.

Disks tend to organize things in 512 to 4096 byte sections. Since the pieces of data we need to fetch for validation are only a few hundred bytes, each read tends to result in an independent fetch from disk.

As for how to move the database without moving blocks: In Linux, you can use a symlink to another directory for the $DATADIR/blocks directory. There is something similar in Windows, but I don't know the details.

Ok, well from what you're telling me it sounds like bitcoin core could implement a couple performance improvements to fix this problem:

• Store (more?) of the database in memory. How big is the database?
• Have separate options (that you can set in the bitcoin options in the GUI) for location of the database vs the raw blockchain
• Organize data on-disk so that single large sequential reads can gather multiple (hundreds) of the pieces of data needed for validation all at once and then run through them sequentially from memory.

Honestly I'm surprised these sorts of optimizations aren't already done. Should I create a new issue for these optimizations? Who can comment on which of these would actually help performance or what other optimizations would be critical for this kind of issue?

Its gonna start getting a ton more important to optimize this for external HD usage as the blockchain grows. Top of the line laptops still come with a baseline 256GB SSDs, and a 120GB blockchain is already straining the space on those things (+ OS and programs and games). And some people don't have top of the line laptops..

It looks like everything that doesn't include the blocks directry inside the data directory is less than 3GB for me. So why isn't my bitcoin core using more than 300MB of memory? It should be storing some of that db in there right?

Store (more?) of the database in memory.

So why isn't my bitcoin core using more than 300MB of memory? It should be storing some of that db in there right?

That's controlled by -dbcache, but only the pieces that are actually used - they still get loaded only when needed. Plus it reserves some of the dbcache for the time when flushes happen, to prevent briefly spike and make you run out of memory. This slack space is significantly reduced in 0.15; you're free to try master if you want to see if it improves things.

The database is stored in a special compact format on disk. When loaded into memory it's done an quickly-accessible way that is several times larger than the disk version. Loading the whole thing in memory needs around 8 GB.

There could perhaps be an option to load the whole database into memory at startup to speed things up later if you actually have that much dbcache configured.... but if not, you're still stuck with loading the bits and pieces as they are used, and slow disks will keep slowing you down.

Have separate options (that you can set in the bitcoin options in the GUI) for location of the database vs the raw blockchain

Yes, this would be possible.

Organize data on-disk so that single large sequential reads can gather multiple (hundreds) of the pieces of data needed for validation all at once and then run through them sequentially from memory.

We can't predict what pieces will be needed. They're organized by the txids of what inputs are spent from, and thus inherently randomly distributed.

We can't predict what pieces will be needed. They're organized by the txids of what inputs are spent from, and thus inherently randomly distributed.

I don't understand enough about what order the data needs to be accessed in, but why is it sorted by txid? Would it be possible to sort it by something more useful to blockchain validation?

Ok, so I attempted to symlink the blocks directory from my SSD to my external HD (which are both using NTFS). I copied the data directory (minus the blocks directory) to my SSD, cd'd in there and did:

mklink /D blocks H:\Bitcoin\blocks

I can confirm that its moving about 6 times as fast now. Where it was telling me 3 days til I'm synced, now its saying 12 hours. So a huge speed up! Not as much of a speed up as I had hoped, but the client is now using over 650MB of memory and 5-6 Mbps of network bandwidth (that last being relatively consistent with the 4x speedup). Also, the client starts up a ton faster (not a lot of waiting at "Done loading" anymore).

So thanks @sipa for helping me figure this out! Anything else I might be able to do to make it go any faster?

@fresheneesz Every transaction has a number of inputs, which refer to previous transaction outputs. Whenever a transaction is being validated, we need to look up the outputs being spent to figure out (1) whether they aren't spent already (2) which address/script they were sent to to verify the signature against and (3) to determine whether input and output amounts balance. There are over 50 million unspent outputs, and they all need to be individually addressable by the txid they were created it, because that's how they're referred to in inputs. As we don't know which outputs will be spent in future transaction, there is nothing better to index them by.

I think this issue can be closed, as the whole way of doing caching is significantly rewritten in 0.15.

@sipa Hmm ok.

So the fact that my problem has been solved (with significant effort and workarounds) doesn't solve the problem for the project. Maybe 0.15 means I would have never had this problem in the first place, but I'm not convinced. Since I solved this problem by separating the database from the blockchain storage, why don't I create an issue for making a clear way (via the GUI) to allow the user to separate those out on different drives?

@fresheneesz Feel free to open a wishlist item to separate the chainstate location from block storage.

However, neither of the things currently listed in this issue are what I consider bugs (it being slow on slow disks is inevitable, and I haven't seen evidence that the -dbcache value does not affect the cache size).

it being slow on slow disks is inevitable

Bug or not, its a major usability flaw if the user isn't informed via the interface about critical performance decisions they have to make. And this is especially true when the GUI doesn't even support options that would allow users to easily optimize the client. So I'll close this and open up a wishlist item. Thanks for all your help!

Bug or not, its a major usability flaw if the user isn't informed via the interface about critical performance decisions they have to make. And this is especially true when the GUI doesn't even support options that would allow users to easily optimize the client.

I agree with all of that.

As for how to move the database without moving blocks: In Linux, you can use a symlink to another directory for the $DATADIR/blocks directory. There is something similar in Windows, but I don't know the details.

In case anyone finds this in the future, I used this guide to sync a node with the blocks on an external hard drive and the database on an internal hard drive on Windows, which fixed the problem and drastically improved my initial sync time. Running -debug=bench, the connect block time (which is the same bottleneck the user above had) reduced from around 21000ms to about 700-800ms.

Thank you @fresheneesz for posting the issue, @sipa for the explanation and advice, everyone else on the issue and to actuallytwolamas on bitcointalk for the guide. Cheers