From 6f931ce46f3ba06cbf5279acf256f407a53ea36e Mon Sep 17 00:00:00 2001 From: Valentin Brandl Date: Fri, 30 Oct 2020 16:40:35 +0100 Subject: [PATCH] Use `tracing` instead of `slog` for better ergonomics --- Cargo.lock | 189 ++++++++++++++++++++++++++++++++++++++++++++++++-- Cargo.toml | 4 ++ src/cache.rs | 19 +++-- src/config.rs | 23 +----- src/count.rs | 4 +- src/main.rs | 184 ++++++++++++++++++++++++------------------------ 6 files changed, 302 insertions(+), 121 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 6366fba..9ab6e45 100644 --- a/Cargo.lock +++ b/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" -version = "0.6.14" +name = "regex-automata" +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" diff --git a/Cargo.toml b/Cargo.toml index b2e905e..40a567b 100644 --- a/Cargo.toml +++ b/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" diff --git a/src/cache.rs b/src/cache.rs index 22abc6c..df413fd 100644 --- a/src/cache.rs +++ b/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: impl AsRef + std::fmt::Debug, branch: &str, head: &str, ) -> Result> { + 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, 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) -> Result<()> { + #[instrument] + pub(crate) fn write_to_file(&self, path: impl AsRef + 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() diff --git a/src/config.rs b/src/config.rs index bfff158..c44c537 100644 --- a/src/config.rs +++ b/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()); - 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 + tracing_subscriber::fmt().init(); } diff --git a/src/count.rs b/src/count.rs index 4c56d52..4a74b27 100644 --- a/src/count.rs +++ b/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

(repo_path: P) -> Result where - P: AsRef, + P: AsRef + std::fmt::Debug, { + trace!("Counting repositories"); std::fs::create_dir_all(&repo_path)?; Ok(read_dir(repo_path)? .filter_map(StdResult::ok) diff --git a/src/main.rs b/src/main.rs index 164d551..10036a8 100644 --- a/src/main.rs +++ b/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) -> Result<()> { Ok(()) } -fn hoc( - repo: &str, - repo_dir: &str, - cache_dir: &str, - branch: &str, - logger: &Logger, -) -> Result<(u64, String, u64)> { +fn hoc(repo: &str, repo_dir: &str, cache_dir: &str, branch: &str) -> 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 - .logger - .new(o!("service" => T::domain(), "user" => data.0.clone(), "repo" => data.1.clone())); - let repo = format!( - "{}/{}/{}", - T::domain(), - data.0.to_lowercase(), - data.1.to_lowercase() + let span = info_span!( + "deleting repository and cache", + service = T::domain(), + user = data.0.as_str(), + repo = data.1.as_str() ); - info!(logger, "Deleting cache and repository"); - let cache_dir = format!("{}/{}.json", &state.cache, repo); - let repo_dir = format!("{}/{}", &state.repos, repo); - std::fs::remove_file(&cache_dir).or_else(|e| { - if e.kind() == io::ErrorKind::NotFound { - Ok(()) - } else { - Err(e) - } - })?; - std::fs::remove_dir_all(&repo_dir).or_else(|e| { - if e.kind() == io::ErrorKind::NotFound { - Ok(()) - } else { - Err(e) - } - })?; - REPO_COUNT.fetch_sub(1, Ordering::Relaxed); - Ok(HttpResponse::TemporaryRedirect() - .header( - LOCATION, - format!("/view/{}/{}/{}", T::url_path(), data.0, data.1), - ) - .finish()) + let future = async { + let repo = format!( + "{}/{}/{}", + T::domain(), + data.0.to_lowercase(), + data.1.to_lowercase() + ); + info!("Deleting cache and repository"); + let cache_dir = format!("{}/{}.json", &state.cache, repo); + let repo_dir = format!("{}/{}", &state.repos, repo); + std::fs::remove_file(&cache_dir).or_else(|e| { + if e.kind() == io::ErrorKind::NotFound { + Ok(()) + } else { + Err(e) + } + })?; + std::fs::remove_dir_all(&repo_dir).or_else(|e| { + if e.kind() == io::ErrorKind::NotFound { + Ok(()) + } else { + Err(e) + } + })?; + 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( @@ -236,44 +233,51 @@ where F: Fn(HocResult) -> Result, { let data = data.into_inner(); - let logger = state - .logger - .new(o!("service" => T::domain(), "user" => data.0.clone(), "repo" => data.1.clone(), "branch" => branch.to_string())); - let repo = format!("{}/{}", data.0.to_lowercase(), data.1.to_lowercase()); - let service_path = format!("{}/{}", T::url_path(), repo); - let service_url = format!("{}/{}", T::domain(), repo); - let path = format!("{}/{}", state.repos, service_url); - let url = format!("https://{}", service_url); - let remote_exists = remote_exists(&url).await?; - let file = Path::new(&path); - if !file.exists() { - if !remote_exists { - warn!(logger, "Repository does not exist"); - return mapper(HocResult::NotFound); + let span = info_span!( + "handling hoc calculation", + service = T::domain(), + user = data.0.as_str(), + repo = data.1.as_str(), + branch + ); + let future = async { + let repo = format!("{}/{}", data.0.to_lowercase(), data.1.to_lowercase()); + let service_path = format!("{}/{}", T::url_path(), repo); + let service_url = format!("{}/{}", T::domain(), repo); + let path = format!("{}/{}", state.repos, service_url); + let url = format!("https://{}", service_url); + 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"); - 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); - } - pull(&path)?; - let (hoc, head, commits) = hoc(&service_url, &state.repos, &state.cache, branch, &logger)?; - let hoc_pretty = match NumberPrefix::decimal(hoc as f64) { - NumberPrefix::Standalone(hoc) => hoc.to_string(), - NumberPrefix::Prefixed(prefix, hoc) => format!("{:.1}{}", hoc, prefix), + pull(&path)?; + let (hoc, head, commits) = hoc(&service_url, &state.repos, &state.cache, branch)?; + let hoc_pretty = match NumberPrefix::decimal(hoc as f64) { + NumberPrefix::Standalone(hoc) => hoc.to_string(), + NumberPrefix::Prefixed(prefix, hoc) => format!("{:.1}{}", hoc, prefix), + }; + let res = HocResult::Hoc { + hoc, + commits, + hoc_pretty, + head, + url, + repo, + service_path, + }; + mapper(res) }; - let res = HocResult::Hoc { - hoc, - commits, - hoc_pretty, - head, - url, - repo, - service_path, - }; - mapper(res) + future.instrument(span).await } pub(crate) async fn json_hoc( @@ -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( - state.logger.new(o!("log_type" => "access")), - )) + .wrap(tracing_actix_web::TracingLogger) .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::)) @@ -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(); - start_server(logger).await + config::init(); + let span = info_span!("hoc", version = env!("CARGO_PKG_VERSION")); + let _ = span.enter(); + start_server().instrument(span).await }