ench: use tracing for logging

Cargo.lock

@@ -32,13 +32,15 @@ dependencies = [
 [[package]]
 name = "anode-cache-common"
 version = "0.1.0"
-source = "git+https://git.dzuchun.ing/actions/cache-common-src.git#03a207d32a9b72647a5a1015b3cf63adb6d24b36"
+source = "git+https://git.dzuchun.ing/actions/cache-common-src.git#479d6fe4149b1cc4c81486fdf0eb6f6a56fc9282"
 dependencies = [
  "anyhow",
  "isahc",
  "secrecy",
  "serde_json",
  "thiserror",
+ "tracing",
+ "tracing-subscriber",
 ]
 
 [[package]]
@@ -115,6 +117,7 @@ dependencies = [
  "flate2",
  "secrecy",
  "tar",
+ "tracing",
 ]
 
 [[package]]
@@ -485,6 +488,12 @@ version = "1.0.17"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "92ecc6618181def0457392ccd0ee51198e065e016d1d527a7ac1b6dc7c1f09d2"
 
+[[package]]
+name = "lazy_static"
+version = "1.5.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe"
+
 [[package]]
 name = "libc"
 version = "0.2.182"
@@ -564,6 +573,15 @@ dependencies = [
  "simd-adler32",
 ]
 
+[[package]]
+name = "nu-ansi-term"
+version = "0.50.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5"
+dependencies = [
+ "windows-sys 0.61.2",
+]
+
 [[package]]
 name = "once_cell"
 version = "1.21.3"
@@ -774,6 +792,15 @@ dependencies = [
  "zmij",
 ]
 
+[[package]]
+name = "sharded-slab"
+version = "0.1.7"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6"
+dependencies = [
+ "lazy_static",
+]
+
 [[package]]
 name = "shlex"
 version = "1.3.0"
@@ -878,6 +905,15 @@ dependencies = [
  "syn",
 ]
 
+[[package]]
+name = "thread_local"
+version = "1.1.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185"
+dependencies = [
+ "cfg-if",
+]
+
 [[package]]
 name = "tinystr"
 version = "0.8.2"
@@ -918,6 +954,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a"
 dependencies = [
  "once_cell",
+ "valuable",
 ]
 
 [[package]]
@@ -930,6 +967,31 @@ dependencies = [
  "tracing",
 ]
 
+[[package]]
+name = "tracing-log"
+version = "0.2.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3"
+dependencies = [
+ "log",
+ "once_cell",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.3.22"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "2f30143827ddab0d256fd843b7a66d164e9f271cfa0dde49142c5ca0ca291f1e"
+dependencies = [
+ "nu-ansi-term",
+ "sharded-slab",
+ "smallvec",
+ "thread_local",
+ "tracing-core",
+ "tracing-log",
+]
+
 [[package]]
 name = "unicode-ident"
 version = "1.0.24"
@@ -960,6 +1022,12 @@ version = "1.0.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "b6c140620e7ffbb22c2dee59cafe6084a59b5ffc27a8859a5f0d494b5d52b6be"
 
+[[package]]
+name = "valuable"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65"
+
 [[package]]
 name = "vcpkg"
 version = "0.2.15"

Cargo.toml

@@ -10,6 +10,7 @@ anyhow = "1.0.101"
 flate2 = "1.1.9"
 secrecy = "0.10.3"
 tar = "0.4.44"
+tracing = { version = "0.1.44", features = ["attributes"] }
 
 [build-dependencies]
 anode-build = { git = "https://git.dzuchun.ing/dzu/anode.git", version = "0.1.0" }

src/main.rs

@@ -5,6 +5,7 @@ use anyhow::{Context, Result};
 use flate2::read::GzDecoder;
 use secrecy::ExposeSecret;
 use tar::Archive;
+use tracing::{debug, info, info_span, warn};
 
 #[derive(Debug, anode::Input)]
 #[name = "Cache load"]
@@ -21,6 +22,10 @@ struct Input {
     /// Must be in UTF-8
     #[parser(key_parser)]
     key: CacheKey,
+    /// If the debug log should be printed
+    ///
+    /// If omitted, defined by compiler settings (print debug if `debug_assertions` is enabled)
+    debug: Option<bool>,
 }
 
 #[derive(Debug, PartialEq, Clone, Copy)]
@@ -32,7 +37,9 @@ enum PathState {
 
 fn main() -> Result<()> {
     // parse inputs
-    let Input { path, key } = Input::get();
+    let Input { path, key, debug } = Input::get();
+    anode_cache_common::setup_logger(debug.unwrap_or(cfg!(debug_assertions)));
+
     let actions_token = actions_token().context("reading actions token")?;
 
     let cache_url = std::env::var("ACTIONS_CACHE_URL").context("reading action cache url")?;
@@ -40,91 +47,92 @@ fn main() -> Result<()> {
     // set up http client
     let client = Client::new(actions_token.expose_secret(), cache_url)
         .context("intializing cache client")?;
+    debug!("Cache client initialized");
 
     // download the cache archive
     let Some(cache) = client.load_cache(&key).context("loading the cache")? else {
-        println!("cache miss");
+        info!("Cache miss");
         return Ok(());
     };
     let mut cache = &*cache;
 
     let in_uncomp = GzDecoder::new(&mut cache);
     let mut archive = Archive::new(in_uncomp);
+
+    debug!(paths = ?path);
     let mut paths = path
         .into_iter()
         .map(|p| (p, PathState::Unused))
         .collect::<HashMap<_, _>>();
-    let mut entry_path = PathBuf::new();
+
-    let mut directory_path = PathBuf::new();
+    // tmp buffers
+    let mut entry_path_buf = PathBuf::new();
+    let mut directory_path_buf = PathBuf::new();
     for entry in archive.entries().context("reading cache entries")? {
         let mut entry = entry.context("reading cache entry")?;
-        entry_path.clear();
+        {
-        entry_path.push(entry.path().context("reading entry path")?.as_ref());
+            let entry_path = entry.path().context("reading entry path")?;
-        if let Some(state) = paths.get_mut(&entry_path) {
+            entry_path_buf.clear();
-            // exact match on one of cached paths
+            entry_path_buf.push(&entry_path);
+        }
+        let _span = info_span!("archive-entry", path = %entry_path_buf.display());
+        let _span = _span.enter();
+        if let Some(state) = paths.get_mut(&entry_path_buf) {
             let new_state = if entry.header().entry_type().is_dir() {
                 PathState::Directory
             } else {
                 PathState::File
             };
+            debug!(?new_state, "Exact match on one of the cached paths");
             // match on (old, new)
             match (core::mem::replace(state, new_state), new_state) {
                 (PathState::Unused, _) => {
-                    // a previously-unseen entry, unpack normally
+                    entry
-                    entry.unpack(&entry_path).context("writing cache entry")?;
+                        .unpack(&entry_path_buf)
+                        .context("writing cache entry")?;
+                    debug!("Unpacked normally");
                 }
                 (PathState::File, PathState::File) => {
-                    println!("warn: double file in the archive: {}", entry_path.display());
+                    warn!("Double file in the cache");
                 }
                 (PathState::Directory, PathState::Directory) => {
+                    debug!("Directory found again");
                     // entry could be marked as directory because of previous contained file entries; nothing to warn about here
                 }
                 (PathState::Directory, PathState::File) => {
-                    println!(
+                    warn!("A directory that was previously assumed to be a regular file");
-                        "WARN: found a directory path that was previously assumed to be a regular file: {}",
-                        directory_path.display()
-                    );
                 }
                 (PathState::File, PathState::Directory) => {
-                    println!(
+                    warn!("A regular file that was previously assumed to be a directory");
-                        "WARN: found a regular file that was previously assumed to be a directory: {}",
-                        entry_path.display()
-                    );
                 }
                 (_, PathState::Unused) => unreachable!(),
             }
-        }
+        } else if let Some(directory) = paths.keys().find(|p| entry_path_buf.starts_with(p)) {
-        if let Some(directory) = paths.keys().find(|p| entry_path.starts_with(p)) {
+            debug!(directory = %directory.display(), "File in a directory");
-            directory_path.clone_from(directory);
+            directory_path_buf.clone_from(directory);
             // file in a cached directory
             let state = paths
-                .get_mut(&directory_path)
+                .get_mut(&directory_path_buf)
                 .expect("paths should contain a path that was just extracted as a key");
             match core::mem::replace(state, PathState::Directory) {
                 PathState::Unused | PathState::Directory => {
-                    entry.unpack(&entry_path).context("writing cache entry")?;
+                    entry
+                        .unpack(&entry_path_buf)
+                        .context("writing cache entry")?;
+                    debug!("Unpacked normally");
                 }
                 PathState::File => {
-                    println!(
+                    warn!("A directory that was previously assumed to be a regular file",);
-                        "WARN: found a directory path that was previously assumed to be a regular file: {}",
-                        directory_path.display()
-                    );
                 }
             }
         } else {
-            println!(
+            warn!("Unmatched entry in the archive");
-                "warn: unmatched entry in the archive: {}",
-                entry_path.display()
-            );
         }
     }
 
     for (path, state) in paths {
         if state == PathState::Unused {
-            println!(
+            warn!(path = %path.display(), "Cached path was not found in the cache",);
-                "warn: cached path was not found in the cache: {}",
-                path.display(),
-            );
         }
     }