inodes: recover from corrupted sqlite database

Summary:
We've seen several cases where the sqlite database is corrupted causing EdenFS
to fail to start and requiring manual remediation. On Windows, we can always
reconstruct the sqlite database from scratch due to FSCK being able to build it
from scratch. Thus, we can simply delete the database on disk and continue
starting up.

Reviewed By: chadaustin

Differential Revision: D44155034

fbshipit-source-id: de05c814796ab8f76fd3cd9a3e98df438431c657

Author: xavierd

eden/fs/inodes/Overlay.cpp

@@ -43,20 +43,22 @@ std::unique_ptr<InodeCatalog> makeInodeCatalog(
     AbsolutePathPiece localDir,
     Overlay::InodeCatalogType inodeCatalogType,
     const EdenConfig& config,
-    IFileContentStore* fileContentStore) {
+    IFileContentStore* fileContentStore,
+    const std::shared_ptr<StructuredLogger>& logger) {
   if (inodeCatalogType == Overlay::InodeCatalogType::Tree) {
-    return std::make_unique<SqliteInodeCatalog>(localDir);
+    return std::make_unique<SqliteInodeCatalog>(localDir, logger);
   } else if (inodeCatalogType == Overlay::InodeCatalogType::TreeInMemory) {
     XLOG(WARN) << "In-memory overlay requested. This will cause data loss.";
     return std::make_unique<SqliteInodeCatalog>(
         std::make_unique<SqliteDatabase>(SqliteDatabase::inMemory));
   } else if (
       inodeCatalogType == Overlay::InodeCatalogType::TreeSynchronousOff) {
     return std::make_unique<SqliteInodeCatalog>(
-        localDir, SqliteTreeStore::SynchronousMode::Off);
+        localDir, logger, SqliteTreeStore::SynchronousMode::Off);
   } else if (inodeCatalogType == Overlay::InodeCatalogType::TreeBuffered) {
     XLOG(DBG4) << "Buffered tree overlay being used";
-    return std::make_unique<BufferedSqliteInodeCatalog>(localDir, config);
+    return std::make_unique<BufferedSqliteInodeCatalog>(
+        localDir, logger, config);
   } else if (
       inodeCatalogType == Overlay::InodeCatalogType::TreeInMemoryBuffered) {
     XLOG(WARN)
@@ -69,15 +71,15 @@ std::unique_ptr<InodeCatalog> makeInodeCatalog(
     XLOG(DBG2)
         << "Buffered tree overlay being used with synchronous-mode = off";
     return std::make_unique<BufferedSqliteInodeCatalog>(
-        localDir, config, SqliteTreeStore::SynchronousMode::Off);
+        localDir, logger, config, SqliteTreeStore::SynchronousMode::Off);
   }
 #ifdef _WIN32
   (void)fileContentStore;
   if (inodeCatalogType == Overlay::InodeCatalogType::Legacy) {
     throw std::runtime_error(
         "Legacy overlay type is not supported. Please reclone.");
   }
-  return std::make_unique<SqliteInodeCatalog>(localDir);
+  return std::make_unique<SqliteInodeCatalog>(localDir, logger);
 #else
   return std::make_unique<FsInodeCatalog>(
       static_cast<FileContentStore*>(fileContentStore));
@@ -143,7 +145,8 @@ Overlay::Overlay(
           localDir,
           inodeCatalogType,
           config,
-          fileContentStore_ ? fileContentStore_.get() : nullptr)},
+          fileContentStore_ ? fileContentStore_.get() : nullptr,
+          logger)},
       inodeCatalogType_{inodeCatalogType},
       supportsSemanticOperations_{inodeCatalog_->supportsSemanticOperations()},
       localDir_{localDir},

eden/fs/inodes/sqlitecatalog/BufferedSqliteInodeCatalog.cpp

@@ -19,11 +19,14 @@
 
 namespace facebook::eden {
 
+class StructuredLogger;
+
 BufferedSqliteInodeCatalog::BufferedSqliteInodeCatalog(
     AbsolutePathPiece path,
+    std::shared_ptr<StructuredLogger> logger,
     const EdenConfig& config,
     SqliteTreeStore::SynchronousMode mode)
-    : SqliteInodeCatalog(path, mode),
+    : SqliteInodeCatalog(path, std::move(logger), mode),
       bufferSize_{config.overlayBufferSize.getValue()} {
   workerThread_ = std::thread{[this] {
     folly::setThreadName("OverlayBuffer");

eden/fs/inodes/sqlitecatalog/BufferedSqliteInodeCatalog.h

@@ -23,11 +23,13 @@ namespace facebook::eden {
 
 struct InodeNumber;
 class EdenConfig;
+class StructuredLogger;
 
 class BufferedSqliteInodeCatalog : public SqliteInodeCatalog {
  public:
   explicit BufferedSqliteInodeCatalog(
       AbsolutePathPiece path,
+      std::shared_ptr<StructuredLogger> logger,
       const EdenConfig& config,
       SqliteTreeStore::SynchronousMode mode =
           SqliteTreeStore::SynchronousMode::Normal);

eden/fs/inodes/sqlitecatalog/SqliteInodeCatalog.cpp

@@ -15,10 +15,13 @@
 
 namespace facebook::eden {
 
+class StructuredLogger;
+
 SqliteInodeCatalog::SqliteInodeCatalog(
     AbsolutePathPiece path,
+    std::shared_ptr<StructuredLogger> logger,
     SqliteTreeStore::SynchronousMode mode)
-    : store_{path, mode} {}
+    : store_{path, std::move(logger), mode} {}
 
 std::optional<InodeNumber> SqliteInodeCatalog::initOverlay(
     bool createIfNonExisting) {

eden/fs/inodes/sqlitecatalog/SqliteInodeCatalog.h

@@ -28,11 +28,13 @@ namespace overlay {
 class OverlayDir;
 }
 struct InodeNumber;
+class StructuredLogger;
 
 class SqliteInodeCatalog : public InodeCatalog {
  public:
   explicit SqliteInodeCatalog(
       AbsolutePathPiece path,
+      std::shared_ptr<StructuredLogger> logger,
       SqliteTreeStore::SynchronousMode mode =
           SqliteTreeStore::SynchronousMode::Normal);
 

eden/fs/inodes/sqlitecatalog/SqliteTreeStore.cpp

@@ -8,11 +8,13 @@
 #include "eden/fs/inodes/sqlitecatalog/SqliteTreeStore.h"
 
 #include <folly/Range.h>
+#include <folly/stop_watch.h>
 #include <array>
 #include "eden/fs/inodes/InodeNumber.h"
 #include "eden/fs/inodes/overlay/gen-cpp2/overlay_types.h"
 #include "eden/fs/sqlite/PersistentSqliteStatement.h"
 #include "eden/fs/sqlite/SqliteStatement.h"
+#include "eden/fs/telemetry/StructuredLogger.h"
 #include "eden/fs/utils/DirType.h"
 
 namespace facebook::eden {
@@ -119,12 +121,73 @@ struct SqliteTreeStore::StatementCache {
   std::array<PersistentSqliteStatement, kBatchInsertSize> batchInsert;
 };
 
+namespace {
+std::unique_ptr<SqliteDatabase> removeAndRecreateDb(AbsolutePathPiece path) {
+  int rc = ::unlink(path.copy().c_str());
+  if (rc != 0 && errno != ENOENT) {
+    throw_<std::runtime_error>(
+        "unable to remove sqlite database ", path, ", errno: ", errno);
+  }
+  return std::make_unique<SqliteDatabase>(path);
+}
+
+std::unique_ptr<SqliteDatabase> openAndVerifyDb(
+    AbsolutePathPiece path,
+    std::shared_ptr<StructuredLogger> logger) {
+  try {
+    auto db = std::make_unique<SqliteDatabase>(path);
+
+    std::vector<std::string> errors;
+    errors.reserve(0);
+
+    folly::stop_watch<> integrityCheckRuntime;
+    {
+      auto dbLock = db->lock();
+      auto stmt = SqliteStatement(dbLock, "PRAGMA integrity_check");
+      while (stmt.step()) {
+        errors.push_back(stmt.columnBlob(0).str());
+      }
+    }
+    auto runtimeInSeconds =
+        std::chrono::duration<double>{integrityCheckRuntime.elapsed()}.count();
+
+    if (errors.empty() || (errors.size() == 1 && errors.front() == "ok")) {
+      logger->logEvent(SqliteIntegrityCheck{runtimeInSeconds, 0});
+      return db;
+    } else {
+      logger->logEvent(SqliteIntegrityCheck{
+          runtimeInSeconds, folly::to_signed(errors.size())});
+      if (folly::kIsWindows) {
+        XLOG(WARN) << "SqliteDatabase is corrupted";
+        for (auto& error : errors) {
+          XLOG(WARN) << "Sqlite error: " << error;
+        }
+        db.reset();
+        return removeAndRecreateDb(path);
+      } else {
+        throw_<std::runtime_error>("SqliteDatabase is corrupted");
+      }
+    }
+
+  } catch (const std::exception& ex) {
+    if (folly::kIsWindows) {
+      XLOG(WARN) << "SqliteDatabase (" << path
+                 << ") failed to open: " << ex.what();
+      return removeAndRecreateDb(path);
+    }
+    throw;
+  }
+}
+} // namespace
+
 SqliteTreeStore::SqliteTreeStore(
     AbsolutePathPiece path,
+    std::shared_ptr<StructuredLogger> logger,
     SqliteTreeStore::SynchronousMode synchronous_mode) {
   ensureDirectoryExists(path);
 
-  db_ = std::make_unique<SqliteDatabase>(path + kTreeStorePath);
+  AbsolutePath sqliteDbPath = path + kTreeStorePath;
+  db_ = openAndVerifyDb(sqliteDbPath, std::move(logger));
 
   // Enable WAL for faster writes to the database. See also:
   // https://www.sqlite.org/wal.html

eden/fs/inodes/sqlitecatalog/SqliteTreeStore.h

@@ -24,6 +24,7 @@ class OverlayEntry;
 } // namespace overlay
 class SqliteStatement;
 struct InodeNumber;
+class StructuredLogger;
 
 class SqliteTreeStoreNonEmptyError : public std::exception {
  public:
@@ -52,6 +53,7 @@ class SqliteTreeStore {
 
   explicit SqliteTreeStore(
       AbsolutePathPiece dir,
+      std::shared_ptr<StructuredLogger> logger,
       SqliteTreeStore::SynchronousMode mode =
           SqliteTreeStore::SynchronousMode::Normal);
 

eden/fs/inodes/sqlitecatalog/WindowsOverlayScanner.cpp

@@ -15,6 +15,7 @@
 #include "eden/fs/config/EdenConfig.h"
 #include "eden/fs/inodes/fscatalog/OverlayChecker.h"
 #include "eden/fs/inodes/sqlitecatalog/SqliteInodeCatalog.h"
+#include "eden/fs/telemetry/NullStructuredLogger.h"
 #include "eden/fs/utils/PathFuncs.h"
 #include "eden/fs/utils/WinStackTrace.h"
 
@@ -48,7 +49,8 @@ int main(int argc, char** argv) {
   auto overlayPath = canonicalPath(argv[1]);
   auto mountPath = canonicalPath(FLAGS_mount_path);
 
-  SqliteInodeCatalog inodeCatalog(overlayPath);
+  SqliteInodeCatalog inodeCatalog(
+      overlayPath, std::make_shared<NullStructuredLogger>());
   inodeCatalog.initOverlay(true);
   XLOG(INFO) << "start scanning";
   OverlayChecker::LookupCallback lookup = [](auto, auto) {

eden/fs/telemetry/LogEvent.h

@@ -344,4 +344,16 @@ struct WorkingCopyGc {
   }
 };
 
+struct SqliteIntegrityCheck {
+  static constexpr const char* type = "sqlite_integrity_check";
+
+  double duration = 0.0;
+  int64_t numErrors = 0;
+
+  void populate(DynamicEvent& event) const {
+    event.addDouble("duration", duration);
+    event.addInt("num_errors", numErrors);
+  }
+};
+
 } // namespace facebook::eden

eden/integration/corrupt_overlay_test.py

@@ -13,6 +13,8 @@
 import eden.integration.lib.overlay as overlay_mod
 from eden.integration.lib import testcase
 
+from facebook.eden.ttypes import MountState
+
 
 @testcase.eden_nfs_repo_test
 class CorruptOverlayTest(testcase.HgRepoTestMixin, testcase.EdenRepoTest):
@@ -100,3 +102,43 @@ def test_eden_list_does_not_return_corrupt_mounts(self) -> None:
 
         self.eden.start()
         self.assertEqual({str(self.mount): "NOT_RUNNING"}, self.eden.list_cmd_simple())
+
+
+@testcase.eden_repo_test
+class CorruptSqliteOverlayTest(testcase.EdenRepoTest):
+    def populate_repo(self) -> None:
+        self.repo.write_file("hello", "hola\n")
+        self.repo.write_file("dir/a", "a\n")
+        self.repo.write_file("dir/b", "b\n")
+
+        self.repo.commit("Initial commit.")
+
+    def test_integrity_corrupt_sqlite(self) -> None:
+        """Slightly corrupt the sqlite database so opening it doesn't catch the
+        corruption.
+        """
+        self.read_dir("dir")
+        self.eden.shutdown()
+
+        treestoredb = self.eden.overlay_dir_for_mount(self.mount_path) / "treestore.db"
+        size = os.stat(treestoredb).st_size
+        os.truncate(
+            self.eden.overlay_dir_for_mount(self.mount_path) / "treestore.db", size - 5
+        )
+
+        self.eden.start()
+        self.assertEqual(self.eden.get_mount_state(self.mount_path), MountState.RUNNING)
+
+    def test_full_corrupt_sqlite(self) -> None:
+        """Fully corrupt the database, opening it is sufficient to detect the corruption."""
+        self.read_dir("dir")
+        self.eden.shutdown()
+
+        treestoredb = self.eden.overlay_dir_for_mount(self.mount_path) / "treestore.db"
+        size = os.stat(treestoredb).st_size
+        os.truncate(
+            self.eden.overlay_dir_for_mount(self.mount_path) / "treestore.db", size // 2
+        )
+
+        self.eden.start()
+        self.assertEqual(self.eden.get_mount_state(self.mount_path), MountState.RUNNING)