Merge pull request #338 from cbgbt/instrument-lock

improve logging in lock generation

twoliter/Cargo.toml

@@ -31,6 +31,7 @@ tar = "0.4"
 tempfile = "3"
 tokio = { version = "1", default-features = false, features = ["fs", "macros", "process", "rt-multi-thread"] }
 toml = "0.8"
+tracing = { version = "0.1", features = ["log"] }
 uuid = { version = "1", features = [ "v4" ] }
 
 # Binary dependencies. These are binaries that we want to embed in the Twoliter binary.

twoliter/src/cargo_make.rs

@@ -1,8 +1,8 @@
 use crate::common::{exec_log, BUILDSYS_OUTPUT_GENERATION_ID};
 use anyhow::{bail, Result};
-use log::trace;
 use std::path::PathBuf;
 use tokio::process::Command;
+use tracing::trace;
 
 /// A struct used to invoke `cargo make` tasks with `twoliter`'s `Makefile.toml`.
 /// ```rust

twoliter/src/common.rs

@@ -1,6 +1,7 @@
 use anyhow::{ensure, Context, Result};
-use log::{self, debug, LevelFilter};
+use log::{self, LevelFilter};
 use tokio::process::Command;
+use tracing::{debug, instrument};
 
 /// This is passed as an environment variable to Buildsys. Buildsys tells Cargo to watch this
 /// environment variable for changes. So if we have a breaking change to the way Buildsys and/or
@@ -10,6 +11,7 @@ pub(crate) const BUILDSYS_OUTPUT_GENERATION_ID: u32 = 1;
 
 /// Run a `tokio::process::Command` and return a `Result` letting us know whether or not it worked.
 /// Pipes stdout/stderr when logging `LevelFilter` is more verbose than `Warn`.
+#[instrument(level = "trace", skip(cmd))]
 pub(crate) async fn exec_log(cmd: &mut Command) -> Result<()> {
     let quiet = matches!(
         log::max_level(),
@@ -22,6 +24,7 @@ pub(crate) async fn exec_log(cmd: &mut Command) -> Result<()> {
 /// Run a `tokio::process::Command` and return a `Result` letting us know whether or not it worked.
 /// `quiet` determines whether or not the command output will be piped to `stdout/stderr`. When
 /// `quiet=true`, no output will be shown and will be returned instead.
+#[instrument(level = "trace")]
 pub(crate) async fn exec(cmd: &mut Command, quiet: bool) -> Result<Option<String>> {
     debug!("Running: {:?}", cmd);
     Ok(if quiet {
@@ -73,14 +76,21 @@ pub(crate) mod fs {
     use std::io::ErrorKind;
     use std::path::{Path, PathBuf};
     use tokio::fs;
+    use tracing::instrument;
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn canonicalize(path: impl AsRef<Path>) -> Result<PathBuf> {
         fs::canonicalize(path.as_ref()).await.context(format!(
             "Unable to canonicalize '{}'",
             path.as_ref().display()
         ))
     }
 
+    #[instrument(
+        level = "trace",
+        skip_all,
+        fields(from = %from.as_ref().display(), to = %to.as_ref().display())
+    )]
     pub(crate) async fn copy<P1, P2>(from: P1, to: P2) -> Result<u64>
     where
         P1: AsRef<Path>,
@@ -95,47 +105,54 @@ pub(crate) mod fs {
         ))
     }
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn create_dir(path: impl AsRef<Path>) -> Result<()> {
         fs::create_dir(path.as_ref()).await.context(format!(
             "Unable to create directory '{}'",
             path.as_ref().display()
         ))
     }
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn create_dir_all(path: impl AsRef<Path>) -> Result<()> {
         fs::create_dir_all(path.as_ref()).await.context(format!(
             "Unable to create directory '{}'",
             path.as_ref().display()
         ))
     }
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn metadata(path: impl AsRef<Path>) -> Result<Metadata> {
         fs::metadata(path.as_ref()).await.context(format!(
             "Unable to read metadata for '{}'",
             path.as_ref().display()
         ))
     }
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn read(path: impl AsRef<Path>) -> Result<Vec<u8>> {
         fs::read(path.as_ref())
             .await
             .context(format!("Unable to read from '{}'", path.as_ref().display()))
     }
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn read_to_string(path: impl AsRef<Path>) -> Result<String> {
         fs::read_to_string(path.as_ref()).await.context(format!(
             "Unable to read the following file as a string '{}'",
             path.as_ref().display()
         ))
     }
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn remove_dir(path: impl AsRef<Path>) -> Result<()> {
         fs::remove_dir(path.as_ref()).await.context(format!(
             "Unable to remove directory (remove_dir) '{}'",
             path.as_ref().display()
         ))
     }
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn remove_dir_all(path: impl AsRef<Path>) -> Result<()> {
         match fs::remove_dir_all(path.as_ref()).await {
             Ok(_) => Ok(()),
@@ -152,6 +169,11 @@ pub(crate) mod fs {
         }
     }
 
+    #[instrument(
+        level = "trace",
+        skip_all,
+        fields(from = %from.as_ref().display(), to = %to.as_ref().display())
+    )]
     pub(crate) async fn rename(from: impl AsRef<Path>, to: impl AsRef<Path>) -> Result<()> {
         let from = from.as_ref();
         let to = to.as_ref();
@@ -162,13 +184,15 @@ pub(crate) mod fs {
         ))
     }
 
+    #[instrument(level = "trace", skip(path), fields(path = %path.as_ref().display()))]
     pub(crate) async fn remove_file(path: impl AsRef<Path>) -> Result<()> {
         fs::remove_file(path.as_ref()).await.context(format!(
             "Unable to remove file '{}'",
             path.as_ref().display()
         ))
     }
 
+    #[instrument(level = "trace", skip_all, fields(path = %path.as_ref().display()))]
     pub(crate) async fn write<P, C>(path: P, contents: C) -> Result<()>
     where
         P: AsRef<Path>,