search

btcsuite / btcd

An alternative full node bitcoin implementation written in Go (golang)
https://github.com/btcsuite/btcd/blob/master/README.md
ISC License
6.09k stars 2.31k forks source link

Blockchain sync breaks in prune mode #2188

Open apulsifer opened 1 month ago

apulsifer commented 1 month ago

I downloaded btcd-windows-amd64-v0.24.2-beta.rc1.zip onto a Windows 10 machine and am attempting to do a full sync of the blockchain in prune mode. (I'm using the beta because I wanted the fix for Issue #2121.) After interrupting the sync and restarting it, I very quickly got a Rejected block message followed by an endless stream of orphan blocks. Attached below is the tail of of the console output before interrupting and after restarting.

2024-05-21 07:49:55.503 [INF] SYNC: Processed 12 blocks in the last 11.31s (21195 transactions, height 547827, 2018-10-29 07:30:25 -0400 EDT, ~115 MiB cache) 2024-05-21 07:50:07.119 [INF] SYNC: Processed 6 blocks in the last 11.61s (15672 transactions, height 547833, 2018-10-29 08:48:17 -0400 EDT, ~117 MiB cache) 2024-05-21 07:50:17.859 [INF] SYNC: Processed 7 blocks in the last 10.73s (13708 transactions, height 547840, 2018-10-29 10:02:36 -0400 EDT, ~119 MiB cache) 2024-05-21 07:50:31.526 [INF] SYNC: Processed 9 blocks in the last 13.66s (18756 transactions, height 547849, 2018-10-29 12:06:57 -0400 EDT, ~122 MiB cache) 2024-05-21 07:50:43.001 [INF] SYNC: Processed 6 blocks in the last 11.47s (15819 transactions, height 547855, 2018-10-29 13:45:28 -0400 EDT, ~124 MiB cache) 2024-05-21 07:50:46.681 [INF] BTCD: Received signal (interrupt). Shutting down... 2024-05-21 07:50:46.955 [INF] BTCD: Gracefully shutting down the server... 2024-05-21 07:50:47.057 [WRN] SRVR: Server shutting down 2024-05-21 07:50:47.146 [WRN] RPCS: RPC server shutting down 2024-05-21 07:50:47.557 [INF] RPCS: RPC server shutdown complete 2024-05-21 07:50:48.005 [INF] SYNC: Sync manager shutting down 2024-05-21 07:50:48.929 [INF] SYNC: Lost peer 68.197.218.66:8333 (outbound) 2024-05-21 07:50:48.929 [INF] SYNC: Syncing to block height 844429 from peer [2001:678:68c:fffb::195]:8333 2024-05-21 07:50:48.929 [INF] SYNC: Downloading headers for blocks 547859 to 550000 from peer [2001:678:68c:fffb::195]:8333 2024-05-21 07:50:48.929 [INF] CHAN: Flushing UTXO cache of 125 MiB with 453804 entries to disk. For large sizes, this can take up to several minutes... 2024-05-21 07:50:58.261 [INF] AMGR: Address manager shutting down 2024-05-21 07:50:58.459 [INF] SRVR: Server shutdown complete 2024-05-21 07:50:58.464 [INF] BTCD: Gracefully shutting down the database... 2024-05-21 07:51:04.565 [INF] BTCD: Shutdown complete

2024-05-21 08:17:52.656 [INF] BTCD: Version 0.24.2-betarc1 2024-05-21 08:17:52.658 [INF] BTCD: Loading block database from 'z:\btcd-data\mainnet\blocks_ffldb' 2024-05-21 08:17:53.407 [INF] BTCD: Block database loaded 2024-05-21 08:17:53.439 [INF] INDX: Committed filter index is enabled 2024-05-21 08:17:53.439 [INF] CHAN: Pre-alloacting for 251 MiB: 2024-05-21 08:17:53.450 [INF] CHAN: Loading block index... 2024-05-21 08:17:58.310 [INF] CHAN: Chain state (height 547858, hash 00000000000000000008a55197d985a4ee0e1edcbd467882533105b36c036fae, totaltx 352331688, work 1181530417039900316882394949) 2024-05-21 08:17:58.661 [INF] RPCS: RPC server listening on 127.0.0.1:8334 2024-05-21 08:17:58.699 [INF] AMGR: Loaded 4100 addresses from file 'z:\btcd-data\mainnet\peers.json' 2024-05-21 08:17:58.699 [INF] CMGR: Server listening on 0.0.0.0:8333 2024-05-21 08:17:58.700 [INF] CMGR: Server listening on [::]:8333 2024-05-21 08:17:58.760 [INF] SYNC: New valid peer 3.211.51.136:8333 (outbound) (/Satoshi:0.17.1/) 2024-05-21 08:17:58.760 [INF] SYNC: Syncing to block height 844432 from peer 3.211.51.136:8333 2024-05-21 08:17:58.760 [INF] SYNC: Downloading headers for blocks 547859 to 550000 from peer 3.211.51.136:8333 2024-05-21 08:17:58.790 [INF] SYNC: New valid peer 68.197.218.66:8333 (outbound) (/Satoshi:25.0.0/) 2024-05-21 08:17:58.831 [INF] SYNC: New valid peer 71.204.232.121:8333 (outbound) (/Satoshi:26.0.0/) 2024-05-21 08:17:58.862 [INF] SYNC: Verified downloaded block header against checkpoint at height 550000/hash 000000000000000000223b7a2298fb1c6c75fb0efc28a4c56853ff4112ec6bc9 2024-05-21 08:17:58.862 [INF] SYNC: Received 2142 block headers: Fetching blocks 2024-05-21 08:17:59.007 [INF] SYNC: New valid peer 88.9.74.206:8333 (outbound) (/Satoshi:27.0.0/) 2024-05-21 08:17:59.194 [INF] CMGR: 36 addresses found from DNS seed dnsseed.bitcoin.dashjr.org 2024-05-21 08:17:59.303 [INF] CMGR: 37 addresses found from DNS seed seed.btc.petertodd.net 2024-05-21 08:17:59.307 [INF] CMGR: 37 addresses found from DNS seed seed.bitcoinstats.com 2024-05-21 08:17:59.341 [INF] CMGR: 40 addresses found from DNS seed seed.bitnodes.io 2024-05-21 08:17:59.389 [INF] CMGR: 31 addresses found from DNS seed dnsseed.bluematt.me 2024-05-21 08:17:59.409 [INF] CMGR: 37 addresses found from DNS seed seed.bitcoin.jonasschnelli.ch 2024-05-21 08:18:00.215 [INF] SYNC: Lost peer 3.211.51.136:8333 (outbound) 2024-05-21 08:18:00.216 [INF] SYNC: Syncing to block height 844432 from peer 68.197.218.66:8333 2024-05-21 08:18:00.216 [INF] SYNC: Downloading headers for blocks 547860 to 550000 from peer 68.197.218.66:8333 2024-05-21 08:18:00.392 [INF] CMGR: 39 addresses found from DNS seed seed.bitcoin.sipa.be 2024-05-21 08:18:00.399 [INF] SYNC: Verified downloaded block header against checkpoint at height 550000/hash 000000000000000000223b7a2298fb1c6c75fb0efc28a4c56853ff4112ec6bc9 2024-05-21 08:18:00.399 [INF] SYNC: Received 2141 block headers: Fetching blocks 2024-05-21 08:18:00.481 [INF] SYNC: New valid peer [2a05:d012:42a:5701:dc20:d4b8:b5d0:dba9]:8333 (outbound) (/Satoshi:0.21.1/) 2024-05-21 08:18:12.771 [INF] SYNC: Processed 3 blocks in the last 12.37s (5532 transactions, height 547861, 2018-10-29 14:21:19 -0400 EDT, ~99 MiB cache) 2024-05-21 08:18:22.073 [INF] SYNC: New valid peer 46.137.123.109:8333 (outbound) (/Satoshi:22.0.0/) 2024-05-21 08:18:22.073 [INF] SYNC: New valid peer 122.234.23.105:8333 (outbound) (/Satoshi:25.2.0/) 2024-05-21 08:18:22.073 [INF] SYNC: Lost peer 46.137.123.109:8333 (outbound) 2024-05-21 08:18:24.572 [INF] SYNC: Processed 4 blocks in the last 11.8s (10788 transactions, height 547865, 2018-10-29 14:55:14 -0400 EDT, ~101 MiB cache) 2024-05-21 08:18:24.572 [INF] SYNC: New valid peer [2a00:8a60:e012:a00::21]:8333 (outbound) (/Satoshi:27.0.0/) 2024-05-21 08:18:26.529 [INF] SYNC: New valid peer [2001:4060:4419:8001::42]:8333 (outbound) (/Satoshi:24.0.1/) 2024-05-21 08:18:37.257 [INF] SYNC: Processed 6 blocks in the last 12.68s (15434 transactions, height 547871, 2018-10-29 15:51:25 -0400 EDT, ~104 MiB cache) 2024-05-21 08:18:49.377 [INF] SYNC: Processed 8 blocks in the last 12.12s (17568 transactions, height 547879, 2018-10-29 17:14:18 -0400 EDT, ~107 MiB cache) 2024-05-21 08:19:00.539 [INF] SYNC: Processed 7 blocks in the last 11.16s (14979 transactions, height 547886, 2018-10-29 18:26:25 -0400 EDT, ~110 MiB cache) 2024-05-21 08:19:00.547 [INF] SYNC: Lost peer [2001:4060:4419:8001::42]:8333 (outbound) 2024-05-21 08:19:00.547 [INF] SYNC: Lost peer [2a05:d012:42a:5701:dc20:d4b8:b5d0:dba9]:8333 (outbound) 2024-05-21 08:19:01.778 [INF] SYNC: New valid peer 141.95.75.152:8333 (outbound) (/Satoshi:25.0.0/) 2024-05-21 08:19:10.729 [INF] SYNC: Processed 8 blocks in the last 10.19s (15855 transactions, height 547894, 2018-10-29 19:19:35 -0400 EDT, ~113 MiB cache) 2024-05-21 08:19:10.730 [INF] SYNC: New valid peer [2001:638:a000:4140::ffff:47]:8333 (outbound) (/Satoshi:27.0.0/) 2024-05-21 08:19:21.654 [INF] SYNC: Processed 9 blocks in the last 10.92s (15036 transactions, height 547903, 2018-10-29 20:51:36 -0400 EDT, ~115 MiB cache) 2024-05-21 08:19:21.654 [INF] SYNC: New valid peer 13.115.247.80:8333 (outbound) (/Satoshi:0.21.1/) 2024-05-21 08:19:32.782 [INF] SYNC: Processed 13 blocks in the last 11.12s (28435 transactions, height 547916, 2018-10-29 23:28:42 -0400 EDT, ~119 MiB cache) 2024-05-21 08:19:43.124 [INF] SYNC: Processed 19 blocks in the last 10.34s (25963 transactions, height 547935, 2018-10-30 02:22:37 -0400 EDT, ~121 MiB cache) 2024-05-21 08:19:53.846 [INF] SYNC: Processed 11 blocks in the last 10.72s (25271 transactions, height 547946, 2018-10-30 05:15:24 -0400 EDT, ~124 MiB cache) 2024-05-21 08:20:04.032 [INF] SYNC: Processed 19 blocks in the last 10.18s (45109 transactions, height 547965, 2018-10-30 08:27:34 -0400 EDT, ~129 MiB cache) 2024-05-21 08:20:34.705 [INF] SYNC: Processed 12 blocks in the last 30.67s (24938 transactions, height 547977, 2018-10-30 10:22:24 -0400 EDT, ~132 MiB cache) 2024-05-21 08:20:34.705 [INF] SYNC: Lost peer 13.115.247.80:8333 (outbound) 2024-05-21 08:20:34.705 [INF] SYNC: New valid peer [2001:b030:2422::208d]:8333 (outbound) (/Satoshi:27.0.0/) 2024-05-21 08:20:34.705 [INF] SYNC: Lost peer [2001:b030:2422::208d]:8333 (outbound) 2024-05-21 08:20:45.629 [INF] SYNC: Processed 3 blocks in the last 10.92s (6544 transactions, height 547980, 2018-10-30 10:44:03 -0400 EDT, ~133 MiB cache) 2024-05-21 08:20:55.722 [INF] SYNC: Processed 9 blocks in the last 10.09s (22313 transactions, height 547989, 2018-10-30 12:49:44 -0400 EDT, ~135 MiB cache) 2024-05-21 08:20:56.554 [INF] SYNC: New valid peer 173.212.98.0:8333 (outbound) (/Satoshi:0.19.0.1/) 2024-05-21 08:20:57.101 [INF] SYNC: Lost peer 173.212.98.0:8333 (outbound) 2024-05-21 08:20:57.133 [INF] SYNC: New valid peer 140.238.220.99:8333 (outbound) (/Satoshi:25.1.0/) 2024-05-21 08:21:05.909 [INF] SYNC: Processed 15 blocks in the last 10.18s (30841 transactions, height 548004, 2018-10-30 14:18:59 -0400 EDT, ~137 MiB cache) 2024-05-21 08:21:16.007 [INF] SYNC: Processed 24 blocks in the last 10.09s (39628 transactions, height 548028, 2018-10-30 17:35:15 -0400 EDT, ~141 MiB cache) 2024-05-21 08:21:26.027 [INF] SYNC: Processed 34 blocks in the last 10.02s (44395 transactions, height 548062, 2018-10-30 21:48:26 -0400 EDT, ~146 MiB cache) 2024-05-21 08:21:36.657 [INF] SYNC: Processed 29 blocks in the last 10.62s (42539 transactions, height 548091, 2018-10-31 02:08:48 -0400 EDT, ~150 MiB cache) 2024-05-21 08:21:47.036 [INF] SYNC: Processed 20 blocks in the last 10.37s (40492 transactions, height 548111, 2018-10-31 06:25:54 -0400 EDT, ~154 MiB cache) 2024-05-21 08:21:57.535 [INF] SYNC: Processed 18 blocks in the last 10.49s (34301 transactions, height 548129, 2018-10-31 09:21:53 -0400 EDT, ~157 MiB cache) 2024-05-21 08:22:08.166 [INF] SYNC: Processed 18 blocks in the last 10.63s (38643 transactions, height 548147, 2018-10-31 11:13:38 -0400 EDT, ~159 MiB cache) 2024-05-21 08:22:18.913 [INF] SYNC: Processed 18 blocks in the last 10.74s (37400 transactions, height 548165, 2018-10-31 13:49:03 -0400 EDT, ~162 MiB cache) 2024-05-21 08:22:29.457 [INF] SYNC: Processed 19 blocks in the last 10.54s (31914 transactions, height 548184, 2018-10-31 16:06:57 -0400 EDT, ~164 MiB cache) 2024-05-21 08:22:39.679 [INF] SYNC: Processed 20 blocks in the last 10.22s (33735 transactions, height 548204, 2018-10-31 19:01:23 -0400 EDT, ~167 MiB cache) 2024-05-21 08:22:49.777 [INF] SYNC: Processed 23 blocks in the last 10.09s (31661 transactions, height 548227, 2018-10-31 22:12:07 -0400 EDT, ~171 MiB cache) 2024-05-21 08:22:59.817 [INF] SYNC: Processed 19 blocks in the last 10.04s (25609 transactions, height 548246, 2018-11-01 00:39:02 -0400 EDT, ~173 MiB cache) 2024-05-21 08:23:11.009 [INF] SYNC: Processed 27 blocks in the last 11.19s (33840 transactions, height 548273, 2018-11-01 04:04:35 -0400 EDT, ~175 MiB cache) 2024-05-21 08:23:21.363 [INF] SYNC: Processed 21 blocks in the last 10.35s (41872 transactions, height 548294, 2018-11-01 08:09:49 -0400 EDT, ~179 MiB cache) 2024-05-21 08:23:31.728 [INF] SYNC: Processed 20 blocks in the last 10.36s (42706 transactions, height 548314, 2018-11-01 10:48:49 -0400 EDT, ~182 MiB cache) 2024-05-21 08:23:42.187 [INF] SYNC: Processed 21 blocks in the last 10.45s (42960 transactions, height 548335, 2018-11-01 13:53:57 -0400 EDT, ~185 MiB cache) 2024-05-21 08:23:52.577 [INF] SYNC: Processed 21 blocks in the last 10.38s (49360 transactions, height 548356, 2018-11-01 17:25:48 -0400 EDT, ~188 MiB cache) 2024-05-21 08:24:02.780 [INF] SYNC: Processed 17 blocks in the last 10.2s (36679 transactions, height 548373, 2018-11-01 21:38:09 -0400 EDT, ~191 MiB cache) 2024-05-21 08:24:12.892 [INF] SYNC: Processed 28 blocks in the last 10.11s (39130 transactions, height 548401, 2018-11-02 01:03:15 -0400 EDT, ~195 MiB cache) 2024-05-21 08:24:23.284 [INF] SYNC: Processed 25 blocks in the last 10.39s (45144 transactions, height 548426, 2018-11-02 05:41:47 -0400 EDT, ~198 MiB cache) 2024-05-21 08:24:33.480 [INF] SYNC: Processed 21 blocks in the last 10.19s (48295 transactions, height 548447, 2018-11-02 10:17:05 -0400 EDT, ~201 MiB cache) 2024-05-21 08:24:43.847 [INF] SYNC: Processed 18 blocks in the last 10.36s (46227 transactions, height 548465, 2018-11-02 13:23:02 -0400 EDT, ~217 MiB cache) 2024-05-21 08:24:53.874 [INF] SYNC: Processed 20 blocks in the last 10.02s (54005 transactions, height 548485, 2018-11-02 16:14:44 -0400 EDT, ~220 MiB cache) 2024-05-21 08:25:04.184 [INF] SYNC: Processed 15 blocks in the last 10.3s (30161 transactions, height 548500, 2018-11-02 18:22:02 -0400 EDT, ~223 MiB cache) 2024-05-21 08:25:14.382 [INF] SYNC: Processed 21 blocks in the last 10.19s (35273 transactions, height 548521, 2018-11-02 21:39:02 -0400 EDT, ~225 MiB cache) 2024-05-21 08:25:24.390 [INF] SYNC: Processed 29 blocks in the last 10s (40522 transactions, height 548550, 2018-11-03 02:12:22 -0400 EDT, ~235 MiB cache) 2024-05-21 08:25:34.533 [INF] SYNC: Processed 29 blocks in the last 10.14s (36980 transactions, height 548579, 2018-11-03 06:14:24 -0400 EDT, ~238 MiB cache) 2024-05-21 08:25:44.879 [INF] SYNC: Processed 25 blocks in the last 10.34s (46286 transactions, height 548604, 2018-11-03 10:15:49 -0400 EDT, ~244 MiB cache) 2024-05-21 08:25:55.357 [INF] SYNC: Processed 18 blocks in the last 10.47s (41997 transactions, height 548622, 2018-11-03 13:31:49 -0400 EDT, ~249 MiB cache) 2024-05-21 08:26:00.777 [INF] CHAN: Flushing UTXO cache of 250 MiB with 2107529 entries to disk. For large sizes, this can take up to several minutes... 2024-05-21 08:26:48.428 [INF] SYNC: Processed 10 blocks in the last 53.07s (17102 transactions, height 548632, 2018-11-03 15:06:27 -0400 EDT, ~97 MiB cache) 2024-05-21 08:26:59.084 [INF] SYNC: Processed 13 blocks in the last 10.65s (22003 transactions, height 548645, 2018-11-03 17:05:32 -0400 EDT, ~102 MiB cache) 2024-05-21 08:27:09.632 [INF] SYNC: Processed 35 blocks in the last 10.54s (38761 transactions, height 548680, 2018-11-03 21:35:24 -0400 EDT, ~107 MiB cache) 2024-05-21 08:27:19.770 [INF] SYNC: Processed 23 blocks in the last 10.13s (47484 transactions, height 548703, 2018-11-04 02:20:14 -0500 EST, ~112 MiB cache) 2024-05-21 08:27:30.287 [INF] SYNC: Processed 24 blocks in the last 10.51s (40688 transactions, height 548727, 2018-11-04 06:34:28 -0500 EST, ~117 MiB cache) 2024-05-21 08:27:40.753 [INF] SYNC: Processed 16 blocks in the last 10.46s (30650 transactions, height 548743, 2018-11-04 09:55:18 -0500 EST, ~121 MiB cache) 2024-05-21 08:27:51.116 [INF] SYNC: Processed 11 blocks in the last 10.36s (22453 transactions, height 548754, 2018-11-04 12:54:06 -0500 EST, ~125 MiB cache) 2024-05-21 08:28:01.655 [INF] SYNC: Processed 10 blocks in the last 10.53s (23401 transactions, height 548764, 2018-11-04 14:22:51 -0500 EST, ~128 MiB cache) 2024-05-21 08:28:12.157 [INF] SYNC: Processed 14 blocks in the last 10.5s (25568 transactions, height 548778, 2018-11-04 16:00:01 -0500 EST, ~131 MiB cache) 2024-05-21 08:28:22.638 [INF] SYNC: Processed 18 blocks in the last 10.48s (28988 transactions, height 548796, 2018-11-04 19:14:23 -0500 EST, ~135 MiB cache) 2024-05-21 08:28:33.680 [INF] SYNC: Processed 31 blocks in the last 11.04s (46233 transactions, height 548827, 2018-11-04 23:25:00 -0500 EST, ~139 MiB cache) 2024-05-21 08:28:43.825 [INF] SYNC: Processed 11 blocks in the last 10.14s (29088 transactions, height 548838, 2018-11-05 03:43:57 -0500 EST, ~142 MiB cache) 2024-05-21 08:28:54.200 [INF] SYNC: Processed 19 blocks in the last 10.37s (45802 transactions, height 548857, 2018-11-05 07:27:19 -0500 EST, ~147 MiB cache) 2024-05-21 08:29:04.293 [INF] SYNC: Processed 17 blocks in the last 10.09s (36677 transactions, height 548874, 2018-11-05 09:42:46 -0500 EST, ~150 MiB cache) 2024-05-21 08:29:14.782 [INF] SYNC: Processed 22 blocks in the last 10.48s (49753 transactions, height 548896, 2018-11-05 12:24:20 -0500 EST, ~154 MiB cache) 2024-05-21 08:29:24.858 [INF] SYNC: Processed 18 blocks in the last 10.07s (40074 transactions, height 548914, 2018-11-05 15:34:01 -0500 EST, ~158 MiB cache) 2024-05-21 08:29:35.220 [INF] SYNC: Processed 31 blocks in the last 10.36s (54669 transactions, height 548945, 2018-11-05 20:08:38 -0500 EST, ~162 MiB cache) 2024-05-21 08:29:45.447 [INF] SYNC: Processed 29 blocks in the last 10.22s (56830 transactions, height 548974, 2018-11-06 01:02:13 -0500 EST, ~166 MiB cache) 2024-05-21 08:29:55.503 [INF] SYNC: Processed 25 blocks in the last 10.05s (50136 transactions, height 548999, 2018-11-06 05:38:50 -0500 EST, ~170 MiB cache) 2024-05-21 08:30:05.636 [INF] SYNC: Processed 23 blocks in the last 10.13s (48663 transactions, height 549022, 2018-11-06 10:28:36 -0500 EST, ~173 MiB cache) 2024-05-21 08:30:06.205 [ERR] SYNC: Failed to process block 0000000000000000001ffa51b023619b5e43b109a95a0212ee65a5ab5658c701: remove z:\btcd-data\mainnet\blocks_ffldb\000000352.fdb: The process cannot access the file because it is being used by another process.: remove z:\btcd-data\mainnet\blocks_ffldb\000000352.fdb: The process cannot access the file because it is being used by another process. 2024-05-21 08:30:06.458 [WRN] CHAN: fastAdd set in the side chain case? 00000000000000000022dbd7545dc807288aa39f813c31903c2fdf0e26c9cee4

2024-05-21 08:30:11.596 [INF] CHAN: REORGANIZE: Block 00000000000000000022dbd7545dc807288aa39f813c31903c2fdf0e26c9cee4 is causing a reorganize. 2024-05-21 08:30:12.202 [INF] SYNC: Rejected block 00000000000000000022dbd7545dc807288aa39f813c31903c2fdf0e26c9cee4 from 68.197.218.66:8333 (outbound): output 9ab1bfcce4827c1e0af979ebe2de7c5f46aa03c59b9192520e7d649387c21a18:1 referenced from transaction 151b1732f27518aca51ee5dd26096d4ee9b4187fb2cce93d29d1d5e4fb8c3188:0 either does not exist or has already been spent 2024-05-21 08:30:12.225 [INF] SYNC: Rejected block 0000000000000000000caa594b74f5f7d5201afafafc41e6e1a0936fcffd6461 from 68.197.218.66:8333 (outbound): previous block 00000000000000000022dbd7545dc807288aa39f813c31903c2fdf0e26c9cee4 is known to be invalid 2024-05-21 08:30:12.321 [INF] CHAN: Adding orphan block 0000000000000000000c98ab143c015304f334094ea439a511442a2bcafa5ec7 with parent 0000000000000000000caa594b74f5f7d5201afafafc41e6e1a0936fcffd6461 2024-05-21 08:30:19.686 [INF] CHAN: Adding orphan block 00000000000000000006fc25151edfed27ef92ac53ce86b3c6f9cd58904ac468 with parent 0000000000000000000c98ab143c015304f334094ea439a511442a2bcafa5ec7 2024-05-21 08:30:19.830 [INF] CHAN: Adding orphan block 0000000000000000000064720bd93f637ac60dbb2127d94cf643f596873e1bd4 with parent 00000000000000000006fc25151edfed27ef92ac53ce86b3c6f9cd58904ac468 2024-05-21 08:30:20.270 [INF] CHAN: Adding orphan block 000000000000000000257727845ae7020b1de0258d32731d1d1abfa3adf65219 with parent 0000000000000000000064720bd93f637ac60dbb2127d94cf643f596873e1bd4 2024-05-21 08:30:20.807 [INF] CHAN: Adding orphan block 0000000000000000000c22963bd419ae3e8ffd8a64fe0cafe43fb690efc22661 with parent 000000000000000000257727845ae7020b1de0258d32731d1d1abfa3adf65219 2024-05-21 08:30:21.338 [INF] CHAN: Adding orphan block 0000000000000000000a9b4e6b6283a264bb6372b26ebffc440b46ba211e9c8f with parent 0000000000000000000c22963bd419ae3e8ffd8a64fe0cafe43fb690efc22661 2024-05-21 08:30:21.918 [INF] CHAN: Adding orphan block 00000000000000000016f1c5f534c82c4d39d4882cbcc6ddbb114d75d2ee3cae with parent 0000000000000000000a9b4e6b6283a264bb6372b26ebffc440b46ba211e9c8f 2024-05-21 08:30:22.515 [INF] CHAN: Adding orphan block 00000000000000000014ae68a64932e966da59ce9c42f35ab2b921cf7ed0b6be with parent 00000000000000000016f1c5f534c82c4d39d4882cbcc6ddbb114d75d2ee3cae 2024-05-21 08:30:23.027 [INF] CHAN: Adding orphan block 0000000000000000001e75fcfc5ae80d613a9a7660b3a3b9b713a1aa1bf5ec63 with parent 00000000000000000014ae68a64932e966da59ce9c42f35ab2b921cf7ed0b6be 2024-05-21 08:30:23.540 [INF] CHAN: Adding orphan block 000000000000000000161cf0d0bc50e082d5cce4bb7348bdc83455660879d671 with parent 0000000000000000001e75fcfc5ae80d613a9a7660b3a3b9b713a1aa1bf5ec63 2024-05-21 08:30:23.990 [INF] CHAN: Adding orphan block 00000000000000000006918cfa9c68365b6ea8c8c266d6b77c478b7375464b8c with parent 000000000000000000161cf0d0bc50e082d5cce4bb7348bdc83455660879d671 2024-05-21 08:30:24.526 [INF] CHAN: Adding orphan block 0000000000000000000a7a936668b4ade3638ee0a87312760f6903ad4db53ff2 with parent 00000000000000000006918cfa9c68365b6ea8c8c266d6b77c478b7375464b8c 2024-05-21 08:30:24.965 [INF] CHAN: Adding orphan block 000000000000000000206fc3ddb64fba6fb2b0217285ff1a59e8add0b0da82f1 with parent 0000000000000000000a7a936668b4ade3638ee0a87312760f6903ad4db53ff2 2024-05-21 08:30:25.426 [INF] CHAN: Adding orphan block 0000000000000000000c71775a7f376597617dce2618394a9c20fbde264849aa with parent 000000000000000000206fc3ddb64fba6fb2b0217285ff1a59e8add0b0da82f1 2024-05-21 08:30:25.902 [INF] CHAN: Adding orphan block 000000000000000000063c905023e0d7fb76fd271bcd9440807a69d812d35e7a with parent 0000000000000000000c71775a7f376597617dce2618394a9c20fbde264849aa 2024-05-21 08:30:26.404 [INF] CHAN: Adding orphan block 0000000000000000001dc731749c7a62c7fdfcdacfd168dd04341c0fc96c21cf with parent 000000000000000000063c905023e0d7fb76fd271bcd9440807a69d812d35e7a 2024-05-21 08:30:26.873 [INF] CHAN: Adding orphan block 000000000000000000101e4c42f083edf8e617d7bb1b970339bf71ebe59c9016 with parent 0000000000000000001dc731749c7a62c7fdfcdacfd168dd04341c0fc96c21cf 2024-05-21 08:30:27.355 [INF] CHAN: Adding orphan block 000000000000000000074cb620fc405c143a6d5b19cadce154aabb1c3ddbf919 with parent 000000000000000000101e4c42f083edf8e617d7bb1b970339bf71ebe59c9016 2024-05-21 08:30:27.858 [INF] CHAN: Adding orphan block 0000000000000000000f4af1e482a2fe1f1e23f0b376d2e0ce6c53def4046c90 with parent 000000000000000000074cb620fc405c143a6d5b19cadce154aabb1c3ddbf919 2024-05-21 08:30:28.533 [INF] CHAN: Adding orphan block 000000000000000000114bb162879f41e18524d43e3c0b1390d1b6ae46c502b4 with parent 0000000000000000000f4af1e482a2fe1f1e23f0b376d2e0ce6c53def4046c90

Roasbeef commented 1 month ago

It looks like btcd was unable to open/remove a file, which lead to the sync issue?

2024-05-21 08:30:06.205 [ERR] SYNC: Failed to process block 0000000000000000001ffa51b023619b5e43b109a95a0212ee65a5ab5658c701: remove z:\btcd-data\mainnet\blocks_ffldb\000000352.fdb: The process cannot access the file because it is being used by another process.: remove z:\btcd-data\mainnet\blocks_ffldb\000000352.fdb: The process cannot access the file because it is being used by another process.
apulsifer commented 1 month ago

I read the log entry but I'm certainly not going to blindly trust that the entry is accurate or that it's the cause of the problem. It just so happens that the reason I interrupted bctd was to make a copy of data directory to backup progress after two days of syncing, so I can confirm that file did exist. But it could be that the "remove" happened after the problem and it's just a side effect of whatever actually caused the problem. In any event, whatever did cause remove to fail is internal to btcd because there was nothing external touching any of those files (it was 30 minutes later that I restarted btcd, and the copy had long since finished). I would also note this is my second attempt at doing a full sync, and I saw a block confirmation failure and a block "is known to be invalid" message followed by an endless stream of orphaned blocks that time, too, but I didn't keep the console output that time so I nuked everything and started over to capture the console output from the beginning. Two failures in a row after several days of syncing but still only maybe 20% finished obvi makes this software unusable at least in prune mode.

kcalvinalvin commented 2 days ago

I was able to reproduce it once but not when I tried it the second and the third time. Trying to reproduce but seems to work just fine. I've verified that files are pruning correctly and I was able to stop and restart multiple times after the initial prune.

My guess is that windows does something to access the file and when btcd tries to access it at the same time it errors out.

My system: 

Windows 10 Pro
Version 22H2
Build 19045.4529

Flags I'm running with (on powershell):

./btcd --prune=1536

Built on master on commit 139669066ca7631559d45efe25ab5518bb692554

Roasbeef commented 1 day ago

Closing based on the above comment, v0.24.2 has also been tagged.

kcalvinalvin commented 1 day ago

I think this issue should stay open until the root cause is resolved. I left the binary sync overnight and it hit the same error again. My guess is that when Windows detects the user isn't doing anything with the process it tries some optimization with the files and when pruning happens at the same time it errors out.

apulsifer commented 23 hours ago

[comment in error deleted]

saubyk commented 10 hours ago

@apulsifer

I downloaded btcd-windows-amd64-v0.24.2-beta.rc1.zip onto a Windows 10 machine and am attempting to do a full sync of the blockchain in prune mode

you indicated on the first line of the issue that you're running on Windows

apulsifer commented 3 hours ago

GM Saubyk, my apologies, I got confused with similar issue with bitcoind under Linux. Yes, this is under Windows. As I recall, if I interrupt the blockchain sync and try to resume, it fails 100% of the time. I don't remember exactly tho, I was unable to get anywhere with btcd so I stopped using it.