From 44a0b9a6516b06542d466150f2893d0329353cc1 Mon Sep 17 00:00:00 2001 From: Lucas Schwiderski Date: Thu, 23 Feb 2023 21:05:53 +0100 Subject: [PATCH] feat: Reduce clutter in release mode logging Ref #7. --- Cargo.lock | 26 +++++++++ crates/dtmm/src/main.rs | 30 +--------- crates/dtmt/src/main.rs | 17 +----- lib/dtmt-shared/Cargo.toml | 4 ++ lib/dtmt-shared/src/lib.rs | 4 ++ lib/dtmt-shared/src/log.rs | 115 +++++++++++++++++++++++++++++++++++-- 6 files changed, 147 insertions(+), 49 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 55dd12d..ef1fbb5 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -722,6 +722,10 @@ name = "dtmt-shared" version = "0.1.0" dependencies = [ "serde", + "time", + "tracing", + "tracing-error", + "tracing-subscriber", ] [[package]] @@ -1564,6 +1568,15 @@ dependencies = [ "libc", ] +[[package]] +name = "num_threads" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2819ce041d2ee131036f4fc9d6ae7ae125a3a40e97ba64d04fe799ad9dabbb44" +dependencies = [ + "libc", +] + [[package]] name = "objc" version = "0.2.7" @@ -2277,8 +2290,12 @@ version = "0.3.19" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "53250a3b3fed8ff8fd988587d8925d26a83ac3845d9e03b220b37f34c2b8d6c2" dependencies = [ + "itoa", + "libc", + "num_threads", "serde", "time-core", + "time-macros", ] [[package]] @@ -2287,6 +2304,15 @@ version = "0.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "2e153e1f1acaef8acc537e68b44906d2db6436e2b35ac2c6b42640fff91f00fd" +[[package]] +name = "time-macros" +version = "0.2.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a460aeb8de6dcb0f381e1ee05f1cd56fcf5a5f6eb8187ff3d8f0b11078d38b7c" +dependencies = [ + "time-core", +] + [[package]] name = "tinystr" version = "0.7.1" diff --git a/crates/dtmm/src/main.rs b/crates/dtmm/src/main.rs index a738fef..32c15f8 100644 --- a/crates/dtmm/src/main.rs +++ b/crates/dtmm/src/main.rs @@ -26,9 +26,6 @@ use state::ACTION_FINISH_DELETE_SELECTED_MOD; use tokio::runtime::Runtime; use tokio::sync::mpsc::UnboundedReceiver; use tokio::sync::RwLock; -use tracing_error::ErrorLayer; -use tracing_subscriber::prelude::*; -use tracing_subscriber::EnvFilter; use crate::engine::deploy_mods; use crate::state::{AsyncAction, Delegate, State, ACTION_FINISH_DEPLOY}; @@ -175,32 +172,7 @@ fn main() -> Result<()> { ) .get_matches(); - { - let filter_layer = - EnvFilter::try_from_default_env().or_else(|_| EnvFilter::try_new("info"))?; - - if cfg!(debug_assertions) { - let fmt_layer = tracing_subscriber::fmt::layer().pretty(); - - tracing_subscriber::registry() - .with(filter_layer) - .with(fmt_layer) - .with(ErrorLayer::new( - tracing_subscriber::fmt::format::Pretty::default(), - )) - .init(); - } else { - let fmt_layer = tracing_subscriber::fmt::layer().compact(); - - tracing_subscriber::registry() - .with(filter_layer) - .with(fmt_layer) - .with(ErrorLayer::new( - tracing_subscriber::fmt::format::Pretty::default(), - )) - .init(); - } - } + dtmt_shared::create_tracing_subscriber(); unsafe { oodle_sys::init(matches.get_one::("oodle")); diff --git a/crates/dtmt/src/main.rs b/crates/dtmt/src/main.rs index 830550d..dc4853e 100644 --- a/crates/dtmt/src/main.rs +++ b/crates/dtmt/src/main.rs @@ -13,9 +13,6 @@ use serde::{Deserialize, Serialize}; use tokio::fs::File; use tokio::io::BufReader; use tokio::sync::RwLock; -use tracing_error::ErrorLayer; -use tracing_subscriber::prelude::*; -use tracing_subscriber::EnvFilter; mod cmd { pub mod build; @@ -62,19 +59,7 @@ async fn main() -> Result<()> { // .subcommand(cmd::watch::command_definition()) .get_matches(); - { - let fmt_layer = tracing_subscriber::fmt::layer().pretty(); - let filter_layer = - EnvFilter::try_from_default_env().or_else(|_| EnvFilter::try_new("info"))?; - - tracing_subscriber::registry() - .with(filter_layer) - .with(fmt_layer) - .with(ErrorLayer::new( - tracing_subscriber::fmt::format::Pretty::default(), - )) - .init(); - } + dtmt_shared::create_tracing_subscriber(); // TODO: Move this into a `Context::init` method? let ctx = sdk::Context::new(); diff --git a/lib/dtmt-shared/Cargo.toml b/lib/dtmt-shared/Cargo.toml index 30daa24..0f8ed63 100644 --- a/lib/dtmt-shared/Cargo.toml +++ b/lib/dtmt-shared/Cargo.toml @@ -7,3 +7,7 @@ edition = "2021" [dependencies] serde = "1.0.152" +time = { version = "0.3.19", features = ["formatting", "local-offset", "macros"] } +tracing = "0.1.37" +tracing-error = "0.2.0" +tracing-subscriber = "0.3.16" diff --git a/lib/dtmt-shared/src/lib.rs b/lib/dtmt-shared/src/lib.rs index 592d779..6625c5b 100644 --- a/lib/dtmt-shared/src/lib.rs +++ b/lib/dtmt-shared/src/lib.rs @@ -1,3 +1,7 @@ +mod log; + +pub use log::*; + #[derive(Clone, Debug, Default, serde::Deserialize)] pub struct ModConfigResources { pub init: String, diff --git a/lib/dtmt-shared/src/log.rs b/lib/dtmt-shared/src/log.rs index 6b48375..41b015d 100644 --- a/lib/dtmt-shared/src/log.rs +++ b/lib/dtmt-shared/src/log.rs @@ -1,6 +1,113 @@ -use tracing_subscriber::fmt::format::Writer; +// Rust Analyzer cannot properly determine that `cfg!(debug_assertions)` alone does not make code +// unused. These sections should be small enough that no truly dead code slips in. -fn format_time(w: &mut Writer) -> std::fmt::Result { - let time = now_local(); - write!(w, ""); +#[allow(dead_code)] +mod prod { + use std::fmt::Result; + + use time::format_description::FormatItem; + use time::macros::format_description; + use time::OffsetDateTime; + use tracing::field::Field; + use tracing::{Event, Metadata, Subscriber}; + use tracing_error::ErrorLayer; + use tracing_subscriber::filter::FilterFn; + use tracing_subscriber::fmt::format::{debug_fn, Writer}; + use tracing_subscriber::fmt::{FmtContext, FormatEvent, FormatFields}; + use tracing_subscriber::prelude::*; + use tracing_subscriber::registry::LookupSpan; + use tracing_subscriber::EnvFilter; + + const TIME_FORMAT: &[FormatItem] = format_description!("[hour]:[minute]:[second]"); + + fn format_field(w: &mut Writer<'_>, field: &Field, val: &dyn std::fmt::Debug) -> Result { + if field.name() == "message" { + write!(w, "{:?}", val) + } else { + Ok(()) + } + } + + fn filter(metadata: &Metadata<'_>) -> bool { + metadata + .fields() + .iter() + .any(|field| field.name() == "message") + } + + struct Formatter; + + impl FormatEvent for Formatter + where + S: Subscriber + for<'a> LookupSpan<'a>, + N: for<'a> FormatFields<'a> + 'static, + { + fn format_event( + &self, + ctx: &FmtContext<'_, S, N>, + mut writer: Writer<'_>, + event: &Event<'_>, + ) -> Result { + let meta = event.metadata(); + + let time = OffsetDateTime::now_local().unwrap_or_else(|_| OffsetDateTime::now_utc()); + let time = time.format(TIME_FORMAT).map_err(|_| std::fmt::Error)?; + + write!(writer, "[{}] [{:>5}] ", time, meta.level())?; + + ctx.field_format().format_fields(writer.by_ref(), event)?; + + writeln!(writer) + } + } + + /// Creates a subscriber that + /// - only prints events that contain a message + /// - does not print fields + /// - does not print spans/targets + /// - only prints time, not date + pub fn create_tracing_subscriber() { + let filter_layer = EnvFilter::try_from_default_env() + .unwrap_or_else(|_| EnvFilter::try_new("info").unwrap()); + + let fmt_layer = tracing_subscriber::fmt::layer() + .event_format(Formatter) + .fmt_fields(debug_fn(format_field)); + + tracing_subscriber::registry() + .with(FilterFn::new(filter)) + .with(filter_layer) + .with(fmt_layer) + .with(ErrorLayer::new( + tracing_subscriber::fmt::format::Pretty::default(), + )) + .init(); + } } + +#[allow(dead_code)] +mod dev { + use tracing_error::ErrorLayer; + use tracing_subscriber::prelude::*; + use tracing_subscriber::EnvFilter; + + pub fn create_tracing_subscriber() { + let filter_layer = EnvFilter::try_from_default_env() + .unwrap_or_else(|_| EnvFilter::try_new("info").unwrap()); + let fmt_layer = tracing_subscriber::fmt::layer().pretty(); + + tracing_subscriber::registry() + .with(filter_layer) + .with(fmt_layer) + .with(ErrorLayer::new( + tracing_subscriber::fmt::format::Pretty::default(), + )) + .init(); + } +} + +#[cfg(debug_assertions)] +pub use dev::create_tracing_subscriber; + +#[cfg(not(debug_assertions))] +pub use prod::create_tracing_subscriber;