Fake data corruption after not really running out of disk space during IBD (pruned, Windows VM on macOS) #17392

<!-- Describe the issue -->

Expected behavior

Not run out of disk space, or:

Run out of disk space, shut down. Free up disk space, start up again, continue IBD.

Actual behavior

QT says it ran out of disk space, but I suspect it was a permission issue due to the host and/or guest machine going into power saving (there was still 20 GB left).

It waited until I unlocked the computer, and only then shut down.

I reduced the prune size and started up again, and got an Error opening block database.

I freed up some space on the guest machine (I didn't realize yet that it actually had plenty). Started again, but got the same error.

I suspend the guest machine and unsuspended it and tried again. It happily continued IBD.

To reproduce

Haven't tried.

System information

Bitcoin Qt v0.19.3rc3 running on Windows 10 in a Virtual Box. Unlike #9482 I did not use a shared folder. The host machine (macOS) was locked, so it's possible some sort of power saving messd with it.

Log when "running out of space":

2019-11-05T21:59:29Z UpdateTip: new best=000000000000000000175173c6fe40dd7cd74612e7b844be0419d8eac86c8375 height=517248 version=0x20000000 log2_work=88.539759 tx=309055810 date='2018-04-08T16:27:04Z' progress=0.654537 cache=2307.7MiB(16942461txo)
2019-11-05T21:59:30Z UpdateTip: new best=0000000000000000003e0453ef04d9e17818ec3718d1811f1c0b295887828870 height=517249 version=0x20000000 log2_work=88.539807 tx=309058752 date='2018-04-08T16:54:07Z' progress=0.654543 cache=2308.0MiB(16945096txo)
2019-11-05T21:59:30Z *** Disk space is too low!
2019-11-05T21:59:30Z Error: Disk space is too low!
2019-11-05T22:19:31Z socket sending timeout: 1201s
2019-11-06T06:51:51Z ERROR: SaveBlockToDisk: FindBlockPos failed
2019-11-06T06:51:51Z ERROR: ProcessNewBlock: AcceptBlock FAILED (AcceptBlock: Failed to find position to write new block to disk (code 0))
2019-11-06T06:51:51Z ERROR: SerializeDB: Serialize or I/O error - CAutoFile::write: write failed: iostream error
2019-11-06T06:51:51Z Shutdown: In progress...
2019-11-06T06:51:51Z net thread exit
2019-11-06T06:51:51Z addcon thread exit
2019-11-06T06:51:51Z opencon thread exit
2019-11-06T06:51:52Z msghand thread exit
2019-11-06T06:51:52Z ERROR: SerializeDB: Serialize or I/O error - CAutoFile::write: write failed: iostream error
2019-11-06T06:51:52Z scheduler thread interrupt
2019-11-06T06:51:52Z Dumped mempool: 0s to copy, 0s to dump
2019-11-06T06:51:52Z CBlockPolicyEstimator::Write(): unable to write policy estimator data (non-fatal)
2019-11-06T06:51:52Z *** Disk space is too low!
2019-11-06T06:51:52Z Error: Disk space is too low!
2019-11-06T06:51:52Z ForceFlushStateToDisk: failed to flush state (Disk space is too low! (code 0))
2019-11-06T06:51:52Z *** Disk space is too low!
2019-11-06T06:51:52Z Error: Disk space is too low!
2019-11-06T06:51:52Z ForceFlushStateToDisk: failed to flush state (Disk space is too low! (code 0))
2019-11-06T06:52:04Z Shutdown: done

Note the time gap before SaveBlockToDisk, which was when I unlocked the host macOS as well as the guest Windows 10 machine.

Log upon restart. I reduced prune size, but that's generally not enough.

2019-11-06T06:52:29Z Bitcoin Core version v0.19.0rc3 (release build)
2019-11-06T06:52:29Z InitParameterInteraction: parameter interaction: -connect set -> setting -dnsseed=0
2019-11-06T06:52:29Z InitParameterInteraction: parameter interaction: -listen=0 -> setting -upnp=0
2019-11-06T06:52:29Z InitParameterInteraction: parameter interaction: -listen=0 -> setting -discover=0
2019-11-06T06:52:29Z InitParameterInteraction: parameter interaction: -listen=0 -> setting -listenonion=0
2019-11-06T06:52:30Z Assuming ancestors of block 00000000000000000005f8920febd3925f8272a6a71237563d78c2edfdd09ddf have valid signatures.
2019-11-06T06:52:30Z Setting nMinimumChainWork=000000000000000000000000000000000000000008ea3cf107ae0dec57f03fe8
2019-11-06T06:52:30Z Prune configured to target 10000 MiB on disk for block and undo files.
2019-11-06T06:52:30Z Using the 'sse4(1way),sse41(4way),avx2(8way)' SHA256 implementation
2019-11-06T06:52:30Z Using RdSeed as additional entropy source
2019-11-06T06:52:30Z Using RdRand as an additional entropy source
2019-11-06T06:52:30Z GUI: "registerShutdownBlockReason: Successfully registered: Bitcoin Core didn't yet exit safely..."
2019-11-06T06:52:30Z Default data directory C:\Users\sjors\AppData\Roaming\Bitcoin
2019-11-06T06:52:30Z Using data directory C:\Users\sjors\AppData\Roaming\Bitcoin
2019-11-06T06:52:30Z Config file: C:\Users\sjors\AppData\Roaming\Bitcoin\bitcoin.conf
2019-11-06T06:52:30Z Using at most 125 automatic connections (2048 file descriptors available)
2019-11-06T06:52:30Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2019-11-06T06:52:30Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2019-11-06T06:52:30Z Using 6 threads for script verification
2019-11-06T06:52:30Z Using wallet directory C:\Users\sjors\AppData\Roaming\Bitcoin\wallets
2019-11-06T06:52:30Z scheduler thread start
2019-11-06T06:52:30Z init message: Verifying wallet(s)...
2019-11-06T06:52:30Z init message: Loading banlist...
2019-11-06T06:52:30Z Cache configuration:
2019-11-06T06:52:30Z * Using 2.0 MiB for block index database
2019-11-06T06:52:30Z * Using 8.0 MiB for chain state database
2019-11-06T06:52:30Z * Using 6990.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space)
2019-11-06T06:52:30Z init message: Loading block index...
2019-11-06T06:52:30Z Opening LevelDB in C:\Users\sjors\AppData\Roaming\Bitcoin\blocks\index
2019-11-06T06:52:30Z Fatal LevelDB error: IO error: Win32WritableFile.Append::WriteFile: C:\Users\sjors\AppData\Roaming\Bitcoin\blocks\index\000932.ldb: There is not enough space on the disk.\x0d

2019-11-06T06:52:30Z You can use -debug=leveldb to get more complete diagnostic messages
2019-11-06T06:52:30Z Fatal LevelDB error: IO error: Win32WritableFile.Append::WriteFile: C:\Users\sjors\AppData\Roaming\Bitcoin\blocks\index\000932.ldb: There is not enough space on the disk.\x0d

2019-11-06T06:52:30Z : Error opening block database.
Please restart with -reindex or -reindex-chainstate to recover.
2019-11-06T06:52:58Z Aborted block database rebuild. Exiting.
2019-11-06T06:52:58Z Shutdown: In progress...
2019-11-06T06:52:58Z scheduler thread interrupt
2019-11-06T06:52:58Z Shutdown: done

I freed some space and tried again:

2019-11-06T06:53:27Z Bitcoin Core version v0.19.0rc3 (release build)
2019-11-06T06:53:27Z InitParameterInteraction: parameter interaction: -connect set -> setting -dnsseed=0
2019-11-06T06:53:27Z InitParameterInteraction: parameter interaction: -listen=0 -> setting -upnp=0
2019-11-06T06:53:27Z InitParameterInteraction: parameter interaction: -listen=0 -> setting -discover=0
2019-11-06T06:53:27Z InitParameterInteraction: parameter interaction: -listen=0 -> setting -listenonion=0
2019-11-06T06:53:27Z Assuming ancestors of block 00000000000000000005f8920febd3925f8272a6a71237563d78c2edfdd09ddf have valid signatures.
2019-11-06T06:53:27Z Setting nMinimumChainWork=000000000000000000000000000000000000000008ea3cf107ae0dec57f03fe8
2019-11-06T06:53:27Z Prune configured to target 10000 MiB on disk for block and undo files.
2019-11-06T06:53:27Z Using the 'sse4(1way),sse41(4way),avx2(8way)' SHA256 implementation
2019-11-06T06:53:28Z scheduler thread start
2019-11-06T06:53:36Z Aborted block database rebuild. Exiting.
2019-11-06T06:53:37Z Shutdown: In progress...
2019-11-06T06:53:37Z scheduler thread interrupt
2019-11-06T06:53:37Z Shutdown: done

2019-11-06T06:52:30Z Opening LevelDB in C:\Users\sjors\AppData\Roaming\Bitcoin\blocks\index
2019-11-06T06:52:30Z Fatal LevelDB error: IO error: > Win32WritableFile.Append::WriteFile: C:\Users\sjors\AppData\Roaming\Bitcoin\blocks\index\000932.ldb: There is not enough space on the disk.\x0d

I'm not sure the bug label is appropriate here. There's very little any software can do if the OS rejects writes to disk. (I've seen similar errors with low-level file system corruption, there might be something in your OS or kernel log about filesystem or harddisk problems)

Shouldn't it at least correctly detect that it's not allow to write to disk? Instead of telling the user to do a -reindex.

Well sure, if your issue is "the error handling on corruption or other disk issues should be more user friendly", I agree.

But if the OS falsely reports disk full and starts rejecting writes that's such a specific and strange circumstance. Software at some level needs to be able to assume to be running in a sane environment.

The other reason I reported this is that we did a bunch refactoring on the IBD code, so just want to make sure it's not a regression.

VirtualBox for example has a feature to select dynamic size growing disks. Maybe you are writing to fast to the disk and the virtualization software is not able to keep up.

Something like this was last observed two years ago, see #18301. I haven't tried to reproduce.

Going to close this for now.