Use tracing instead of slog for better ergonomics

Cargo.lock

@@ -337,6 +337,15 @@ dependencies = [
  "winapi 0.3.8",
 ]
 
+[[package]]
+name = "ansi_term"
+version = "0.12.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d52a9bb7ec0cf484c551830a7ce27bd20d67eac647e1befb56b0be4ee39a55d2"
+dependencies = [
+ "winapi 0.3.8",
+]
+
 [[package]]
 name = "anyhow"
 version = "1.0.26"
@@ -594,7 +603,7 @@ version = "2.33.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "5067f5bb2d80ef5d68b4c87db81601f0b75bca627bc2ef76b141d7b846a3c6d9"
 dependencies = [
- "ansi_term",
+ "ansi_term 0.11.0",
  "atty",
  "bitflags",
  "strsim",
@@ -926,6 +935,19 @@ dependencies = [
  "byteorder",
 ]
 
+[[package]]
+name = "generator"
+version = "0.6.23"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8cdc09201b2e8ca1b19290cf7e65de2246b8e91fb6874279722189c4de7b94dc"
+dependencies = [
+ "cc",
+ "libc",
+ "log",
+ "rustc_version",
+ "winapi 0.3.8",
+]
+
 [[package]]
 name = "generic-array"
 version = "0.14.4"
@@ -1024,6 +1046,10 @@ dependencies = [
  "slog-term",
  "structopt",
  "tempfile",
+ "tracing",
+ "tracing-actix-web",
+ "tracing-futures",
+ "tracing-subscriber",
  "vergen",
 ]
 
@@ -1286,6 +1312,19 @@ dependencies = [
  "cfg-if",
 ]
 
+[[package]]
+name = "loom"
+version = "0.3.6"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "a0e8460f2f2121162705187214720353c517b97bdfb3494c0b1e33d83ebe4bed"
+dependencies = [
+ "cfg-if",
+ "generator",
+ "scoped-tls",
+ "serde",
+ "serde_json",
+]
+
 [[package]]
 name = "lru-cache"
 version = "0.1.2"
@@ -1295,6 +1334,15 @@ dependencies = [
  "linked-hash-map",
 ]
 
+[[package]]
+name = "matchers"
+version = "0.0.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f099785f7595cc4b4553a174ce30dd7589ef93391ff414dbb67f62392b9e0ce1"
+dependencies = [
+ "regex-automata",
+]
+
 [[package]]
 name = "matches"
 version = "0.1.8"
@@ -1763,10 +1811,20 @@ dependencies = [
 ]
 
 [[package]]
-name = "regex-syntax"
+name = "regex-automata"
-version = "0.6.14"
+version = "0.1.9"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "b28dfe3fe9badec5dbf0a79a9cccad2cfc2ab5484bdb3e44cbd1ae8b3ba2be06"
+checksum = "ae1ded71d66a4a97f5e961fd0cb25a5f366a42a41570d16a763a69c092c26ae4"
+dependencies = [
+ "byteorder",
+ "regex-syntax",
+]
+
+[[package]]
+name = "regex-syntax"
+version = "0.6.20"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8cab7a364d15cde1e505267766a2d3c4e22a843e1a601f0fa7564c0f82ced11c"
 
 [[package]]
 name = "remove_dir_all"
@@ -1888,6 +1946,12 @@ dependencies = [
  "winapi 0.3.8",
 ]
 
+[[package]]
+name = "scoped-tls"
+version = "1.0.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ea6a9290e3c9cf0f18145ef7ffa62d68ee0bf5fcd651017e586dc7fd5da448c2"
+
 [[package]]
 name = "scopeguard"
 version = "1.1.0"
@@ -1992,6 +2056,16 @@ version = "0.6.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "2579985fda508104f7587689507983eadd6a6e84dd35d6d115361f530916fa0d"
 
+[[package]]
+name = "sharded-slab"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "7b4921be914e16899a80adefb821f8ddb7974e3f1250223575a44ed994882127"
+dependencies = [
+ "lazy_static",
+ "loom",
+]
+
 [[package]]
 name = "signal-hook-registry"
 version = "1.2.0"
@@ -2392,6 +2466,104 @@ version = "0.3.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "e987b6bf443f4b5b3b6f38704195592cca41c5bb7aedd3c3693c7081f8289860"
 
+[[package]]
+name = "tracing"
+version = "0.1.21"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b0987850db3733619253fe60e17cb59b82d37c7e6c0236bb81e4d6b87c879f27"
+dependencies = [
+ "cfg-if",
+ "pin-project-lite",
+ "tracing-attributes",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-actix-web"
+version = "0.2.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "cc36fc2f840643e49d220d07cd7ca81bc31c7f6df25f164d4257971533dab354"
+dependencies = [
+ "actix-web",
+ "futures",
+ "tracing",
+ "tracing-futures",
+ "uuid",
+]
+
+[[package]]
+name = "tracing-attributes"
+version = "0.1.11"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "80e0ccfc3378da0cce270c946b676a376943f5cd16aeba64568e7939806f4ada"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn",
+]
+
+[[package]]
+name = "tracing-core"
+version = "0.1.17"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f50de3927f93d202783f4513cda820ab47ef17f624b03c096e86ef00c67e6b5f"
+dependencies = [
+ "lazy_static",
+]
+
+[[package]]
+name = "tracing-futures"
+version = "0.2.4"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ab7bb6f14721aa00656086e9335d363c5c8747bae02ebe32ea2c7dece5689b4c"
+dependencies = [
+ "pin-project 0.4.23",
+ "tracing",
+]
+
+[[package]]
+name = "tracing-log"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5e0f8c7178e13481ff6765bd169b33e8d554c5d2bbede5e32c356194be02b9b9"
+dependencies = [
+ "lazy_static",
+ "log",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-serde"
+version = "0.1.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "fb65ea441fbb84f9f6748fd496cf7f63ec9af5bca94dd86456978d055e8eb28b"
+dependencies = [
+ "serde",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.2.14"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "2810660b9d5b18895d140caba6401765749a6a162e5d0736cfc44ea50db9d79d"
+dependencies = [
+ "ansi_term 0.12.1",
+ "chrono",
+ "lazy_static",
+ "matchers",
+ "regex",
+ "serde",
+ "serde_json",
+ "sharded-slab",
+ "smallvec",
+ "thread_local",
+ "tracing",
+ "tracing-core",
+ "tracing-log",
+ "tracing-serde",
+]
+
 [[package]]
 name = "trust-dns-proto"
 version = "0.19.5"
@@ -2506,6 +2678,15 @@ dependencies = [
  "percent-encoding",
 ]
 
+[[package]]
+name = "uuid"
+version = "0.8.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "9fde2f6a4bea1d6e007c4ad38c6839fa71cbb63b6dbf5b595aa38dc9b1093c11"
+dependencies = [
+ "rand",
+]
+
 [[package]]
 name = "vcpkg"
 version = "0.2.8"

Cargo.toml

@@ -25,6 +25,10 @@ slog-async = "2.5.0"
 slog-atomic = "3.0.0"
 slog-term = "2.6.0"
 structopt = "0.3.20"
+tracing = "0.1.21"
+tracing-subscriber = "0.2.14"
+tracing-actix-web = "0.2.1"
+tracing-futures = "0.2.4"
 
 [build-dependencies]
 ructe = "0.12.0"

src/cache.rs

@@ -8,6 +8,7 @@ use std::{
 };
 
 /// Enum to indicate the state of the cache
+#[derive(Debug)]
 pub(crate) enum CacheState<'a> {
     /// Current head and cached head are the same
     Current {
@@ -26,11 +27,13 @@ pub(crate) enum CacheState<'a> {
 }
 
 impl<'a> CacheState<'a> {
+    #[instrument]
     pub(crate) fn read_from_file(
-        path: impl AsRef<Path>,
+        path: impl AsRef<Path> + std::fmt::Debug,
         branch: &str,
         head: &str,
     ) -> Result<CacheState<'a>> {
+        trace!("Reading cache");
         if path.as_ref().exists() {
             let cache: Cache = serde_json::from_reader(BufReader::new(File::open(path)?))?;
             Ok(cache
@@ -38,6 +41,7 @@ impl<'a> CacheState<'a> {
                 .get(branch)
                 .map(|c| {
                     if c.head == head {
+                        trace!("Cache is up to date");
                         CacheState::Current {
                             count: c.count,
                             commits: c.commits,
@@ -45,6 +49,7 @@ impl<'a> CacheState<'a> {
                             cache: cache.clone(),
                         }
                     } else {
+                        trace!("Cache is out of date");
                         CacheState::Old {
                             head: c.head.to_string(),
                             // TODO: get rid of clone
@@ -59,6 +64,7 @@ impl<'a> CacheState<'a> {
         }
     }
 
+    #[instrument]
     pub(crate) fn calculate_new_cache(
         self,
         count: u64,
@@ -66,6 +72,7 @@ impl<'a> CacheState<'a> {
         head: Cow<'a, str>,
         branch: &'a str,
     ) -> Cache<'a> {
+        trace!("Calculating new cache");
         match self {
             CacheState::Old { mut cache, .. } => {
                 if let Some(mut cache) = cache.entries.get_mut(branch) {
@@ -77,6 +84,7 @@ impl<'a> CacheState<'a> {
             }
             CacheState::Current { cache, .. } => cache,
             CacheState::NoneForBranch(mut cache) => {
+                trace!("Creating new cache for branch");
                 cache.entries.insert(
                     branch.into(),
                     CacheEntry {
@@ -88,6 +96,7 @@ impl<'a> CacheState<'a> {
                 cache
             }
             CacheState::No => {
+                trace!("Creating new cache file");
                 let mut entries = HashMap::with_capacity(1);
                 entries.insert(
                     branch.into(),
@@ -103,12 +112,12 @@ impl<'a> CacheState<'a> {
     }
 }
 
-#[derive(Serialize, Deserialize, Clone)]
+#[derive(Serialize, Deserialize, Clone, Debug)]
 pub(crate) struct Cache<'a> {
     pub entries: HashMap<Cow<'a, str>, CacheEntry<'a>>,
 }
 
-#[derive(Serialize, Deserialize, Clone)]
+#[derive(Serialize, Deserialize, Clone, Debug)]
 pub(crate) struct CacheEntry<'a> {
     /// HEAD commit ref
     pub head: Cow<'a, str>,
@@ -119,7 +128,9 @@ pub(crate) struct CacheEntry<'a> {
 }
 
 impl<'a> Cache<'a> {
-    pub(crate) fn write_to_file(&self, path: impl AsRef<Path>) -> Result<()> {
+    #[instrument]
+    pub(crate) fn write_to_file(&self, path: impl AsRef<Path> + std::fmt::Debug) -> Result<()> {
+        trace!("Persisting cache to disk");
         create_dir_all(path.as_ref().parent().ok_or(Error::Internal)?)?;
         serde_json::to_writer(
             OpenOptions::new()

src/config.rs

@@ -1,5 +1,3 @@
-use slog::{Drain, Logger};
-use slog_atomic::AtomicSwitch;
 use std::path::PathBuf;
 use structopt::StructOpt;
 
@@ -33,28 +31,11 @@ pub(crate) struct Opt {
     #[structopt(short = "w", long = "workers", default_value = "4")]
     /// Number of worker threads
     pub(crate) workers: usize,
-    // #[structopt(
-    //     short = "l",
-    //     long = "logfile",
-    //     parse(from_os_str),
-    //     default_value = "./hoc.log"
-    // )]
-    // /// The logfile
-    // pub(crate) logfile: PathBuf,
 }
 
-pub(crate) fn init() -> Logger {
+pub(crate) fn init() {
     std::env::set_var("RUST_LOG", "actix_web=info,hoc=info");
     openssl_probe::init_ssl_cert_env_vars();
 
-    let decorator = slog_term::PlainDecorator::new(std::io::stdout());
+    tracing_subscriber::fmt().init();
-    let drain = slog_term::FullFormat::new(decorator).build().fuse();
-    let drain = slog_async::Async::new(drain).build().fuse();
-    let drain = AtomicSwitch::new(drain);
-
-    let root = Logger::root(drain, o!("version" => env!("CARGO_PKG_VERSION")));
-
-    info!(root, "Logging initialized");
-
-    root
 }

src/count.rs

@@ -1,10 +1,12 @@
 use crate::error::Result;
 use std::{fs::read_dir, path::Path, result::Result as StdResult};
 
+#[instrument]
 pub(crate) fn count_repositories<P>(repo_path: P) -> Result<usize>
 where
-    P: AsRef<Path>,
+    P: AsRef<Path> + std::fmt::Debug,
 {
+    trace!("Counting repositories");
     std::fs::create_dir_all(&repo_path)?;
     Ok(read_dir(repo_path)?
         .filter_map(StdResult::ok)

src/main.rs

@@ -4,12 +4,10 @@
 extern crate actix_web;
 #[macro_use]
 extern crate lazy_static;
-// #[macro_use]
-// extern crate log;
 #[macro_use]
 extern crate serde_derive;
 #[macro_use]
-extern crate slog;
+extern crate tracing;
 
 mod cache;
 mod config;
@@ -37,7 +35,6 @@ use actix_web::{
 use badge::{Badge, BadgeOptions};
 use git2::{BranchType, Repository};
 use number_prefix::NumberPrefix;
-use slog::Logger;
 use std::{
     borrow::Cow,
     fs::create_dir_all,
@@ -48,6 +45,7 @@ use std::{
     sync::Arc,
     time::{Duration, SystemTime},
 };
+use tracing::Instrument;
 
 include!(concat!(env!("OUT_DIR"), "/templates.rs"));
 
@@ -62,7 +60,6 @@ struct GeneratorForm<'a> {
 pub(crate) struct State {
     repos: String,
     cache: String,
-    logger: Logger,
 }
 
 #[derive(Serialize)]
@@ -85,13 +82,7 @@ fn pull(path: impl AsRef<Path>) -> Result<()> {
     Ok(())
 }
 
-fn hoc(
+fn hoc(repo: &str, repo_dir: &str, cache_dir: &str, branch: &str) -> Result<(u64, String, u64)> {
-    repo: &str,
-    repo_dir: &str,
-    cache_dir: &str,
-    branch: &str,
-    logger: &Logger,
-) -> Result<(u64, String, u64)> {
     let repo_dir = format!("{}/{}", repo_dir, repo);
     let cache_dir = format!("{}/{}.json", cache_dir, repo);
     let cache_dir = Path::new(&cache_dir);
@@ -118,16 +109,16 @@ fn hoc(
     let cache = CacheState::read_from_file(&cache_dir, branch, &head)?;
     match &cache {
         CacheState::Current { count, commits, .. } => {
-            info!(logger, "Using cache");
+            info!("Using cache");
             return Ok((*count, head, *commits));
         }
         CacheState::Old { head, .. } => {
-            info!(logger, "Updating cache");
+            info!("Updating cache");
             arg.push(format!("{}..{}", head, branch));
             arg_commit_count.push(format!("{}..{}", head, branch));
         }
         CacheState::No | CacheState::NoneForBranch(..) => {
-            info!(logger, "Creating cache");
+            info!("Creating cache");
             arg.push(branch.to_string());
             arg_commit_count.push(branch.to_string());
         }
@@ -190,39 +181,45 @@ where
     T: Service,
 {
     let data = data.into_inner();
-    let logger = state
+    let span = info_span!(
-        .logger
+        "deleting repository and cache",
-        .new(o!("service" => T::domain(), "user" => data.0.clone(), "repo" => data.1.clone()));
+        service = T::domain(),
-    let repo = format!(
+        user = data.0.as_str(),
-        "{}/{}/{}",
+        repo = data.1.as_str()
-        T::domain(),
-        data.0.to_lowercase(),
-        data.1.to_lowercase()
     );
-    info!(logger, "Deleting cache and repository");
+    let future = async {
-    let cache_dir = format!("{}/{}.json", &state.cache, repo);
+        let repo = format!(
-    let repo_dir = format!("{}/{}", &state.repos, repo);
+            "{}/{}/{}",
-    std::fs::remove_file(&cache_dir).or_else(|e| {
+            T::domain(),
-        if e.kind() == io::ErrorKind::NotFound {
+            data.0.to_lowercase(),
-            Ok(())
+            data.1.to_lowercase()
-        } else {
+        );
-            Err(e)
+        info!("Deleting cache and repository");
-        }
+        let cache_dir = format!("{}/{}.json", &state.cache, repo);
-    })?;
+        let repo_dir = format!("{}/{}", &state.repos, repo);
-    std::fs::remove_dir_all(&repo_dir).or_else(|e| {
+        std::fs::remove_file(&cache_dir).or_else(|e| {
-        if e.kind() == io::ErrorKind::NotFound {
+            if e.kind() == io::ErrorKind::NotFound {
-            Ok(())
+                Ok(())
-        } else {
+            } else {
-            Err(e)
+                Err(e)
-        }
+            }
-    })?;
+        })?;
-    REPO_COUNT.fetch_sub(1, Ordering::Relaxed);
+        std::fs::remove_dir_all(&repo_dir).or_else(|e| {
-    Ok(HttpResponse::TemporaryRedirect()
+            if e.kind() == io::ErrorKind::NotFound {
-        .header(
+                Ok(())
-            LOCATION,
+            } else {
-            format!("/view/{}/{}/{}", T::url_path(), data.0, data.1),
+                Err(e)
-        )
+            }
-        .finish())
+        })?;
+        REPO_COUNT.fetch_sub(1, Ordering::Relaxed);
+        Ok(HttpResponse::TemporaryRedirect()
+            .header(
+                LOCATION,
+                format!("/view/{}/{}/{}", T::url_path(), data.0, data.1),
+            )
+            .finish())
+    };
+    future.instrument(span).await
 }
 
 async fn handle_hoc_request<T, F>(
@@ -236,44 +233,51 @@ where
     F: Fn(HocResult) -> Result<HttpResponse>,
 {
     let data = data.into_inner();
-    let logger = state
+    let span = info_span!(
-        .logger
+        "handling hoc calculation",
-        .new(o!("service" => T::domain(), "user" => data.0.clone(), "repo" => data.1.clone(), "branch" => branch.to_string()));
+        service = T::domain(),
-    let repo = format!("{}/{}", data.0.to_lowercase(), data.1.to_lowercase());
+        user = data.0.as_str(),
-    let service_path = format!("{}/{}", T::url_path(), repo);
+        repo = data.1.as_str(),
-    let service_url = format!("{}/{}", T::domain(), repo);
+        branch
-    let path = format!("{}/{}", state.repos, service_url);
+    );
-    let url = format!("https://{}", service_url);
+    let future = async {
-    let remote_exists = remote_exists(&url).await?;
+        let repo = format!("{}/{}", data.0.to_lowercase(), data.1.to_lowercase());
-    let file = Path::new(&path);
+        let service_path = format!("{}/{}", T::url_path(), repo);
-    if !file.exists() {
+        let service_url = format!("{}/{}", T::domain(), repo);
-        if !remote_exists {
+        let path = format!("{}/{}", state.repos, service_url);
-            warn!(logger, "Repository does not exist");
+        let url = format!("https://{}", service_url);
-            return mapper(HocResult::NotFound);
+        let remote_exists = remote_exists(&url).await?;
+        let file = Path::new(&path);
+        if !file.exists() {
+            if !remote_exists {
+                warn!("Repository does not exist");
+                return mapper(HocResult::NotFound);
+            }
+            info!("Cloning for the first time");
+            create_dir_all(file)?;
+            let repo = Repository::init_bare(file)?;
+            repo.remote_add_fetch("origin", "refs/heads/*:refs/heads/*")?;
+            repo.remote_set_url("origin", &url)?;
+            REPO_COUNT.fetch_add(1, Ordering::Relaxed);
         }
-        info!(logger, "Cloning for the first time");
+        pull(&path)?;
-        create_dir_all(file)?;
+        let (hoc, head, commits) = hoc(&service_url, &state.repos, &state.cache, branch)?;
-        let repo = Repository::init_bare(file)?;
+        let hoc_pretty = match NumberPrefix::decimal(hoc as f64) {
-        repo.remote_add_fetch("origin", "refs/heads/*:refs/heads/*")?;
+            NumberPrefix::Standalone(hoc) => hoc.to_string(),
-        repo.remote_set_url("origin", &url)?;
+            NumberPrefix::Prefixed(prefix, hoc) => format!("{:.1}{}", hoc, prefix),
-        REPO_COUNT.fetch_add(1, Ordering::Relaxed);
+        };
-    }
+        let res = HocResult::Hoc {
-    pull(&path)?;
+            hoc,
-    let (hoc, head, commits) = hoc(&service_url, &state.repos, &state.cache, branch, &logger)?;
+            commits,
-    let hoc_pretty = match NumberPrefix::decimal(hoc as f64) {
+            hoc_pretty,
-        NumberPrefix::Standalone(hoc) => hoc.to_string(),
+            head,
-        NumberPrefix::Prefixed(prefix, hoc) => format!("{:.1}{}", hoc, prefix),
+            url,
+            repo,
+            service_path,
+        };
+        mapper(res)
     };
-    let res = HocResult::Hoc {
+    future.instrument(span).await
-        hoc,
-        commits,
-        hoc_pretty,
-        head,
-        url,
-        repo,
-        service_path,
-    };
-    mapper(res)
 }
 
 pub(crate) async fn json_hoc<T: Service>(
@@ -419,23 +423,19 @@ fn favicon32() -> HttpResponse {
     HttpResponse::Ok().content_type("image/png").body(FAVICON)
 }
 
-async fn start_server(logger: Logger) -> std::io::Result<()> {
+async fn start_server() -> std::io::Result<()> {
     let interface = format!("{}:{}", OPT.host, OPT.port);
     let state = Arc::new(State {
         repos: OPT.outdir.display().to_string(),
         cache: OPT.cachedir.display().to_string(),
-        logger,
     });
     HttpServer::new(move || {
         App::new()
             .data(state.clone())
-            .wrap(actix_slog::StructuredLogger::new(
+            .wrap(tracing_actix_web::TracingLogger)
-                state.logger.new(o!("log_type" => "access")),
-            ))
             .wrap(middleware::NormalizePath::new(TrailingSlash::Trim))
             .service(index)
             .service(web::resource("/tacit-css.min.css").route(web::get().to(css)))
-            // TODO
             .service(web::resource("/favicon.ico").route(web::get().to(favicon32)))
             .service(generate)
             .service(web::resource("/github/{user}/{repo}").to(calculate_hoc::<GitHub>))
@@ -469,6 +469,8 @@ async fn start_server(logger: Logger) -> std::io::Result<()> {
 
 #[actix_rt::main]
 async fn main() -> std::io::Result<()> {
-    let logger = config::init();
+    config::init();
-    start_server(logger).await
+    let span = info_span!("hoc", version = env!("CARGO_PKG_VERSION"));
+    let _ = span.enter();
+    start_server().instrument(span).await
 }