bitcoin / bitcoin

Bitcoin Core integration/staging tree
https://bitcoincore.org/en/download
MIT License
78.75k stars 36.23k forks source link

assumeutxo: not syncing the snapshot chainstate #30971

Open fanquake opened 1 week ago

fanquake commented 1 week ago

Testing -loadtxoutset on node running master (39219fe145e5), with Sjors snapshot (height 840000). After it finished validating the snapshot, it (so far), has just not started syncing the snapshot chain, only the background chain is progressing. It also seems like the cache resizing has not worked correctly?

./build/src/bitcoind
2024-09-25T15:53:23Z Bitcoin Core version v28.99.0-39219fe145e5 (release build)
2024-09-25T15:53:23Z Script verification uses 9 additional threads
2024-09-25T15:53:23Z Using the 'arm_shani(1way,2way)' SHA256 implementation
2024-09-25T15:53:23Z Default data directory xxx/Library/Application Support/Bitcoin
2024-09-25T15:53:23Z Using data directory xxx/Library/Application Support/Bitcoin
2024-09-25T15:53:23Z Config file: xxx/Library/Application Support/Bitcoin/bitcoin.conf (not found, skipping)
2024-09-25T15:53:23Z Using at most 125 automatic connections (285 file descriptors available)
2024-09-25T15:53:23Z scheduler thread start
2024-09-25T15:53:23Z Binding RPC on address ::1 port 8332
2024-09-25T15:53:23Z Binding RPC on address 127.0.0.1 port 8332
2024-09-25T15:53:23Z Using random cookie authentication.
2024-09-25T15:53:23Z Generated RPC authentication cookie xxx/Library/Application Support/Bitcoin/.cookie
2024-09-25T15:53:23Z Permissions used for cookie: rw-------
2024-09-25T15:53:23Z Starting HTTP server with 4 worker threads
2024-09-25T15:53:23Z Using wallet directory xxx/Library/Application Support/Bitcoin
2024-09-25T15:53:23Z init message: Verifying wallet(s)…
2024-09-25T15:53:23Z Using /16 prefix for IP bucketing
2024-09-25T15:53:23Z init message: Loading P2P addresses…
2024-09-25T15:53:23Z Loaded 17302 addresses from peers.dat  18ms
2024-09-25T15:53:23Z init message: Loading banlist…
2024-09-25T15:53:23Z SetNetworkActive: true
2024-09-25T15:53:23Z Script verification uses 9 additional threads
2024-09-25T15:53:23Z Cache configuration:
2024-09-25T15:53:23Z * Using 2.0 MiB for block index database
2024-09-25T15:53:23Z * Using 8.0 MiB for chain state database
2024-09-25T15:53:23Z * Using 440.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space)
2024-09-25T15:53:23Z Using obfuscation key for blocksdir *.dat files (xxx/Library/Application Support/Bitcoin/blocks): '127ac22335625780'
2024-09-25T15:53:23Z Using 16 MiB out of 16 MiB requested for signature cache, able to store 524288 elements
2024-09-25T15:53:23Z Using 16 MiB out of 16 MiB requested for script execution cache, able to store 524288 elements
2024-09-25T15:53:23Z init message: Loading block index…
2024-09-25T15:53:23Z Assuming ancestors of block 000000000000000000011c5890365bdbe5d25b97ce0057589acaef4f1a57263f have valid signatures.
2024-09-25T15:53:23Z Setting nMinimumChainWork=000000000000000000000000000000000000000088e186b70e0862c193ec44d6
2024-09-25T15:53:23Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/blocks/index
2024-09-25T15:53:23Z Opened LevelDB successfully
2024-09-25T15:53:23Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/blocks/index: 0000000000000000
2024-09-25T15:53:25Z LoadBlockIndexDB: last block file = 75
2024-09-25T15:53:25Z LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=49, size=74710965, heights=843763...843815, time=2024-05-16...2024-05-17)
2024-09-25T15:53:25Z Checking all blk files are present...
2024-09-25T15:53:25Z Initializing chainstate Chainstate [ibd] @ height -1 (null)
2024-09-25T15:53:25Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate
2024-09-25T15:53:26Z Opened LevelDB successfully
2024-09-25T15:53:26Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate: 79defe88c10839b8
2024-09-25T15:53:26Z Loaded best chain: hashBestChain=000000000000096051e4f2756ca5e322beb73cf21c7abaee6c584319c00cad73 height=137460 date=2011-07-22T08:34:27Z progress=0.001016
2024-09-25T15:53:26Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate
2024-09-25T15:53:26Z Opened LevelDB successfully
2024-09-25T15:53:26Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate: 79defe88c10839b8
2024-09-25T15:53:26Z [Chainstate [ibd] @ height 137460 (000000000000096051e4f2756ca5e322beb73cf21c7abaee6c584319c00cad73)] resized coinsdb cache to 8.0 MiB
2024-09-25T15:53:26Z [Chainstate [ibd] @ height 137460 (000000000000096051e4f2756ca5e322beb73cf21c7abaee6c584319c00cad73)] resized coinstip cache to 440.0 MiB
2024-09-25T15:53:26Z init message: Verifying blocks…
2024-09-25T15:53:26Z Verifying last 6 blocks at level 3
2024-09-25T15:53:26Z Verification progress: 0%
2024-09-25T15:53:26Z Verification progress: 16%
2024-09-25T15:53:26Z Verification progress: 33%
2024-09-25T15:53:26Z Verification progress: 50%
2024-09-25T15:53:26Z Verification progress: 66%
2024-09-25T15:53:26Z Verification progress: 83%
2024-09-25T15:53:26Z Verification progress: 99%
2024-09-25T15:53:26Z Verification: No coin database inconsistencies in last 6 blocks (728 transactions)
2024-09-25T15:53:26Z  block index            2319ms
2024-09-25T15:53:26Z Setting NODE_NETWORK on non-prune mode
2024-09-25T15:53:26Z block tree size = 862827
2024-09-25T15:53:26Z nBestHeight = 137460
2024-09-25T15:53:26Z initload thread start
2024-09-25T15:53:26Z torcontrol thread start
2024-09-25T15:53:26Z Bound to 127.0.0.1:8334
2024-09-25T15:53:26Z Bound to [::]:8333
2024-09-25T15:53:26Z Bound to 0.0.0.0:8333
2024-09-25T15:53:26Z Loaded 0 addresses from "anchors.dat"
2024-09-25T15:53:26Z 0 block-relay-only anchors will be tried for connections.
2024-09-25T15:53:26Z init message: Starting network threads…
2024-09-25T15:53:26Z net thread start
2024-09-25T15:53:26Z opencon thread start
2024-09-25T15:53:26Z init message: Done loading
2024-09-25T15:53:26Z addcon thread start
2024-09-25T15:53:26Z dnsseed thread start
2024-09-25T15:53:26Z msghand thread start
2024-09-25T15:53:26Z Waiting 300 seconds before querying DNS seeds.
2024-09-25T15:53:26Z UpdateTip: new best=00000000000000609b06e85fdafab41835959e3c8c1143ce27fff626701c1113 height=137461 version=0x00000001 log2_work=65.540856 tx=1101365 date='2011-07-22T08:34:49Z' progress=0.001016 cache=0.3MiB(121txo)
2024-09-25T15:53:26Z UpdateTip: new best=00000000000008ce750f95de4ab31625e351a389c3eb4a8ff89c2f237dc9bca7 height=137462 version=0x00000001 log2_work=65.541051 tx=1101403 date='2011-07-22T09:03:30Z' progress=0.001016 cache=0.3MiB(623txo)
2024-09-25T15:53:26Z UpdateTip: new best=000000000000035f0e005175e84590f7d1f58d35c69312324753b2402edb92f2 height=137463 version=0x00000001 log2_work=65.541246 tx=1101516 date='2011-07-22T09:04:30Z' progress=0.001016 cache=0.3MiB(1042txo)
2024-09-25T15:53:26Z UpdateTip: new best=000000000000063555c43b8de63993da329f1e826b07153fa87e9eae050d0e19 height=137464 version=0x00000001 log2_work=65.541441 tx=1101630 date='2011-07-22T09:07:42Z' progress=0.001017 cache=0.3MiB(1217txo)
2024-09-25T15:53:26Z UpdateTip: new best=000000000000097137c042f03e2da5e7c78f2c24eb989aff9360d0e421156ed8 height=137465 version=0x00000001 log2_work=65.541637 tx=1101698 date='2011-07-22T09:22:47Z' progress=0.001017 cache=0.3MiB(1493txo)
2024-09-25T15:53:26Z UpdateTip: new best=000000000000048f329ea57f07805dbc2526f37043cd066d4c1eb0894eef0cfe height=137466 version=0x00000001 log2_work=65.541832 tx=1101714 date='2011-07-22T09:24:12Z' progress=0.001017 cache=0.3MiB(1513txo)
<snip>
2024-09-25T15:53:56Z UpdateTip: new best=00000000000008eca958f405fff3aa956000f1b355f9576f0343d0604cde3df9 height=187138 version=0x00000001 log2_work=68.339181 tx=4627181 date='2012-07-02T05:22:12Z' progress=0.004270 cache=211.1MiB(1622619txo)
2024-09-25T15:53:56Z UpdateTip: new best=0000000000000486fb041456433d90fec75b5fbc284babcab882b2842e76c2c9 height=187139 version=0x00000001 log2_work=68.339210 tx=4627262 date='2012-07-02T05:24:19Z' progress=0.004270 cache=211.1MiB(1622630txo)
2024-09-25T15:53:56Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate
2024-09-25T15:53:56Z Opened LevelDB successfully
2024-09-25T15:53:56Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate: 79defe88c10839b8
2024-09-25T15:53:56Z [Chainstate [ibd] @ height 187139 (0000000000000486fb041456433d90fec75b5fbc284babcab882b2842e76c2c9)] resized coinsdb cache to 0.1 MiB
2024-09-25T15:53:56Z [Chainstate [ibd] @ height 187139 (0000000000000486fb041456433d90fec75b5fbc284babcab882b2842e76c2c9)] resized coinstip cache to 4.4 MiB
2024-09-25T15:53:57Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate_snapshot
2024-09-25T15:53:57Z Opened LevelDB successfully
2024-09-25T15:53:57Z Wrote new obfuscate key for xxx/Library/Application Support/Bitcoin/chainstate_snapshot: 3cedc53d26d5e869
2024-09-25T15:53:57Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate_snapshot: 3cedc53d26d5e869
2024-09-25T15:53:57Z [snapshot] loading 176948713 coins from snapshot 0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5
2024-09-25T15:53:57Z UpdateTip: new best=000000000000057d242bd6e5cce860ee7c71393f045f28b6cf1e42b01c9bef07 height=187140 version=0x00000001 log2_work=68.339238 tx=4627488 date='2012-07-02T05:42:16Z' progress=0.004270 cache=0.3MiB(879txo)
2024-09-25T15:53:57Z UpdateTip: new best=000000000000073b59cf746291c9f054dcf2f30950c9eeed17b35d052a3394e6 height=187141 version=0x00000001 log2_work=68.339267 tx=4627616 date='2012-07-02T05:57:32Z' progress=0.004270 cache=0.3MiB(1222txo)
2024-09-25T15:53:57Z UpdateTip: new best=000000000000069a34483541b43e8cac54fd2a4eb8689769962d1663bb3a70b3 height=187142 version=0x00000001 log2_work=68.339296 tx=4627628 date='2012-07-02T06:10:08Z' progress=0.004270 cache=0.3MiB(1258txo)
2024-09-25T15:53:57Z UpdateTip: new best=0000000000000719f4d8baa3baa639cc284bd26b956c5e46d5a214433b60656f height=187143 version=0x00000001 log2_work=68.339324 tx=4628056 date='2012-07-02T06:38:07Z' progress=0.004271 cache=0.5MiB(2062txo)
<snip>
2024-09-25T15:54:00Z UpdateTip: new best=00000000000006fcfb1ac89d21f638407b5740c93b4885fb1a5960bea81a0607 height=188377 version=0x00000001 log2_work=68.374612 tx=4818578 date='2012-07-10T05:15:31Z' progress=0.004446 cache=23.1MiB(174283txo)
2024-09-25T15:54:00Z UpdateTip: new best=000000000000015756b4cd10b7833c53797593c20af9c8fe0cb2590f22c5894b height=188378 version=0x00000001 log2_work=68.374640 tx=4818610 date='2012-07-10T05:23:58Z' progress=0.004446 cache=23.1MiB(174309txo)
2024-09-25T15:54:00Z UpdateTip: new best=0000000000000122c7d4552cf8d3e7aa235c7ddc4a15b059acb73b5430c5b079 height=188379 version=0x00000001 log2_work=68.374669 tx=4818777 date='2012-07-10T05:27:51Z' progress=0.004447 cache=23.1MiB(174425txo)
2024-09-25T15:54:00Z [snapshot] 1000000 coins loaded (0.57%, 158 MB)
2024-09-25T15:54:00Z UpdateTip: new best=000000000000000d16b34a8b89a686f9038f748ac9728f8c7643a831793c2040 height=188380 version=0x00000001 log2_work=68.374697 tx=4819497 date='2012-07-10T05:50:19Z' progress=0.004447 cache=23.1MiB(174847txo)
2024-09-25T15:54:00Z UpdateTip: new best=000000000000054fd6b4453d7d622da98f887d3733f60041aabd0e01c9846d52 height=188381 version=0x00000001 log2_work=68.374725 tx=4819711 date='2012-07-10T05:39:17Z' progress=0.004447 cache=23.1MiB(175165txo)
2024-09-25T15:54:00Z UpdateTip: new best=00000000000003d8190e06edd2a573f6d10c9beffad530072a4e7c8904fe4ddd height=188382 version=0x00000001 log2_work=68.374754 tx=4819743 date='2012-07-10T06:10:43Z' progress=0.004447 cache=23.1MiB(175211txo)
<snip>
2024-09-25T16:05:57Z UpdateTip: new best=0000000000000004df1cbc9b13485e2878817457fbd57820136db8f182dbb5b7 height=271605 version=0x00000002 log2_work=74.240837 tx=27877081 date='2013-11-26T12:30:48Z' progress=0.025724 cache=233.0MiB(1700579txo)
2024-09-25T16:05:57Z [snapshot] 175000000 coins loaded (98.90%, 159 MB)
2024-09-25T16:05:57Z UpdateTip: new best=000000000000000296a638b75ebfaa712b2b2bc891b2793ace65cbad049c56f6 height=271606 version=0x00000002 log2_work=74.241006 tx=27877750 date='2013-11-26T12:42:31Z' progress=0.025724 cache=233.0MiB(1701016txo)
<snip>
2024-09-25T16:05:58Z UpdateTip: new best=00000000000000014397cfcb1320dc18091f8a970ba28c512a2e6e5821725490 height=271710 version=0x00000002 log2_work=74.258493 tx=27939164 date='2013-11-27T04:29:36Z' progress=0.025781 cache=238.5MiB(1745907txo)
2024-09-25T16:05:58Z UpdateTip: new best=00000000000000051de730ce205ed6bb14b485555f686138a74ecde15cf82b87 height=271711 version=0x00000002 log2_work=74.258660 tx=27939411 date='2013-11-27T04:31:26Z' progress=0.025781 cache=238.5MiB(1746176txo)
2024-09-25T16:05:59Z [snapshot] 176000000 coins loaded (99.46%, 317 MB)
2024-09-25T16:05:59Z UpdateTip: new best=0000000000000005f9149afa5050d1558aba8a01174c0802462e980d0512c3e1 height=271712 version=0x00000002 log2_work=74.258828 tx=27939820 date='2013-11-27T04:40:16Z' progress=0.025781 cache=238.5MiB(1746431txo)
2024-09-25T16:05:59Z UpdateTip: new best=0000000000000006413b34873c70dd3ea9e182e41696cf4edc21b614469789be height=271713 version=0x00000002 log2_work=74.258995 tx=27940097 date='2013-11-27T04:44:30Z' progress=0.025782 cache=238.5MiB(1746586txo)
2024-09-25T16:05:59Z UpdateTip: new best=0000000000000000c1912eb6bb766f9e92aa3e48da24d4c83f15605a3abb3698 height=271714 version=0x00000002 log2_work=74.259162 tx=27940235 date='2013-11-27T04:48:35Z' progress=0.025782 cache=238.5MiB(1746683txo)
2024-09-25T16:05:59Z UpdateTip: new best=000000000000000141dad40b79bea2ec0e94cec6539fe14012e881b3817e4863 height=271715 version=0x00000002 log2_work=74.259329 tx=27940481 date='2013-11-27T05:07:21Z' progress=0.025782 cache=238.7MiB(1746888txo)
2024-09-25T16:05:59Z [snapshot] loaded 176948713 (455 MB) coins from snapshot 0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5
2024-09-25T16:05:59Z FlushSnapshotToDisk: saving snapshot chainstate (455 MB) started
2024-09-25T16:05:59Z UpdateTip: new best=0000000000000001419a7e1585ecbeb2b69b77ec39f7408d8a9abc7606644b3e height=271716 version=0x00000002 log2_work=74.259496 tx=27941253 date='2013-11-27T05:04:26Z' progress=0.025783 cache=238.7MiB(1747255txo)
2024-09-25T16:05:59Z UpdateTip: new best=0000000000000003b9769b216adaabbdc2077a88f7b5044e5630bd955e91f5b4 height=271717 version=0x00000002 log2_work=74.259663 tx=27941454 date='2013-11-27T05:07:19Z' progress=0.025783 cache=238.7MiB(1747471txo)
<snip>
2024-09-25T16:08:31Z UpdateTip: new best=000000000000000170298e49f1f024516ef3ed52dcd58320f1cf0276f8e92ce0 height=285171 version=0x00000002 log2_work=76.475756 tx=32663594 date='2014-02-10T23:15:05Z' progress=0.030140 cache=81.9MiB(617074txo)
2024-09-25T16:08:31Z UpdateTip: new best=0000000000000000d697fe89a7c48fe025cfe64808511d3917d5a5463a75dc47 height=285172 version=0x00000002 log2_work=76.475911 tx=32663997 date='2014-02-10T23:28:25Z' progress=0.030141 cache=81.9MiB(617535txo)
2024-09-25T16:08:31Z UpdateTip: new best=00000000000000003f7d69d948ff4dfdd284f1ecec9e50e3c0339965d73c2d46 height=285173 version=0x00000002 log2_work=76.476065 tx=32664060 date='2014-02-10T23:27:13Z' progress=0.030141 cache=81.9MiB(617442txo)
2024-09-25T16:08:33Z [snapshot] validated snapshot (0 MB)
2024-09-25T16:08:33Z [snapshot] successfully activated snapshot 0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5
2024-09-25T16:08:33Z [snapshot] (0 MB)
2024-09-25T16:08:33Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate
2024-09-25T16:08:34Z Opened LevelDB successfully
2024-09-25T16:08:34Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate: 79defe88c10839b8
2024-09-25T16:08:34Z [Chainstate [ibd] @ height 285173 (00000000000000003f7d69d948ff4dfdd284f1ecec9e50e3c0339965d73c2d46)] resized coinsdb cache to 0.4 MiB
2024-09-25T16:08:34Z [Chainstate [ibd] @ height 285173 (00000000000000003f7d69d948ff4dfdd284f1ecec9e50e3c0339965d73c2d46)] resized coinstip cache to 22.0 MiB
2024-09-25T16:08:34Z Cache size (85866560) exceeds total space (23068672)
2024-09-25T16:08:36Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate_snapshot
2024-09-25T16:08:36Z Opened LevelDB successfully
2024-09-25T16:08:36Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate_snapshot: d5cf473cf236f9ee
2024-09-25T16:08:36Z [Chainstate [snapshot] @ height 840000 (0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5)] resized coinsdb cache to 7.6 MiB
2024-09-25T16:08:36Z [Chainstate [snapshot] @ height 840000 (0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5)] resized coinstip cache to 418.0 MiB
2024-09-25T16:08:40Z Cache size (23169840) exceeds total space (23068672)
2024-09-25T16:08:42Z Cache size (23156368) exceeds total space (23068672)
2024-09-25T16:08:44Z Cache size (23166512) exceeds total space (23068672)
2024-09-25T16:08:47Z [background validation] UpdateTip: new best=00000000000000004388ae444347bde423f2f3aa6ef335b50909f5bc27d31ea3 height=286000 version=0x00000002 log2_work=76.598535 tx=32972570 date='2014-02-15T14:40:58Z' progress=0.030425 cache=20.1MiB(149927txo)
2024-09-25T16:08:47Z Cache size (23181520) exceeds total space (23068672)
2024-09-25T16:08:50Z Cache size (23164240) exceeds total space (23068672)
2024-09-25T16:09:15Z Cache size (23160688) exceeds total space (23068672)
2024-09-25T16:09:17Z Cache size (23163600) exceeds total space (23068672)
2024-09-25T16:09:20Z Cache size (23155824) exceeds total space (23068672)
2024-09-25T16:09:22Z Cache size (23161872) exceeds total space (23068672)
2024-09-25T16:09:24Z [background validation] UpdateTip: new best=00000000000000003c395f08779c3ac1301488b8a18c0999c008129a55610785 height=288000 version=0x00000002 log2_work=76.896966 tx=33738512 date='2014-02-26T23:51:53Z' progress=0.031132 cache=19.8MiB(148059txo)
2024-09-25T16:09:42Z Cache size (23160112) exceeds total space (23068672)
2024-09-25T16:09:44Z Cache size (23415536) exceeds total space (23068672)
2024-09-25T16:09:47Z Cache size (23151600) exceeds total space (23068672)
2024-09-25T16:09:48Z Cache size (23152048) exceeds total space (23068672)
2024-09-25T16:09:50Z Cache size (23151344) exceeds total space (23068672)
2024-09-25T16:10:00Z Cache size (23423760) exceeds total space (23068672)
2024-09-25T16:10:05Z [background validation] UpdateTip: new best=0000000000000000fa0b2badd05db0178623ebf8dd081fe7eb874c26e27d0b3b height=290000 version=0x00000002 log2_work=77.192040 tx=34604254 date='2014-03-11T08:27:57Z' progress=0.031931 cache=16.6MiB(121464txo)
2024-09-25T16:10:06Z Cache size (23160048) exceeds total space (23068672)
2024-09-25T16:10:07Z Cache size (23155088) exceeds total space (23068672)
2024-09-25T16:10:09Z Cache size (23161008) exceeds total space (23068672)
2024-09-25T16:10:12Z Cache size (23162864) exceeds total space (23068672)
2024-09-25T16:10:16Z Cache size (23154384) exceeds total space (23068672)
2024-09-25T16:10:25Z Cache size (23156432) exceeds total space (23068672)
2024-09-25T16:10:27Z Cache size (23162096) exceeds total space (23068672)
2024-09-25T16:10:28Z Cache size (23161744) exceeds total space (23068672)
2024-09-25T16:10:30Z [background validation] UpdateTip: new best=0000000000000000620671231acb6a68134a0396235dcb0e53f4fc82bbaa1184 height=292000 version=0x00000002 log2_work=77.464916 tx=35415929 date='2014-03-23T07:21:11Z' progress=0.032680 cache=6.4MiB(48002txo)
2024-09-25T16:10:32Z Cache size (23154704) exceeds total space (23068672)
2024-09-25T16:10:48Z Cache size (23156080) exceeds total space (23068672)
2024-09-25T16:10:50Z Cache size (23173072) exceeds total space (23068672)
2024-09-25T16:10:52Z Cache size (23677776) exceeds total space (23068672)
2024-09-25T16:10:53Z Cache size (23154992) exceeds total space (23068672)
2024-09-25T16:10:55Z Cache size (23155152) exceeds total space (23068672)
2024-09-25T16:10:58Z Cache size (23150544) exceeds total space (23068672)
2024-09-25T16:11:00Z [background validation] UpdateTip: new best=0000000000000000cb2540b3f00ce422887904c75b24bf75b8a73817302a4138 height=294000 version=0x00000002 log2_work=77.729434 tx=36160308 date='2014-04-03T17:19:15Z' progress=0.033367 cache=18.1MiB(134561txo)
2024-09-25T16:11:23Z Cache size (23164752) exceeds total space (23068672)
2024-09-25T16:11:26Z Cache size (23438928) exceeds total space (23068672)
2024-09-25T16:11:27Z Cache size (23167952) exceeds total space (23068672)
2024-09-25T16:11:31Z [background validation] UpdateTip: new best=00000000000000009570102278e59ecf045c16ec8c8a5ea85bf823d0ec72e3d0 height=296000 version=0x00000002 log2_work=77.996579 tx=36895009 date='2014-04-15T14:15:39Z' progress=0.034045 cache=11.5MiB(86994txo)
2024-09-25T16:11:43Z Cache size (23207760) exceeds total space (23068672)
2024-09-25T16:11:45Z Cache size (23243376) exceeds total space (23068672)
2024-09-25T16:11:46Z Cache size (23188048) exceeds total space (23068672)
2024-09-25T16:11:50Z Cache size (23216176) exceeds total space (23068672)
2024-09-25T16:12:03Z Cache size (23177456) exceeds total space (23068672)
2024-09-25T16:12:03Z [background validation] UpdateTip: new best=000000000000000047d2f2eb7278e3f4aded9acaf502f5ec27bab5018b5871f2 height=298000 version=0x00000002 log2_work=78.253021 tx=37661919 date='2014-04-27T17:02:15Z' progress=0.034752 cache=14.6MiB(104480txo)
2024-09-25T16:12:04Z Cache size (23165104) exceeds total space (23068672)
2024-09-25T16:12:07Z Cache size (23172304) exceeds total space (23068672)
2024-09-25T16:12:26Z Cache size (23170896) exceeds total space (23068672)
2024-09-25T16:12:28Z Cache size (23168688) exceeds total space (23068672)
2024-09-25T16:12:30Z Cache size (23170496) exceeds total space (23068672)
2024-09-25T16:12:32Z Cache size (23176176) exceeds total space (23068672)
2024-09-25T16:12:35Z [background validation] UpdateTip: new best=000000000000000082ccf8f1557c5d40b21edabb18d2d691cfbf87118bac7254 height=300000 version=0x00000002 log2_work=78.499549 tx=38463789 date='2014-05-10T06:32:34Z' progress=0.035492 cache=12.1MiB(91917txo)
2024-09-25T16:12:52Z Cache size (23165008) exceeds total space (23068672)
<snip>
2024-09-25T16:28:58Z Cache size (23544688) exceeds total space (23068672)
2024-09-25T16:28:59Z Cache size (23198576) exceeds total space (23068672)
2024-09-25T16:29:00Z Cache size (23212368) exceeds total space (23068672)
2024-09-25T16:29:01Z [background validation] UpdateTip: new best=0000000000000000053cf64f0400bb38e0c4b3872c38795ddde27acb40a112bb height=350000 version=0x00000002 log2_work=82.531372 tx=63960713 date='2015-03-30T22:17:14Z' progress=0.059019 cache=12.5MiB(94440txo)
2024-09-25T16:29:02Z Cache size (23168560) exceeds total space (23068672)
2024-09-25T16:29:03Z Cache size (23210064) exceeds total space (23068672)
2024-09-25T16:29:04Z Cache size (23174928) exceeds total space (23068672)
2024-09-25T16:29:10Z Cache size (23275184) exceeds total space (23068672)
2024-09-25T16:29:11Z Cache size (23146608) exceeds total space (23068672)
2024-09-25T16:29:26Z Cache size (24775952) exceeds total space (23068672)
2024-09-25T16:29:27Z Cache size (23214064) exceeds total space (23068672)
2024-09-25T16:29:28Z Cache size (23868208) exceeds total space (23068672)

./build/src/bitcoin-cli getchainstates

{
  "headers": 862832,
  "chainstates": [
    {
      "blocks": 352312,
      "bestblockhash": "000000000000000013825ce8db8e39a5daac8969a8d676eff2596cfe60d4bbeb",
      "difficulty": 49446390688.24144,
      "verificationprogress": 0.06061623266278565,
      "coins_db_cache_bytes": 419430,
      "coins_tip_cache_bytes": 23068672,
      "validated": true
    },
    {
      "blocks": 840000,
      "bestblockhash": "0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5",
      "difficulty": 86388558925171.02,
      "verificationprogress": 0.9144655729611229,
      "coins_db_cache_bytes": 7969177,
      "coins_tip_cache_bytes": 438304768,
      "snapshot_blockhash": "0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5",
      "validated": false
    }
  ]
}
mzumsande commented 1 week ago

That's strange. I just tried to reproduce syncing this snapshot with current master (39219fe145e5e6e6f079b591e3f4b5fea8e71804) and didn't experience this (although I do get get similar "Cache size" log messages).

Are you syncing from random peers or do you have some local setup?

pablomartin4btc commented 1 week ago

@fanquake what getchaintips returns?

fanquake commented 1 week ago

Are you syncing from random peers or do you have some local setup?

This was syncing from random peers.

maflcko commented 1 week ago

Are all random peers limited peers, which wouldn't serve historic blocks?

fanquake commented 1 week ago

Are all random peers limited peers,

I don't think so, given some peers would have to be serving (historic) blocks for the background chain to continue syncing? I've now restarted this node, and the behaviour hasn't persisted, both chains are currently syncing. If this gets to the point that the snapshot load completes, I'll close this.

mzumsande commented 1 week ago

It also seems like the cache resizing has not worked correctly?

Just wanted to mention that I think that the cache resize worked as expected here: After the snaphot is loaded, the cache of the background chainstate is set to a lower value: resized coinstip cache to 22.0 MiB because loading from the snapshot chainstate is prioritized.

Then, the cache for the background chainstate is frequently flushed because blocks are downloaded to it and it runs full quickly. These are the Cache size (23160048) exceeds total space (23068672) messages.

So the problem is only that no progress is made towards the snapshot chain, with the larger cache, for an unknown reason (which I still couldn't replicate in multiple runs), but not the cache resizing.

fjahr commented 4 days ago

If this gets to the point that the snapshot load completes, I'll close this.

I don't think we have to close this right away, we can keep this open for a few more weeks to see if this issue occurs for other users. Having an open issue already makes it easier for people to engage. But did loading of the snapshot actually complete eventually @fanquake ?

I am currently looking into the obfuscation key because I find it suspicious that it changes for chainstate_snapshot. From my understanding that shouldn't happen. Note below how @fanquake 's obfuscation key changes from 3cedc53d26d5e869 to d5cf473cf236f9ee while mine stays at a92b5f447f34b873. So far I couldn't figure what caused this though. @fanquake could you share the full logs for the whole sync so I can track down further differences that might give a hint for changes (privately if you prefer). For example, I am curious if there were any abnormal interactions with the snaphot chainstate.

FYI, comparison between my test run and @fanquake 's log excerpts:

fanquake Start ``` 2024-09-25T15:53:56Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate 2024-09-25T15:53:56Z Opened LevelDB successfully 2024-09-25T15:53:56Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate: 79defe88c10839b8 2024-09-25T15:53:56Z [Chainstate [ibd] @ height 187139 (0000000000000486fb041456433d90fec75b5fbc284babcab882b2842e76c2c9)] resized coinsdb cache to 0.1 MiB 2024-09-25T15:53:56Z [Chainstate [ibd] @ height 187139 (0000000000000486fb041456433d90fec75b5fbc284babcab882b2842e76c2c9)] resized coinstip cache to 4.4 MiB 2024-09-25T15:53:57Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate_snapshot 2024-09-25T15:53:57Z Opened LevelDB successfully 2024-09-25T15:53:57Z Wrote new obfuscate key for xxx/Library/Application Support/Bitcoin/chainstate_snapshot: 3cedc53d26d5e869 2024-09-25T15:53:57Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate_snapshot: 3cedc53d26d5e869 2024-09-25T15:53:57Z [snapshot] loading 176948713 coins from snapshot 0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5 ``` Finish ``` 2024-09-25T16:08:33Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate 2024-09-25T16:08:34Z Opened LevelDB successfully 2024-09-25T16:08:34Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate: 79defe88c10839b8 2024-09-25T16:08:34Z [Chainstate [ibd] @ height 285173 (00000000000000003f7d69d948ff4dfdd284f1ecec9e50e3c0339965d73c2d46)] resized coinsdb cache to 0.4 MiB 2024-09-25T16:08:34Z [Chainstate [ibd] @ height 285173 (00000000000000003f7d69d948ff4dfdd284f1ecec9e50e3c0339965d73c2d46)] resized coinstip cache to 22.0 MiB 2024-09-25T16:08:34Z Cache size (85866560) exceeds total space (23068672) 2024-09-25T16:08:36Z Opening LevelDB in xxx/Library/Application Support/Bitcoin/chainstate_snapshot 2024-09-25T16:08:36Z Opened LevelDB successfully 2024-09-25T16:08:36Z Using obfuscation key for xxx/Library/Application Support/Bitcoin/chainstate_snapshot: d5cf473cf236f9ee ```
fjahr Start ``` 2024-10-04T20:06:33Z Opening LevelDB in XXX/test_datadir/chainstate 2024-10-04T20:06:33Z Opened LevelDB successfully 2024-10-04T20:06:33Z Using obfuscation key for XXX/test_datadir/chainstate: 82e29cc1b60af75f 2024-10-04T20:06:33Z [Chainstate [ibd] @ height 21251 (000000003b75b993230abd150a548b35f3e8edd681f9448da45e10a31652ce88)] resized coinsdb cache to 0.1 MiB 2024-10-04T20:06:33Z [Chainstate [ibd] @ height 21251 (000000003b75b993230abd150a548b35f3e8edd681f9448da45e10a31652ce88)] resized coinstip cache to 39.9 MiB 2024-10-04T20:06:35Z Opening LevelDB in XXX/test_datadir/chainstate_snapshot 2024-10-04T20:06:35Z Opened LevelDB successfully 2024-10-04T20:06:35Z Wrote new obfuscate key for XXX/test_datadir/chainstate_snapshot: a92b5f447f34b873 2024-10-04T20:06:35Z Using obfuscation key for XXX/test_datadir/chainstate_snapshot: a92b5f447f34b873 2024-10-04T20:06:35Z [snapshot] loading 176948713 coins from snapshot 0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5 ``` Finish ``` 2024-10-04T20:21:24Z [snapshot] validated snapshot (0 MB) 2024-10-04T20:21:24Z [snapshot] successfully activated snapshot 0000000000000000000320283a032748cef8227873ff4872689bf23f1cda83a5 2024-10-04T20:21:24Z [snapshot] (0 MB) 2024-10-04T20:21:24Z Opening LevelDB in XXX/test_datadir/chainstate 2024-10-04T20:21:24Z Opened LevelDB successfully 2024-10-04T20:21:24Z Using obfuscation key for XXX/test_datadir/chainstate: 82e29cc1b60af75f 2024-10-04T20:21:24Z [Chainstate [ibd] @ height 247064 (0000000000000040d4eb40a2979fa0344a7eba2a0b8eae998c74d41a4796aa1c)] resized coinsdb cache to 0.4 MiB 2024-10-04T20:21:24Z [Chainstate [ibd] @ height 247064 (0000000000000040d4eb40a2979fa0344a7eba2a0b8eae998c74d41a4796aa1c)] resized coinstip cache to 199.5 MiB 2024-10-04T20:21:25Z Opening LevelDB in XXX/test_datadir/chainstate_snapshot 2024-10-04T20:21:25Z Opened LevelDB successfully 2024-10-04T20:21:25Z Using obfuscation key for XXX/test_datadir/chainstate_snapshot: a92b5f447f34b873 ```
fanquake commented 2 days ago

But did loading of the snapshot actually complete eventually

It did. I haven't had time to (re-)test anything here further. I don't think I have the full logs to share any more, but I will try and recreate them.