telemetry: Instrument Overlay error paths with structured error logging

Summary: Logs overlay errors to perfpipe_edenfs_errors when overlay operations fail

Reviewed By: vilatto

Differential Revision: D106151434

fbshipit-source-id: a55596dc1f8d86d46a8f60eb58045809721aa20a

Author: Chandhana Solainathan

eden/fs/inodes/BUCK

@@ -166,6 +166,7 @@ cpp_library(
         "//eden/fs/service:thrift_util",
         "//eden/fs/sqlite:sqlite",
         "//eden/fs/store:backing_store_interface",
+        "//eden/fs/telemetry:error_info",
         "//eden/fs/telemetry:error_logger",
         "//eden/fs/telemetry:file_access_structured_logger",
         "//eden/fs/telemetry:fs_event_logger",

eden/fs/inodes/Overlay.cpp

@@ -35,8 +35,10 @@
 #include "eden/fs/inodes/sqlitecatalog/BufferedSqliteInodeCatalog.h"
 #include "eden/fs/inodes/sqlitecatalog/SqliteInodeCatalog.h"
 #include "eden/fs/sqlite/SqliteDatabase.h"
+#include "eden/fs/telemetry/EdenErrorInfoBuilder.h"
 #include "eden/fs/telemetry/EdenFsEventsLogger.h"
 #include "eden/fs/telemetry/EdenStats.h"
+#include "eden/fs/telemetry/ErrorLogger.h"
 #include "eden/fs/telemetry/LogEvent.h"
 
 #ifndef _WIN32
@@ -769,6 +771,7 @@ void Overlay::saveOverlayDir(
     stats_->increment(&OverlayStats::saveOverlayDirSuccessful);
   } catch (const std::exception& e) {
     XLOGF(ERR, "Failed to save overlay dir {} {}", inodeNumber, e.what());
+    errorLogger_.log(EdenErrorInfo::overlay(e, inodeNumber.get()));
     stats_->increment(&OverlayStats::saveOverlayDirFailure);
     throw;
   }
@@ -1036,6 +1039,7 @@ OverlayFile Overlay::openFile(
     return file;
   } catch (const std::exception& e) {
     XLOGF(ERR, "Failed to open file {} {} {}", inodeNumber, headerId, e.what());
+    errorLogger_.log(EdenErrorInfo::overlay(e, inodeNumber.get()));
     stats_->increment(&OverlayStats::openOverlayFileFailure);
     throw;
   }
@@ -1052,6 +1056,7 @@ OverlayFile Overlay::openFileNoVerify(InodeNumber inodeNumber) {
     return file;
   } catch (const std::exception& e) {
     XLOGF(ERR, "Failed to open file {} {}", inodeNumber, e.what());
+    errorLogger_.log(EdenErrorInfo::overlay(e, inodeNumber.get()));
     stats_->increment(&OverlayStats::openOverlayFileFailure);
     throw;
   }
@@ -1074,6 +1079,7 @@ OverlayFile Overlay::createOverlayFile(
     return file;
   } catch (const std::exception& e) {
     XLOGF(ERR, "Failed to create file {} {}", inodeNumber, e.what());
+    errorLogger_.log(EdenErrorInfo::overlay(e, inodeNumber.get()));
     stats_->increment(&OverlayStats::createOverlayFileFailure);
     throw;
   }
@@ -1096,6 +1102,7 @@ OverlayFile Overlay::createOverlayFile(
     return file;
   } catch (const std::exception& e) {
     XLOGF(ERR, "Failed to create file {} {}", inodeNumber, e.what());
+    errorLogger_.log(EdenErrorInfo::overlay(e, inodeNumber.get()));
     stats_->increment(&OverlayStats::createOverlayFileFailure);
     throw;
   }

eden/fs/inodes/OverlayFileAccess.cpp

@@ -22,6 +22,8 @@
 #include "eden/fs/inodes/OverlayFile.h"
 #include "eden/fs/inodes/TreeInode.h"
 #include "eden/fs/model/Blob.h"
+#include "eden/fs/telemetry/EdenErrorInfoBuilder.h"
+#include "eden/fs/telemetry/ErrorLogger.h"
 
 namespace facebook::eden {
 
@@ -140,6 +142,8 @@ FileOffset OverlayFileAccess::getFileSize(InodeNumber ino, InodeBase* inode) {
         "overlay file for {} is too short for header: size={}",
         ino,
         st.st_size);
+    overlay_->getErrorLogger().log(
+        EdenErrorInfo::overlay("corrupt overlay file", ino.get()));
     throw InodeError(
         EIO,
         inode ? inode->inodePtrFromThis() : InodePtr{},

eden/fs/inodes/test/BUCK

@@ -364,6 +364,7 @@ cpp_unittest(
         "//eden/fs/service:pretty_printers",
         "//eden/fs/telemetry:stats",
         "//eden/fs/telemetry:structured_logger",
+        "//eden/fs/telemetry/test:capturing_scribe_logger",
         "//eden/fs/testharness:fake_backing_store_and_tree_builder",
         "//eden/fs/testharness:test_checks",
         "//eden/fs/testharness:test_mount",

eden/fs/inodes/test/OverlayTest.cpp

@@ -38,6 +38,7 @@
 #include "eden/fs/service/PrettyPrinters.h"
 #include "eden/fs/telemetry/EdenFsEventsLogger.h"
 #include "eden/fs/telemetry/EdenStats.h"
+#include "eden/fs/telemetry/test/CapturingScribeLogger.h"
 #include "eden/fs/testharness/FakeBackingStore.h"
 #include "eden/fs/testharness/FakeTreeBuilder.h"
 #include "eden/fs/testharness/TestChecks.h"
@@ -558,6 +559,45 @@ TEST_P(RawOverlayTest, cannot_create_overlay_file_in_corrupt_overlay) {
   overlay->close();
 }
 
+TEST(OverlayErrorLoggingTest, createOverlayFileLogsErrorOnFailure) {
+  folly::test::TemporaryDirectory testDir;
+  auto scribe = std::make_shared<CapturingScribeLogger>();
+  auto edenConfig = EdenConfig::createTestEdenConfig();
+  edenConfig->enableErrorLogging.setValue(
+      true, ConfigSourceType::Default, true);
+  auto config = std::make_shared<ReloadableConfig>(edenConfig);
+  ErrorLogger errorLogger(scribe, SessionInfo{}, config);
+
+  auto overlay = Overlay::create(
+      canonicalPath(testDir.path().string()),
+      kPathMapDefaultCaseSensitive,
+      kInodeCatalogType,
+      kInodeCatalogOptions,
+      makeTestEdenFsEventsLogger(),
+      errorLogger,
+      makeRefPtr<EdenStats>(),
+      *EdenConfig::createTestEdenConfig());
+  overlay
+      ->initialize(
+          std::make_shared<ReloadableConfig>(
+              EdenConfig::createTestEdenConfig()))
+      .get();
+
+  auto ino = overlay->allocateInodeNumber();
+
+  // Remove the overlay directory to force createOverlayFile to fail
+  boost::filesystem::remove_all(testDir.path());
+
+  EXPECT_THROW(
+      overlay->createOverlayFile(ino, folly::ByteRange{"contents"_sp}),
+      std::system_error);
+
+  ASSERT_EQ(scribe->messages().size(), 1);
+  const auto& msg = scribe->messages()[0];
+  EXPECT_NE(msg.find("overlay"), std::string::npos)
+      << "Should contain overlay component, got: " << msg;
+}
+
 TEST_P(RawOverlayTest, cannot_save_overlay_dir_when_closed) {
   overlay->close();
   auto ino2 = overlay->allocateInodeNumber();