From 6aefbb1aa5ff089c42b29b66bc5570880f723921 Mon Sep 17 00:00:00 2001
From: Christian Schwarz <christian@neon.tech>
Date: Fri, 26 Jan 2024 10:54:35 +0000
Subject: [PATCH] [DO NOT MERGE] more debug logging to prove hypothesis that
 it's the fsyncs

---
 libs/utils/src/crashsafe.rs | 18 +++++++++++++++++-
 libs/utils/src/lock_file.rs |  8 +++++++-
 libs/utils/src/pid_file.rs  |  5 +++++
 3 files changed, 29 insertions(+), 2 deletions(-)

diff --git a/libs/utils/src/crashsafe.rs b/libs/utils/src/crashsafe.rs
index 0c6855d17b..a251ee7055 100644
--- a/libs/utils/src/crashsafe.rs
+++ b/libs/utils/src/crashsafe.rs
@@ -5,6 +5,7 @@ use std::{
 };
 
 use camino::{Utf8Path, Utf8PathBuf};
+use tracing::info;
 
 /// Similar to [`std::fs::create_dir`], except we fsync the
 /// created directory and its parent.
@@ -81,6 +82,22 @@ pub fn path_with_suffix_extension(
     original_path.as_ref().with_extension(new_extension)
 }
 
+#[tracing::instrument(skip_all)]
+pub fn fsync_file_and_parent_log(file_path: &Utf8Path) -> io::Result<()> {
+    let parent = file_path.parent().ok_or_else(|| {
+        io::Error::new(
+            io::ErrorKind::Other,
+            format!("File {file_path:?} has no parent"),
+        )
+    })?;
+    info!("fsync file");
+    fsync(file_path)?;
+    info!("fsync parent");
+    fsync(parent)?;
+    info!("done");
+    Ok(())
+}
+
 pub fn fsync_file_and_parent(file_path: &Utf8Path) -> io::Result<()> {
     let parent = file_path.parent().ok_or_else(|| {
         io::Error::new(
@@ -88,7 +105,6 @@ pub fn fsync_file_and_parent(file_path: &Utf8Path) -> io::Result<()> {
             format!("File {file_path:?} has no parent"),
         )
     })?;
-
     fsync(file_path)?;
     fsync(parent)?;
     Ok(())
diff --git a/libs/utils/src/lock_file.rs b/libs/utils/src/lock_file.rs
index 987b9d9ad2..fe7409b973 100644
--- a/libs/utils/src/lock_file.rs
+++ b/libs/utils/src/lock_file.rs
@@ -16,6 +16,7 @@ use std::{
 use anyhow::Context;
 use camino::{Utf8Path, Utf8PathBuf};
 use nix::{errno::Errno::EAGAIN, fcntl};
+use tracing::info;
 
 use crate::crashsafe;
 
@@ -41,14 +42,19 @@ impl Deref for LockFileGuard {
 
 impl UnwrittenLockFile {
     /// Replace the content of this lock file with the byte representation of `contents`.
+    #[tracing::instrument(skip_all)]
     pub fn write_content(mut self, contents: String) -> anyhow::Result<LockFileGuard> {
+        info!("truncate");
         self.file
             .set_len(0)
             .context("Failed to truncate lockfile")?;
+        info!("write_all");
         self.file
             .write_all(contents.as_bytes())
             .with_context(|| format!("Failed to write '{contents}' contents into lockfile"))?;
-        crashsafe::fsync_file_and_parent(&self.path).context("fsync lockfile")?;
+        info!("fsync file and parent");
+        crashsafe::fsync_file_and_parent_log(&self.path).context("fsync lockfile")?;
+        info!("done");
         Ok(LockFileGuard(self.file))
     }
 }
diff --git a/libs/utils/src/pid_file.rs b/libs/utils/src/pid_file.rs
index 06f5d950d1..7479a891db 100644
--- a/libs/utils/src/pid_file.rs
+++ b/libs/utils/src/pid_file.rs
@@ -54,6 +54,7 @@ use std::ops::Deref;
 use anyhow::Context;
 use camino::Utf8Path;
 use nix::unistd::Pid;
+use tracing::info;
 
 use crate::lock_file::{self, LockFileRead};
 
@@ -85,12 +86,16 @@ impl Deref for PidFileGuard {
 /// The claim ends as soon as the returned guard object is dropped.
 /// To maintain the claim for the remaining lifetime of the current process,
 /// use [`std::mem::forget`] or similar.
+#[tracing::instrument(skip_all)]
 pub fn claim_for_current_process(path: &Utf8Path) -> anyhow::Result<PidFileGuard> {
+    info!("create_exclusive");
     let unwritten_lock_file = lock_file::create_exclusive(path).context("lock file")?;
     // if any of the next steps fail, we drop the file descriptor and thereby release the lock
+    info!("write_content");
     let guard = unwritten_lock_file
         .write_content(Pid::this().to_string())
         .context("write pid to lock file")?;
+    info!("done");
     Ok(PidFileGuard(guard))
 }