Issue Details
- Number
- 29281
- Title
- Post startup stalling
- Description
- Noticed this on a node recently. Basically startup, sync two blocks, but then stall for 15 minutes, until we timed out a peer (in this case a blocks-only peer). @mzumsande mentioned this is because we were too close to tip, for the stalling logic to kick in, but also not close enough for the parallel download logic to kick in. I'm wondering if we should adjust the thresholds for either, to try and make this less likely to occur. It's possible this is also the same issue being seen here: https://github.com/bitcoin/bitcoin/issues/12291#issuecomment-1898517930.
```bash
2024-01-17T21:04:16.142907Z [init] Initializing chainstate Chainstate [ibd] @ height -1 (null)
2024-01-17T21:04:16.143281Z [init] Opening LevelDB in /Users/xxx/Library/Application Support/Bitcoin/chainstate
2024-01-17T21:04:17.980716Z [init] Opened LevelDB successfully
2024-01-17T21:04:17.981318Z [init] Using obfuscation key for /Users/xxx/Library/Application Support/Bitcoin/chainstate: 77d7aeef08b2778d
2024-01-17T21:04:18.522369Z [init] Loaded best chain: hashBestChain=00000000000000000000e21c52f32e7b4695ce0b8e8bb57e579b186d0c398dcf height=825926 date=2024-01-15T21:11:05Z progress=0.999002
2024-01-17T21:04:18.562453Z [init] Opening LevelDB in /Users/xxx/Library/Application Support/Bitcoin/chainstate
2024-01-17T21:04:18.696457Z [init] Opened LevelDB successfully
2024-01-17T21:04:18.696688Z [init] Using obfuscation key for /Users/xxx/Library/Application Support/Bitcoin/chainstate: 77d7aeef08b2778d
2024-01-17T21:04:18.696755Z [init] [Chainstate [ibd] @ height 825926 (00000000000000000000e21c52f32e7b4695ce0b8e8bb57e579b186d0c398dcf)] resized coinsdb cache to 8.0 MiB
2024-01-17T21:04:18.696797Z [init] [Chainstate [ibd] @ height 825926 (00000000000000000000e21c52f32e7b4695ce0b8e8bb57e579b186d0c398dcf)] resized coinstip cache to 384.0 MiB
2024-01-17T21:04:18.696894Z [init] init message: Verifying blocks…
2024-01-17T21:04:18.696973Z [init] Verifying last 6 blocks at level 3
2024-01-17T21:04:18.697061Z [init] Verification progress: 0%
2024-01-17T21:04:24.319192Z [init] Verification progress: 16%
2024-01-17T21:04:29.624412Z [init] Verification progress: 33%
2024-01-17T21:04:32.856466Z [init] Verification progress: 50%
2024-01-17T21:04:34.598393Z [init] Verification progress: 66%
2024-01-17T21:04:36.152079Z [init] Verification progress: 83%
2024-01-17T21:04:37.727802Z [init] Verification progress: 99%
2024-01-17T21:04:37.727970Z [init] Verification: No coin database inconsistencies in last 6 blocks (18844 transactions)
2024-01-17T21:04:37.777381Z [init] block index 57277ms
2024-01-17T21:04:37.785599Z [init] Opening LevelDB in /Users/xxx/Library/Application Support/Bitcoin/indexes/blockfilter/basic/db
2024-01-17T21:04:37.812648Z [init] Opened LevelDB successfully
2024-01-17T21:04:37.812778Z [init] Using obfuscation key for /Users/xxx/Library/Application Support/Bitcoin/indexes/blockfilter/basic/db: 0000000000000000
2024-01-17T21:04:37.813033Z [init] Opening LevelDB in /Users/xxx/Library/Application Support/Bitcoin/indexes/coinstats/db
2024-01-17T21:04:37.852950Z [init] Opened LevelDB successfully
2024-01-17T21:04:37.853086Z [init] Using obfuscation key for /Users/xxx/Library/Application Support/Bitcoin/indexes/coinstats/db: 0000000000000000
2024-01-17T21:04:37.930277Z [init] init message: Pruning blockstore…
2024-01-17T21:04:37.930708Z [init] block tree size = 825941
2024-01-17T21:04:37.930757Z [init] nBestHeight = 825926
2024-01-17T21:04:37.930832Z [initload] initload thread start
2024-01-17T21:04:37.931027Z [torcontrol] torcontrol thread start
2024-01-17T21:04:37.931121Z [coinstatsindex] coinstatsindex thread start
2024-01-17T21:04:37.931225Z [basic block filter index] basic block filter index thread start
2024-01-17T21:04:37.931332Z [coinstatsindex] coinstatsindex is enabled at height 825926
2024-01-17T21:04:37.931386Z [coinstatsindex] coinstatsindex thread exit
2024-01-17T21:04:37.931431Z [basic block filter index] basic block filter index is enabled at height 825926
2024-01-17T21:04:37.931493Z [basic block filter index] basic block filter index thread exit
2024-01-17T21:04:37.931545Z [init] Bound to 127.0.0.1:8334
2024-01-17T21:04:37.931692Z [init] Bound to [::]:8333
2024-01-17T21:04:37.931830Z [init] Bound to 0.0.0.0:8333
2024-01-17T21:04:37.933190Z [initload] Loading 19467 mempool transactions from disk...
2024-01-17T21:04:37.933335Z [init] Loaded 2 addresses from "anchors.dat"
2024-01-17T21:04:37.934342Z [init] 2 block-relay-only anchors will be tried for connections.
2024-01-17T21:04:37.934441Z [init] init message: Starting network threads…
2024-01-17T21:04:37.934636Z [net] net thread start
2024-01-17T21:04:37.934726Z [dnsseed] dnsseed thread start
2024-01-17T21:04:37.934844Z [addcon] addcon thread start
2024-01-17T21:04:37.934962Z [opencon] opencon thread start
2024-01-17T21:04:37.935037Z [msghand] msghand thread start
2024-01-17T21:04:37.935118Z [dnsseed] Waiting 300 seconds before querying DNS seeds.
2024-01-17T21:04:37.935608Z [init] init message: Done loading
2024-01-17T21:04:44.720652Z [msghand] New block-relay-only v1 peer connected: version: 70016, blocks=826175, peer=0, peeraddr=24.118.251.111:8333
2024-01-17T21:04:45.088087Z [msghand] Synchronizing blockheaders, height: 826175 (~100.00%)
2024-01-17T21:04:45.298560Z [msghand] New outbound-full-relay v1 peer connected: version: 70016, blocks=826175, peer=2, peeraddr=213.144.146.33:8333
2024-01-17T21:04:46.518049Z [initload] Progress loading mempool transactions from disk: 10% (tried 1947, 17520 remaining)
2024-01-17T21:04:50.041449Z [msghand] UpdateTip: new best=00000000000000000000ff10e27886dcbad5e3f737aea821dd0bfca23a29222e height=825927 version=0x34870000 log2_work=94.668428 tx=952738179 date='2024-01-15T21:27:43Z' progress=0.999007 cache=2.9MiB(22933txo)
2024-01-17T21:04:53.647945Z [msghand] UpdateTip: new best=0000000000000000000231eb8884fec2e3c2fe14fd82626bcaa1a7ceec5caf93 height=825928 version=0x24b24000 log2_work=94.668442 tx=952741302 date='2024-01-15T21:34:01Z' progress=0.999010 cache=4.8MiB(36259txo)
2024-01-17T21:05:18.323365Z [msghand] New outbound-full-relay v1 peer connected: version: 70015, blocks=826175, peer=6, peeraddr=221.223.27.170:2011
2024-01-17T21:05:20.186948Z [msghand] New outbound-full-relay v1 peer connected: version: 70015, blocks=826175, peer=9, peeraddr=31.171.251.35:8333
2024-01-17T21:05:21.948231Z [dnsseed] P2P peers available. Skipped DNS seeding.
2024-01-17T21:05:21.948340Z [dnsseed] dnsseed thread exit
2024-01-17T21:05:38.095382Z [msghand] New outbound-full-relay v1 peer connected: version: 70016, blocks=826175, peer=11, peeraddr=159.89.121.240:8333
2024-01-17T21:05:40.146740Z [msghand] New outbound-full-relay v1 peer connected: version: 70016, blocks=826175, peer=13, peeraddr=66.203.112.31:30034
2024-01-17T21:05:42.838455Z [msghand] New outbound-full-relay v1 peer connected: version: 70016, blocks=826175, peer=16, peeraddr=104.189.105.88:8333
2024-01-17T21:05:42.839679Z [msghand] New outbound-full-relay v1 peer connected: version: 70016, blocks=826175, peer=14, peeraddr=93.57.81.162:8333
2024-01-17T21:05:43.871172Z [msghand] New outbound-full-relay v1 peer connected: version: 70016, blocks=826175, peer=15, peeraddr=192.146.137.44:8333
2024-01-17T21:05:48.566843Z [msghand] New outbound-full-relay v1 peer connected: version: 70015, blocks=826175, peer=19, peeraddr=91.147.232.98:8333
2024-01-17T21:06:01.649709Z [initload] Progress loading mempool transactions from disk: 20% (tried 3894, 15573 remaining)
2024-01-17T21:06:24.172283Z [msghand] New outbound-full-relay v1 peer connected: version: 70016, blocks=826175, peer=22, peeraddr=108.214.8.13:50501
2024-01-17T21:06:33.410186Z [initload] Progress loading mempool transactions from disk: 30% (tried 5841, 13626 remaining)
2024-01-17T21:06:49.051526Z [msghand] New block-relay-only v1 peer connected: version: 70015, blocks=826175, peer=23, peeraddr=34.95.0.69:8333
2024-01-17T21:07:24.909070Z [msghand] Synchronizing blockheaders, height: 826176 (~100.00%)
2024-01-17T21:07:43.039910Z [msghand] New block-relay-only v1 peer connected: version: 70016, blocks=826176, peer=25, peeraddr=198.58.118.99:8333
2024-01-17T21:08:29.431947Z [initload] Progress loading mempool transactions from disk: 40% (tried 7787, 11680 remaining)
2024-01-17T21:11:05.226379Z [initload] Progress loading mempool transactions from disk: 50% (tried 9734, 9733 remaining)
2024-01-17T21:13:32.216591Z [initload] Progress loading mempool transactions from disk: 60% (tried 11681, 7786 remaining)
2024-01-17T21:14:03.498201Z [msghand] Synchronizing blockheaders, height: 826177 (~100.00%)
2024-01-17T21:14:45.905189Z [initload] Progress loading mempool transactions from disk: 70% (tried 13627, 5840 remaining)
2024-01-17T21:15:14.282892Z [initload] Progress loading mempool transactions from disk: 80% (tried 15574, 3893 remaining)
2024-01-17T21:15:31.923806Z [initload] Progress loading mempool transactions from disk: 90% (tried 17521, 1946 remaining)
2024-01-17T21:15:35.950446Z [initload] Imported mempool transactions from disk: 19358 succeeded, 109 failed, 0 expired, 0 already there, 0 waiting for initial broadcast
2024-01-17T21:15:35.950530Z [initload] initload thread exit
2024-01-17T21:18:46.843126Z [msghand] Synchronizing blockheaders, height: 826178 (~100.00%)
2024-01-17T21:19:51.712211Z [msghand] Timeout downloading block 0000000000000000000388f339429b7cdb2b9d50cf7482dea9556afdc2033d17 from peer=0 peeraddr=24.118.251.111:8333, disconnecting
2024-01-17T21:19:51.944570Z [msghand] New block-relay-only v1 peer connected: version: 70016, blocks=826178, peer=26, peeraddr=86.89.51.161:8333
2024-01-17T21:19:52.960361Z [msghand] New block-relay-only v1 peer connected: version: 70016, blocks=826178, peer=27, peeraddr=82.192.82.173:8333
2024-01-17T21:19:57.559635Z [msghand] UpdateTip: new best=0000000000000000000388f339429b7cdb2b9d50cf7482dea9556afdc2033d17 height=825929 version=0x32f88000 log2_work=94.668457 tx=952745617 date='2024-01-15T21:48:17Z' progress=0.999009 cache=78.2MiB(662424txo)
```
- URL
-
https://github.com/bitcoin/bitcoin/issue/29281
- Closed by
-
#29664
Back to List