ERROR: ReadRawBlockFromDisk: Read from block file failed: CAutoFile::read: end of file: iostream error for CBlockDiskPos(nFile=0, nPos=16830050) #14933

issue andronoob openend this issue on December 12, 2018
  1. andronoob commented at 5:24 am on December 12, 2018: none

    Bitcoin-qt.exe suddenly stopped working. The symptom looked like #14447, an “assertion failed” error message popped up. debug.log said:

    0ERROR: ReadRawBlockFromDisk: Read from block file failed: CAutoFile::read: end of file: iostream error for CBlockDiskPos(nFile=0, nPos=16830050)

    Bitcoin Core v0.17.0.1 x64 Windows 10 17763 x64

    Running Electrum Personal Server with Cygwin x64.

    bitcoin.conf:

     0txindex=1
 1server=1
 2addresstype=p2sh-segwit
 3rpcbind=127.0.0.1:8332
 4rpcuser=USERNAME
 5rpcpassword=PASSWORD
 6rpcallowip=127.0.0.1
 7zmqpubrawblock=tcp://127.0.0.1:18501
 8zmqpubrawtx=tcp://127.0.0.1:18501
 9externalip=DDNS_DOMAIN_NAME
10discover=1

    Specified -blocksdir by command line to migrate block storage to HDD.

  2. jonasschnelli added the label Block storage on Dec 12, 2018
  3. jonasschnelli added the label Data corruption on Dec 12, 2018
  4. jonasschnelli commented at 5:56 am on December 12, 2018: contributor
    Looks like a standard disk corruption… Since everything gets validated, Bitcoin Core is very good in spotting all sorts of corruption on lower levels.
  5. andronoob commented at 7:37 am on December 12, 2018: none

    Looks like a standard disk corruption…

    After that crash, I tried to restart bitcoin-qt, it launched successfully, without any complain. The S.M.A.R.T data didn’t report anything wrong, either.

    debug.log:

     02018-12-12T04:07:21Z Pre-allocating up to position 0x5000000 in blk01459.dat
 12018-12-12T04:07:21Z UpdateTip: new best=0000000000000000002fc33ac46fe482972e0e9e479377e5ce1f5b6d13ec4b58 height=553481 version=0x20000000 log2_work=90.117717 tx=363835988 date='2018-12-12T04:06:32Z' progress=1.000000 cache=76.2MiB(566931txo) warning='最后100个区块中的34个包含未知的版本号'
 22018-12-12T04:14:40Z UpdateTip: new best=0000000000000000002fa928a8c2ecf79f1d8f962745c49a8ba4f98e32de3f05 height=553482 version=0x20000000 log2_work=90.117743 tx=363838797 date='2018-12-12T04:14:27Z' progress=1.000000 cache=76.5MiB(569323txo) warning='最后100个区块中的33个包含未知的版本号'
 32018-12-12T04:15:44Z UpdateTip: new best=000000000000000000189ffff78b77d6c408a36b99098c41fb4be2d4ff6ffceb height=553483 version=0x20000000 log2_work=90.117769 tx=363839216 date='2018-12-12T04:15:40Z' progress=1.000000 cache=76.5MiB(569447txo) warning='最后100个区块中的33个包含未知的版本号'
 42018-12-12T04:24:19Z socket recv error [远程主机强迫关闭了一个现有的连接。(This string was stored as GBK, I've converted it to UTF-8)]  (10054)
 52018-12-12T04:24:48Z New outbound peer connected: version: 70015, blocks=553483, peer=1707
 62018-12-12T04:30:31Z socket receive timeout: 1201s
 72018-12-12T04:46:45Z Potential stale tip detected, will try using extra outbound peer (last tip update: 1861 seconds ago)
 82018-12-12T04:47:07Z New outbound peer connected: version: 70015, blocks=553483, peer=1769
 92018-12-12T04:52:56Z Pre-allocating up to position 0xa00000 in rev01459.dat
102018-12-12T04:52:56Z UpdateTip: new best=0000000000000000001cf0ebf56562a16461f1fea099950fcec09e1f2686b8a7 height=553484 version=0x20000000 log2_work=90.117795 tx=363842195 date='2018-12-12T04:51:50Z' progress=1.000000 cache=8.4MiB(12725txo) warning='最后100个区块中的33个包含未知的版本号'
112018-12-12T05:02:45Z UpdateTip: new best=00000000000000000001396826d49b72e9e1061665039553ac783a26a75e6dfc height=553485 version=0x20000000 log2_work=90.117821 tx=363844765 date='2018-12-12T05:02:33Z' progress=1.000000 cache=9.5MiB(21314txo) warning='最后100个区块中的32个包含未知的版本号'
122018-12-12T05:09:16Z ERROR: ReadRawBlockFromDisk: Read from block file failed: CAutoFile::read: end of file: iostream error for CBlockDiskPos(nFile=0, nPos=16830050)
132018-12-12T05:10:13Z 
14
15
16
17
182018-12-12T05:10:13Z Bitcoin Core version v0.17.0.1 (release build)
192018-12-12T05:10:13Z InitParameterInteraction: parameter interaction: -whitelistforcerelay=1 -> setting -whitelistrelay=1
202018-12-12T05:10:14Z Assuming ancestors of block 0000000000000000002e63058c023a9a1de233554f28c7b21380b6c9003f36a8 have valid signatures.
212018-12-12T05:10:14Z Setting nMinimumChainWork=0000000000000000000000000000000000000000028822fef1c230963535a90d
222018-12-12T05:10:14Z Using the 'sse4(1way),sse41(4way),avx2(8way)' SHA256 implementation
232018-12-12T05:10:14Z Using RdRand as an additional entropy source
242018-12-12T05:10:15Z Default data directory C:\Users\user\AppData\Roaming\Bitcoin
252018-12-12T05:10:15Z Using data directory S:\Bitcoin
262018-12-12T05:10:15Z Using config file S:\Bitcoin\bitcoin.conf
272018-12-12T05:10:15Z Using at most 125 automatic connections (2048 file descriptors available)
282018-12-12T05:10:15Z GUI: "registerShutdownBlockReason: Successfully registered: Bitcoin Core 尚未安全退出"
292018-12-12T05:10:15Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
302018-12-12T05:10:15Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
312018-12-12T05:10:15Z Using 8 threads for script verification
322018-12-12T05:10:15Z scheduler thread start
332018-12-12T05:10:15Z HTTP: creating work queue of depth 16
342018-12-12T05:10:15Z Config options rpcuser and rpcpassword will soon be deprecated. Locally-run instances may remove rpcuser to use cookie-based auth, or may be replaced with rpcauth. Please see share/rpcauth for rpcauth auth generation.
352018-12-12T05:10:15Z HTTP: starting 4 worker threads
362018-12-12T05:10:15Z Using wallet directory S:\Bitcoin
372018-12-12T05:10:15Z init message: 正在检测钱包的完整性...
382018-12-12T05:10:15Z Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
392018-12-12T05:10:15Z Using wallet wallet.dat
402018-12-12T05:10:15Z BerkeleyEnvironment::Open: LogDir=S:\Bitcoin\database ErrorFile=S:\Bitcoin\db.log
412018-12-12T05:10:15Z AddLocal(117.65.15.106:8333,4)
422018-12-12T05:10:15Z Cache configuration:
432018-12-12T05:10:15Z * Using 2.0MiB for block index database
442018-12-12T05:10:15Z * Using 15.8MiB for transaction index database
452018-12-12T05:10:15Z * Using 8.0MiB for chain state database
462018-12-12T05:10:15Z * Using 102.2MiB for in-memory UTXO set (plus up to 286.1MiB of unused mempool space)
472018-12-12T05:10:15Z init message: 正在加载区块索引...
482018-12-12T05:10:15Z Opening LevelDB in S:\Bitcoin\blocks\index
492018-12-12T05:10:15Z Opened LevelDB successfully
502018-12-12T05:10:15Z Using obfuscation key for S:\Bitcoin\blocks\index: 0000000000000000
512018-12-12T05:10:18Z LoadBlockIndexDB: last block file = 1459
522018-12-12T05:10:18Z LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=63, size=70173409, heights=553421...553483, time=2018-12-11...2018-12-12)
532018-12-12T05:10:18Z Checking all blk files are present...
542018-12-12T05:10:19Z Opening LevelDB in S:\Bitcoin\chainstate
552018-12-12T05:10:19Z Opened LevelDB successfully
562018-12-12T05:10:19Z Using obfuscation key for S:\Bitcoin\chainstate: d2e993e4daed8602
572018-12-12T05:10:20Z Loaded best chain: hashBestChain=000000000000000000189ffff78b77d6c408a36b99098c41fb4be2d4ff6ffceb height=553483 date=2018-12-12T04:15:40Z progress=0.999978
582018-12-12T05:10:20Z init message: 回退区块
592018-12-12T05:10:21Z init message: 正在验证区块...
602018-12-12T05:10:21Z Verifying last 6 blocks at level 3
612018-12-12T05:10:21Z [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
622018-12-12T05:10:23Z No coin database inconsistencies in last 6 blocks (8507 transactions)
632018-12-12T05:10:23Z  block index            8173ms
642018-12-12T05:10:23Z Opening LevelDB in S:\Bitcoin\indexes\txindex
652018-12-12T05:10:23Z Opened LevelDB successfully
662018-12-12T05:10:23Z Using obfuscation key for S:\Bitcoin\indexes\txindex: 0000000000000000
672018-12-12T05:10:23Z txindex thread start
682018-12-12T05:10:23Z txindex is enabled at height 553483
692018-12-12T05:10:23Z txindex thread exit
702018-12-12T05:10:23Z init message: 正在加载钱包...
712018-12-12T05:10:23Z [default wallet] nFileVersion = 170001
722018-12-12T05:10:23Z [default wallet] Keys: 0 plaintext, 4016 encrypted, 8018 w/ metadata, 4016 total. Unknown wallet records: 1
732018-12-12T05:10:23Z [default wallet] Wallet completed loading in              78ms
742018-12-12T05:10:23Z [default wallet] setKeyPool.size() = 1999
752018-12-12T05:10:23Z [default wallet] mapWallet.size() = 18
762018-12-12T05:10:23Z [default wallet] mapAddressBook.size() = 4019
772018-12-12T05:10:23Z mapBlockIndex.size() = 553488
782018-12-12T05:10:23Z nBestHeight = 553483
792018-12-12T05:10:23Z torcontrol thread start
802018-12-12T05:10:23Z upnp thread start
812018-12-12T05:10:23Z Bound to [::]:8333
822018-12-12T05:10:23Z Bound to 0.0.0.0:8333
832018-12-12T05:10:23Z init message: 正在加载P2P地址...
842018-12-12T05:10:23Z Imported mempool transactions from disk: 572 succeeded, 0 failed, 0 expired, 0 already there
852018-12-12T05:10:24Z Loaded 70317 addresses from peers.dat  203ms
862018-12-12T05:10:24Z init message: 正在加载黑名单...
872018-12-12T05:10:24Z init message: 正在启动网络线程...
882018-12-12T05:10:24Z net thread start
892018-12-12T05:10:24Z dnsseed thread start
902018-12-12T05:10:24Z addcon thread start
912018-12-12T05:10:24Z opencon thread start
922018-12-12T05:10:24Z init message: 加载完成
  6. andronoob commented at 7:51 am on December 12, 2018: none
    BTW: I came across some problem pasting the log above…😓 The log file contains Chinese charaters with different encoding - both UTF8 and GBK. When I was trying to copy them to the browser, I found that the GBK-encoded Chinese character string “远程主机强迫关闭了一个现有的连接。"(The remote host has forcibly closed an existing connection.) turned into a glitch.
  7. andronoob commented at 6:32 am on December 20, 2018: none

    @jonasschnelli This problem came up once again. The assertion came from here: https://github.com/bitcoin/bitcoin/blob/cb52cee29d0d8be062c22e59299b8e332da340c5/src/net_processing.cpp#L1186

    This time I didn’t keep Electrum Personal Server running in background.

  8. jonasschnelli commented at 7:24 am on December 20, 2018: contributor

    Looks really like a data corruption. What filesystem are you using? Is you disk attached over some sort of a NAS?

    Please try a different (internal) disk to see where the corruption comes from.

  9. andronoob commented at 10:12 am on December 20, 2018: none

    Looks really like a data corruption.

    Maybe… But I didn’t come across such problem before using blocksdir. I’m going to do reindex multiple times - with or without blocksdir - to figure out the exact reason.

    What filesystem are you using? Is you disk attached over some sort of a NAS? Please try a different (internal) disk to see where the corruption comes from.

    NTFS with BitLocker enabled. Blocks are stored in the internal HDD, while other data is stored in the internal SSD.

    Just now, I restarted bitcoin-qt.exe with -reindex -rescan, then I found Deserialize or I/O error in debug.log:

     02018-12-20T08:32:35Z init message: 正在加载P2P地址...
 12018-12-20T08:32:36Z Loaded 70571 addresses from peers.dat  251ms
 22018-12-20T08:32:36Z init message: 正在加载黑名单...
 32018-12-20T08:32:36Z init message: 正在启动网络线程...
 42018-12-20T08:32:36Z net thread start
 52018-12-20T08:32:36Z dnsseed thread start
 62018-12-20T08:32:36Z addcon thread start
 72018-12-20T08:32:36Z opencon thread start
 82018-12-20T08:32:36Z init message: 加载完成
 92018-12-20T08:32:36Z msghand thread start
102018-12-20T08:32:36Z GUI: Platform customization: "windows"
112018-12-20T08:32:36Z GUI: PaymentServer::LoadRootCAs: Loaded  119  root certificates
122018-12-20T08:32:37Z No valid UPnP IGDs found
132018-12-20T08:32:37Z upnp thread exit
142018-12-20T08:32:47Z Loading addresses from DNS seeds (could take a while)
152018-12-20T08:32:47Z New outbound peer connected: version: 70015, blocks=554598, peer=0
162018-12-20T08:32:49Z 162 addresses found from DNS seeds
172018-12-20T08:32:49Z dnsseed thread exit
182018-12-20T08:32:54Z New outbound peer connected: version: 70015, blocks=554598, peer=1
192018-12-20T08:33:00Z New outbound peer connected: version: 70015, blocks=554598, peer=3
202018-12-20T08:33:00Z LoadExternalBlockFile: Deserialize or I/O error - CBufferedFile::Fill: end of file: iostream error
212018-12-20T08:33:00Z Loaded 59344 blocks from external file in 25213ms
222018-12-20T08:33:00Z Reindexing block file blk00001.dat...
232018-12-20T08:33:02Z Reindexing block file blk00002.dat...
242018-12-20T08:33:03Z Reindexing block file blk00003.dat...
252018-12-20T08:33:05Z Reindexing block file blk00004.dat...
262018-12-20T08:33:06Z Reindexing block file blk00005.dat...

    tail of debug.log:

    02018-12-20T09:05:37Z Reindexing block file blk01468.dat...
12018-12-20T09:05:38Z Reindexing finished
22018-12-20T09:05:38Z Pre-allocating up to position 0x100000 in rev00000.dat
32018-12-20T09:06:06Z Pre-allocating up to position 0x200000 in rev00000.dat
42018-12-20T09:06:30Z Pre-allocating up to position 0x300000 in rev00000.dat
52018-12-20T09:06:47Z Pre-allocating up to position 0x400000 in rev00000.dat
62018-12-20T09:06:48Z Imported mempool transactions from disk: 3947 succeeded, 671 failed, 0 expired, 0 already there
72018-12-20T09:07:47Z Pre-allocating up to position 0x2000000 in blk00000.dat
82018-12-20T09:07:56Z Peer=9 is stalling block download, disconnecting

    Now I’m waiting for the download/sync process to complete.

  10. andronoob commented at 7:05 am on December 22, 2018: none

    @jonasschnelli 1st pass of reindex: All blkXXXXX.dat files had “last modified” timestamps of two month ago (should be the date I got initial sync done), before they got overwritten by freshly downloaded data - so does it mean that my HDD is indeedly faulted? If so, why didn’t I receive any warning/error report from Bitcoin Core during this reindex process? CrystalDiskInfo didn’t report anything wrong, either. I also found something suspicious in debug.log such as Deserialize or I/O error (pasted above), but I’m still not sure whether it is related with hardware problems. 2nd pass of reindex: Everything went smoothly, except that the weird Deserialize or I/O error appeared in debug.log again:

     02018-12-20T16:43:23Z init message: 加载完成
 12018-12-20T16:43:23Z opencon thread start
 22018-12-20T16:43:23Z msghand thread start
 32018-12-20T16:43:23Z GUI: Platform customization: "windows"
 42018-12-20T16:43:23Z GUI: PaymentServer::LoadRootCAs: Loaded  119  root certificates
 52018-12-20T16:43:25Z No valid UPnP IGDs found
 62018-12-20T16:43:25Z upnp thread exit
 72018-12-20T16:43:29Z New outbound peer connected: version: 70015, blocks=554655, peer=0
 82018-12-20T16:43:34Z Loading addresses from DNS seeds (could take a while)
 92018-12-20T16:43:36Z 161 addresses found from DNS seeds
102018-12-20T16:43:36Z dnsseed thread exit
112018-12-20T16:43:47Z LoadExternalBlockFile: Deserialize or I/O error - Read attempted past buffer limit: iostream error
122018-12-20T16:43:58Z New outbound peer connected: version: 70015, blocks=554655, peer=1
132018-12-20T16:44:11Z New outbound peer connected: version: 70015, blocks=554655, peer=2
142018-12-20T16:44:17Z Loaded 119629 blocks from external file in 54223ms
152018-12-20T16:44:17Z Reindexing block file blk00001.dat...
162018-12-20T16:44:25Z Loaded 10817 blocks from external file in 8572ms
172018-12-20T16:44:25Z Reindexing block file blk00002.dat...
182018-12-20T16:44:32Z Loaded 5880 blocks from external file in 6399ms
192018-12-20T16:44:32Z Reindexing block file blk00003.dat...
202018-12-20T16:44:38Z Loaded 5856 blocks from external file in 6496ms
212018-12-20T16:44:38Z Reindexing block file blk00004.dat...
222018-12-20T16:44:44Z Loaded 5994 blocks from external file in 6098ms
232018-12-20T16:44:44Z Reindexing block file blk00005.dat...
242018-12-20T16:44:51Z Loaded 7793 blocks from external file in 7099ms

    3rd pass of reindex: Before starting, I moved the datadir from SSD to HDD, then I made a NTFS junction link of indexes pointing to SSD. bitcoin-qt.exe was started without blocksdir. Again, everything went smoothly, Deserialize or I/O error also appeared in debug.log. 4th pass: Deleted all the block files. I made bitcoin-qt to do a initial sync from scratch. Everything went smoothly. This time no Deserialize or I/O error appeared. 5th pass of reindex: Before starting, I moved the datadir (except the blocks subdir) back to SSD. A blocksdir=path_to_hdd line was also added to bitcoin.conf. Similarly, everything went smoothly. No Deserialize or I/O error appeared.

  11. andronoob commented at 7:16 am on December 22, 2018: none
    I’ve also done read-only chkdsk on my SSD and HDD, no problem was found. BTW, A BSOD once happened to me recently, which might be the cause of data corruption.
  12. andronoob commented at 10:43 am on January 1, 2019: none
    Cannot reproduce. Closing this.
  13. andronoob closed this on Jan 1, 2019
  14. DrahtBot locked this on Dec 16, 2021


andronoob jonasschnelli

Labels
Block storage Data corruption

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-09-29 01:12 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me