Add logging and error handling for file syncing #13039

laanwj · 2018-04-20T10:16:04Z

Add logging and error handling inside, and outside of FileCommit.
Functions such as fsync, fdatasync will return error in case of hardware I/O errors, and ignoring this means it can silently continue through data corruption.
(c.f. https://lwn.net/SubscriberLink/752063/12b232ab5039efbe/)

EINVAL is handled specially to avoid crashing out on (network, fuse) filesystems that don't handle f[data]sync.

I checked that the syncing inside leveldb is already generating an I/O error as appropriate.

practicalswift · 2018-04-20T12:39:24Z

Strong concept ACK! Nice!

theuni

concept ACK

theuni · 2018-04-20T14:40:23Z

src/util.cpp

+    if (fflush(file) != 0) { // harmless if redundantly called
+        LogPrintf("%s: fflush failed: %d\n", __func__, errno);
+        return false;
+    }
 #ifdef WIN32
    HANDLE hFile = (HANDLE)_get_osfhandle(_fileno(file));
    FlushFileBuffers(hFile);


This value should probably be checked as well: https://msdn.microsoft.com/en-us/library/windows/desktop/aa364439(v=vs.85).aspx

theuni · 2018-04-20T14:46:48Z

src/util.cpp

 #ifdef WIN32
    HANDLE hFile = (HANDLE)_get_osfhandle(_fileno(file));
    FlushFileBuffers(hFile);
 #else
    #if defined(__linux__) || defined(__NetBSD__)
-    fdatasync(fileno(file));
+    if (fdatasync(fileno(file)) != 0 && errno != EINVAL) { // Ignore EINVAL for filesystems that don't support sync
+        LogPrintf("%s: fdatasync failed: %d\n", __func__, errno);


I can't come up with a specific reason other than "gut feeling", but potentially logging to the same disk that just failed to sync feels icky.

That's not necessarily the case, e.g. they might be logging to stdout, or piping the log to something else over the network. Logging the error is extremely important for troubleshooting in any case, even if it might fail.

theuni · 2018-04-20T14:50:02Z

src/validation.cpp

        fclose(fileOld);
    }

    fileOld = OpenUndoFile(posOld);
    if (fileOld) {
        if (fFinalize)
            TruncateFile(fileOld, vinfoBlockFile[nLastBlockFile].nUndoSize);
-        FileCommit(fileOld);
+        flush_failed = FileCommit(fileOld);


Whoops, and the logic for these is backwards. They should be:

flush_failed |= !FileCommit(fileOld);

Ah yes this should be flush_ok

theuni · 2018-04-20T14:51:40Z

src/validation.cpp


    FILE *fileOld = OpenBlockFile(posOld);
    if (fileOld) {
        if (fFinalize)
            TruncateFile(fileOld, vinfoBlockFile[nLastBlockFile].nSize);
-        FileCommit(fileOld);
+        flush_failed = FileCommit(fileOld);
        fclose(fileOld);
    }

    fileOld = OpenUndoFile(posOld);
    if (fileOld) {
        if (fFinalize)
            TruncateFile(fileOld, vinfoBlockFile[nLastBlockFile].nUndoSize);


Wouldn't hurt to check the return value here too, but I guess it's not crucial since any error would just propagate to the sync.

theuni · 2018-04-20T14:58:50Z

src/addrdb.cpp

@@ -49,7 +49,8 @@ bool SerializeFileDB(const std::string& prefix, const fs::path& path, const Data

    // Serialize
    if (!SerializeDB(fileout, data)) return false;
-    FileCommit(fileout.Get());
+    if (!FileCommit(fileout.Get()))
+        return error("%s: Failed to flush file %s", __func__, pathTmp.string());
    fileout.fclose();


Should this attempt to close before returning? I assume we're in bad shape already if we get here, but I'm afraid that some one-off sync failure could lead to multiple copies open and weird fd behavior.

Doesn't CAutofile destructor take care of this?

yep, nevermind missed that this was a CAutofile.

theuni · 2018-04-20T14:59:47Z

src/validation.cpp


    FILE *fileOld = OpenBlockFile(posOld);
    if (fileOld) {
        if (fFinalize)
            TruncateFile(fileOld, vinfoBlockFile[nLastBlockFile].nSize);
-        FileCommit(fileOld);
+        flush_failed = FileCommit(fileOld);


See fclose comment above.

theuni · 2018-04-20T15:00:14Z

src/validation.cpp

@@ -4760,7 +4765,8 @@ bool DumpMempool(void)
        }

        file << mapDeltas;
-        FileCommit(file.Get());
+        if (!FileCommit(file.Get()))
+            throw std::runtime_error("FileCommit failed");
        file.fclose();


~~aaand here~~ :)

theuni · 2018-04-20T15:32:51Z

src/util.cpp

 #ifdef WIN32
    HANDLE hFile = (HANDLE)_get_osfhandle(_fileno(file));
    FlushFileBuffers(hFile);
 #else
    #if defined(__linux__) || defined(__NetBSD__)
-    fdatasync(fileno(file));
+    if (fdatasync(fileno(file)) != 0 && errno != EINVAL) { // Ignore EINVAL for filesystems that don't support sync


Interestingly, leveldb does not compare the result to EINVAL. Which makes sense for a database, as if writes can't be synchronized at any point, the db can't really ever be trusted.

I think we might want to operate the same way. If a FlushBlockFile() fails due to a disk/filesystem that can't sync, do we really want to continue with updating the index db?

leveldb does compare against EINVAL, we had this issue a long time ago where leveldb didn't work with certain filesystems (e.g. NTFS mounted from Linux). This was eventually fixed by adding the compare against EINVAL.
We certainly don't want to repeat this issue with the block files!

$ git grep fsync util/env_posix.cc: if (fsync(fd) < 0 && errno != EINVAL) { ``

Hmm. leveldb checks the fsync() in SyncDirIfManifest() against EINVAL, but not the fdatasync() in Sync().

I have no knowledge of the past issue though, so I'll defer to you on that.

as if writes can't be synchronized at any point, the db can't really ever be trusted.

I don't agree. When shutting down bitcoind and the OS cleanly, f(data)sync is a no-op. It's only an issue if there are sudden crashes or power outages. In which case the user will just have to accept potential corruption on crashes when choosing to use a filesystem that doesn't support these things. Certainly for the block files, which are huge and more commonly hosted externally.

My intent here is not to break any current usecases.

theuni

utACK after squash.

jonasschnelli · 2018-04-23T11:52:17Z

utACK 36424a4f09de38e1ab54381aa7844781688f5c75 (squash recommended).

Add logging and error handling inside, and outside of FileCommit. Functions such as fsync, fdatasync will return error in case of hardware I/O errors, and ignoring this means it can silently continue through data corruption. (c.f. https://lwn.net/SubscriberLink/752063/12b232ab5039efbe/)

laanwj · 2018-04-23T12:25:52Z

squashed 36424a4 → cf02779

cf02779 Add logging and error handling for file syncing (Wladimir J. van der Laan) Pull request description: Add logging and error handling inside, and outside of FileCommit. Functions such as fsync, fdatasync will return error in case of hardware I/O errors, and ignoring this means it can silently continue through data corruption. (c.f. https://lwn.net/SubscriberLink/752063/12b232ab5039efbe/) EINVAL is handled specially to avoid crashing out on (network, fuse) filesystems that don't handle `f[data]sync`. I checked that the syncing inside leveldb is already generating an I/O error as appropriate. Tree-SHA512: 64cc9bbedca3ecc97ff4bac0a7b7ac6526a7ed763c66f6786d03ca4f2e9e366e42b152cb908299c060448d98ca39ff03395280bffaca51d592e728aa2516f5dd

…+ Add file syncing logging and error handling d593e7e Migrate remaining FLATDATA serialization, we are natively supporting it now. (furszy) 051970d addrdb: Remove temporary files created in SerializeFileDB. Fixes non-determinism in unit tests. (practicalswift) 4be426f Add logging and error handling for file syncing (Wladimir J. van der Laan) 8662fb3 Remove unused double_safe_addition & double_safe_multiplication functions. (furszy) a7c3885 Add native support for serializing char arrays without FLATDATA (Pieter Wuille) 459ecb9 Deduplicate addrdb.cpp and use CHashWriter/Verifier (Pieter Wuille) a5d2f8a Fix copypasted comment. (Pavel Janík) Pull request description: Digging down the peers and ban databases commits path in upstream found some good stuff, back ported the following PRs: * bitcoin#9216. * bitcoin#10248. * bitcoin#12740. * bitcoin#13039. * bitcoin#16212. ACKs for top commit: random-zebra: ACK d593e7e Fuzzbawls: ACK d593e7e Tree-SHA512: 8d567c68a2c36f43c749d5faa4b7f8a299dbfdda133495df434ac642c1a2ac96dc2259123ad85decc9039c62c46602665f6be4aadf6d5bf729344c51692ec60e

cf02779 Add logging and error handling for file syncing (Wladimir J. van der Laan) Pull request description: Add logging and error handling inside, and outside of FileCommit. Functions such as fsync, fdatasync will return error in case of hardware I/O errors, and ignoring this means it can silently continue through data corruption. (c.f. https://lwn.net/SubscriberLink/752063/12b232ab5039efbe/) EINVAL is handled specially to avoid crashing out on (network, fuse) filesystems that don't handle `f[data]sync`. I checked that the syncing inside leveldb is already generating an I/O error as appropriate. Tree-SHA512: 64cc9bbedca3ecc97ff4bac0a7b7ac6526a7ed763c66f6786d03ca4f2e9e366e42b152cb908299c060448d98ca39ff03395280bffaca51d592e728aa2516f5dd

laanwj added the Utils/log/libs label Apr 20, 2018

laanwj force-pushed the 2018_04_fsync_noignore branch from 54299bf to 5657cc5 Compare April 20, 2018 10:17

laanwj requested review from theuni and sipa April 20, 2018 10:18

theuni reviewed Apr 20, 2018

View reviewed changes

theuni approved these changes Apr 20, 2018

View reviewed changes

laanwj force-pushed the 2018_04_fsync_noignore branch from 36424a4 to cf02779 Compare April 23, 2018 12:26

laanwj merged commit cf02779 into bitcoin:master Apr 23, 2018

Bushstar mentioned this pull request Apr 24, 2018

commits from bitcoin/master FeatherCoin/Feathercoin#307

Merged

furszy mentioned this pull request Apr 9, 2021

Addrdb code deduplication + Native support for FLATDATA + Add file syncing logging and error handling PIVX-Project/PIVX#2304

Merged

bitcoin locked as resolved and limited conversation to collaborators Sep 8, 2021

Add logging and error handling for file syncing #13039

Add logging and error handling for file syncing #13039

Uh oh!

Conversation

laanwj commented Apr 20, 2018

Uh oh!

practicalswift commented Apr 20, 2018

Uh oh!

theuni left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

theuni Apr 20, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

laanwj Apr 20, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

theuni left a comment

Choose a reason for hiding this comment

Uh oh!

jonasschnelli commented Apr 23, 2018

Uh oh!

laanwj commented Apr 23, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

theuni Apr 20, 2018 •

edited

Loading

laanwj Apr 20, 2018 •

edited

Loading

laanwj commented Apr 23, 2018 •

edited

Loading