Integrate tracing

Signed-off-by: Alex Saveau <[email protected]>

Cargo.toml

@@ -36,4 +36,5 @@ panic = "abort"
 [profile.dr]
 inherits = "release"
 debug = true
+debug-assertions = true
 strip = false

comparisons/cp_rayon/Cargo.toml

@@ -5,4 +5,4 @@ edition.workspace = true
 publish = false
 
 [dependencies]
-rayon = "1.8.0"
+rayon = "1.8.1"

comparisons/rm_rayon/Cargo.toml

@@ -5,4 +5,4 @@ edition.workspace = true
 publish = false
 
 [dependencies]
-rayon = "1.8.0"
+rayon = "1.8.1"

cpz/Cargo.toml

@@ -14,11 +14,15 @@ clap = { version = "4.4.18", features = ["derive", "wrap_help"] }
 error-stack = "0.4.1"
 fuc_engine = { version = "1", path = "../fuc_engine" }
 thiserror = "1.0.56"
+tracing = { version = "0.1.40", features = ["release_max_level_off"], optional = true }
+tracing-subscriber = { version = "0.3.18", optional = true }
+tracing-tracy = { version = "0.11.0", features = ["flush-on-exit"], optional = true }
+tracy-client = { version = "0.17.0", optional = true }
 
 [dev-dependencies]
 cache-size = "0.6.0"
 criterion = "0.5.1"
-memmap2 = "0.9.3"
+memmap2 = "0.9.4"
 rand = "0.8.5"
 supercilex-tests = { version = "0.4.4", default-features = false, features = ["clap"] }
 tempfile = "3.9.0"
@@ -27,6 +31,9 @@ trycmd = "0.14.20"
 [target.'cfg(unix)'.dev-dependencies]
 rustix = { version = "0.38.30", features = ["fs", "pipe"] }
 
+[features]
+trace = ["fuc_engine/tracing", "dep:tracing", "dep:tracing-subscriber", "dep:tracing-tracy", "dep:tracy-client"]
+
 [[bench]]
 name = "copy_methods"
 harness = false

cpz/src/main.rs

@@ -51,15 +51,50 @@ struct Cpz {
 }
 
 #[derive(thiserror::Error, Debug)]
-pub enum CliError {
+enum CliError {
     #[error("{0}")]
     Wrapper(String),
 }
 
+#[cfg(feature = "trace")]
+#[global_allocator]
+static GLOBAL: tracy_client::ProfiledAllocator<std::alloc::System> =
+    tracy_client::ProfiledAllocator::new(std::alloc::System, 100);
+
 fn main() -> error_stack::Result<(), CliError> {
     #[cfg(not(debug_assertions))]
     error_stack::Report::install_debug_hook::<std::panic::Location>(|_, _| {});
 
+    #[cfg(feature = "trace")]
+    {
+        use tracing_subscriber::{
+            fmt::format::DefaultFields, layer::SubscriberExt, util::SubscriberInitExt,
+        };
+
+        #[derive(Default)]
+        struct Config(DefaultFields);
+
+        impl tracing_tracy::Config for Config {
+            type Formatter = DefaultFields;
+
+            fn formatter(&self) -> &Self::Formatter {
+                &self.0
+            }
+
+            fn stack_depth(&self, _: &tracing::Metadata<'_>) -> u16 {
+                32
+            }
+
+            fn format_fields_in_zone_name(&self) -> bool {
+                false
+            }
+        }
+
+        tracing_subscriber::registry()
+            .with(tracing_tracy::TracyLayer::new(Config::default()))
+            .init();
+    };
+
     let args = Cpz::parse();
 
     copy(args).map_err(|e| {

fuc_engine/Cargo.toml

@@ -12,13 +12,14 @@ license.workspace = true
 [dependencies]
 crossbeam-channel = "0.5.11"
 thiserror = "1.0.56"
+tracing = { version = "0.1.40", default-features = false, features = ["attributes"], optional = true }
 typed-builder = "0.18.1"
 
 [target.'cfg(target_os = "linux")'.dependencies]
 rustix = { version = "0.38.30", features = ["fs", "thread", "linux_latest"] }
 
 [target.'cfg(not(target_os = "linux"))'.dependencies]
-rayon = "1.8.0"
+rayon = "1.8.1"
 
 [target.'cfg(target_os = "windows")'.dependencies]
 remove_dir_all = { version = "0.8.2", features = ["parallel"] }

fuc_engine/api.golden

@@ -39,6 +39,8 @@ impl<T> core::borrow::BorrowMut<T> for fuc_engine::Error where T: core::marker::
 pub fn fuc_engine::Error::borrow_mut(&mut self) -> &mut T
 impl<T> core::convert::From<T> for fuc_engine::Error
 pub fn fuc_engine::Error::from(t: T) -> T
+impl<T> tracing::instrument::Instrument for fuc_engine::Error
+impl<T> tracing::instrument::WithSubscriber for fuc_engine::Error
 pub struct fuc_engine::CopyOp<'a, 'b, I1: core::convert::Into<alloc::borrow::Cow<'a, std::path::Path>> + 'a, I2: core::convert::Into<alloc::borrow::Cow<'b, std::path::Path>> + 'b, F: core::iter::traits::collect::IntoIterator<Item = (I1, I2)>>
 impl<'a, 'b, I1: core::convert::Into<alloc::borrow::Cow<'a, std::path::Path>> + 'a, I2: core::convert::Into<alloc::borrow::Cow<'b, std::path::Path>> + 'b, F: core::iter::traits::collect::IntoIterator<Item = (I1, I2)>> fuc_engine::CopyOp<'a, 'b, I1, I2, F>
 pub fn fuc_engine::CopyOp<'a, 'b, I1, I2, F>::run(self) -> core::result::Result<(), fuc_engine::Error>
@@ -67,6 +69,8 @@ impl<T> core::borrow::BorrowMut<T> for fuc_engine::CopyOp<'a, 'b, I1, I2, F> whe
 pub fn fuc_engine::CopyOp<'a, 'b, I1, I2, F>::borrow_mut(&mut self) -> &mut T
 impl<T> core::convert::From<T> for fuc_engine::CopyOp<'a, 'b, I1, I2, F>
 pub fn fuc_engine::CopyOp<'a, 'b, I1, I2, F>::from(t: T) -> T
+impl<T> tracing::instrument::Instrument for fuc_engine::CopyOp<'a, 'b, I1, I2, F>
+impl<T> tracing::instrument::WithSubscriber for fuc_engine::CopyOp<'a, 'b, I1, I2, F>
 pub struct fuc_engine::RemoveOp<'a, I: core::convert::Into<alloc::borrow::Cow<'a, std::path::Path>> + 'a, F: core::iter::traits::collect::IntoIterator<Item = I>>
 impl<'a, I: core::convert::Into<alloc::borrow::Cow<'a, std::path::Path>>, F: core::iter::traits::collect::IntoIterator<Item = I>> fuc_engine::RemoveOp<'a, I, F>
 pub fn fuc_engine::RemoveOp<'a, I, F>::run(self) -> core::result::Result<(), fuc_engine::Error>
@@ -95,6 +99,8 @@ impl<T> core::borrow::BorrowMut<T> for fuc_engine::RemoveOp<'a, I, F> where T: c
 pub fn fuc_engine::RemoveOp<'a, I, F>::borrow_mut(&mut self) -> &mut T
 impl<T> core::convert::From<T> for fuc_engine::RemoveOp<'a, I, F>
 pub fn fuc_engine::RemoveOp<'a, I, F>::from(t: T) -> T
+impl<T> tracing::instrument::Instrument for fuc_engine::RemoveOp<'a, I, F>
+impl<T> tracing::instrument::WithSubscriber for fuc_engine::RemoveOp<'a, I, F>
 pub fn fuc_engine::copy_file<P: core::convert::AsRef<std::path::Path>, Q: core::convert::AsRef<std::path::Path>>(from: P, to: Q) -> core::result::Result<(), fuc_engine::Error>
 pub fn fuc_engine::remove_dir_all<P: core::convert::AsRef<std::path::Path>>(path: P) -> core::result::Result<(), fuc_engine::Error>
 pub fn fuc_engine::remove_file<P: core::convert::AsRef<std::path::Path>>(path: P) -> core::result::Result<(), fuc_engine::Error>

fuc_engine/src/ops/copy.rs

@@ -56,6 +56,10 @@ impl<
     }
 }
 
+#[cfg_attr(
+    feature = "tracing",
+    tracing::instrument(level = "trace", skip(files, copy))
+)]
 fn schedule_copies<
     'a,
     'b,
@@ -184,6 +188,7 @@ mod compat {
     impl<LF: FnOnce() -> (Sender<TreeNode>, JoinHandle<Result<(), Error>>)>
         DirectoryOp<(Cow<'_, Path>, Cow<'_, Path>)> for Impl<LF>
     {
+        #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip(self)))]
         fn run(&self, (from, to): (Cow<Path>, Cow<Path>)) -> Result<(), Error> {
             let (tasks, _) = &*self.scheduling;
             tasks
@@ -195,6 +200,7 @@ mod compat {
                 .map_err(|_| Error::Internal)
         }
 
+        #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip(self)))]
         fn finish(self) -> Result<(), Error> {
             let Self { scheduling } = self;
 
@@ -206,6 +212,7 @@ mod compat {
         }
     }
 
+    #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip(tasks)))]
     fn root_worker_thread(tasks: Receiver<TreeNode>) -> Result<(), Error> {
         let mut available_parallelism = thread::available_parallelism()
             .map(NonZeroUsize::get)
@@ -238,6 +245,13 @@ mod compat {
 
                     let mut maybe_spawn = || {
                         if available_parallelism > 0 && !tasks.is_empty() {
+                            #[cfg(feature = "tracing")]
+                            tracing::event!(
+                                tracing::Level::TRACE,
+                                available_parallelism,
+                                "Spawning new thread."
+                            );
+
                             available_parallelism -= 1;
                             threads.push(scope.spawn({
                                 let tasks = tasks.clone();
@@ -264,6 +278,7 @@ mod compat {
         })
     }
 
+    #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip(tasks)))]
     fn worker_thread(tasks: Receiver<TreeNode>, root_to_inode: u64) -> Result<(), Error> {
         unshare(UnshareFlags::FILES).map_io_err(|| "Failed to unshare FD table.")?;
 
@@ -275,6 +290,10 @@ mod compat {
         Ok(())
     }
 
+    #[cfg_attr(
+        feature = "tracing",
+        tracing::instrument(level = "trace", skip(messages, buf, symlink_buf_cache, maybe_spawn))
+    )]
     fn copy_dir(
         TreeNode { from, to, messages }: TreeNode,
         root_to_inode: u64,
@@ -343,6 +362,10 @@ mod compat {
         Ok(())
     }
 
+    #[cfg_attr(
+        feature = "tracing",
+        tracing::instrument(level = "trace", skip(from_dir))
+    )]
     pub fn copy_one_dir(
         from_dir: impl AsFd,
         from_path: &CString,
@@ -361,6 +384,10 @@ mod compat {
         Ok(())
     }
 
+    #[cfg_attr(
+        feature = "tracing",
+        tracing::instrument(level = "trace", skip(from_dir, to_dir, symlink_buf_cache))
+    )]
     fn copy_one_file(
         from_dir: impl AsFd,
         to_dir: impl AsFd,
@@ -389,6 +416,10 @@ mod compat {
         }
     }
 
+    #[cfg_attr(
+        feature = "tracing",
+        tracing::instrument(level = "trace", skip(from, to))
+    )]
     fn copy_regular_file(
         from: OwnedFd,
         to: OwnedFd,
@@ -418,6 +449,10 @@ mod compat {
     }
 
     #[cold]
+    #[cfg_attr(
+        feature = "tracing",
+        tracing::instrument(level = "trace", skip(from, to))
+    )]
     fn copy_any_file(
         from: OwnedFd,
         to: OwnedFd,
@@ -434,6 +469,10 @@ mod compat {
             .map(|_| ())
     }
 
+    #[cfg_attr(
+        feature = "tracing",
+        tracing::instrument(level = "trace", skip(from_dir, to_dir))
+    )]
     fn prep_regular_file(
         from_dir: impl AsFd,
         to_dir: impl AsFd,
@@ -478,6 +517,10 @@ mod compat {
     }
 
     #[cold]
+    #[cfg_attr(
+        feature = "tracing",
+        tracing::instrument(level = "trace", skip(from_dir, to_dir, symlink_buf_cache))
+    )]
     fn copy_symlink(
         from_dir: impl AsFd,
         to_dir: impl AsFd,

fuc_engine/src/ops/mod.rs

@@ -52,10 +52,12 @@ mod linux {
         }
     }
 
+    #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace"))]
     pub fn path_buf_to_cstring(buf: PathBuf) -> Result<CString, Error> {
         CString::new(OsString::from(buf).into_vec()).map_err(|_| Error::BadPath)
     }
 
+    #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace"))]
     pub fn concat_cstrs(prefix: &CString, name: &CStr) -> CString {
         let prefix = prefix.as_bytes();
         let name = name.to_bytes_with_nul();
@@ -67,12 +69,14 @@ mod linux {
         unsafe { CString::from_vec_with_nul_unchecked(path) }
     }
 
+    #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace"))]
     pub fn join_cstr_paths(path: &CString, name: &CStr) -> PathBuf {
         Path::new(OsStr::from_bytes(path.as_bytes()))
             .join(Path::new(OsStr::from_bytes(name.to_bytes())))
     }
 
     #[cold]
+    #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip(dir)))]
     pub fn get_file_type(
         dir: impl AsFd,
         file_name: &CStr,