wip: send all logs unedited to trace

core/lib/Cargo.toml

@@ -32,7 +32,7 @@ multiple_bound_locations = "allow"
 manual_range_contains = "allow"
 
 [features]
-default = ["http2", "tokio-macros"]
+default = ["http2", "tokio-macros", "trace"]
 http2 = ["hyper/http2", "hyper-util/http2"]
 http3-preview = ["s2n-quic", "s2n-quic-h3", "tls"]
 secrets = ["cookie/private", "cookie/key-expansion"]
@@ -42,6 +42,7 @@ uuid = ["uuid_", "rocket_http/uuid"]
 tls = ["rustls", "tokio-rustls", "rustls-pemfile"]
 mtls = ["tls", "x509-parser"]
 tokio-macros = ["tokio/macros"]
+trace = ["tracing-subscriber", "rustls?/logging", "tokio-rustls?/logging", "multer/log"]
 
 [dependencies]
 # Optional serialization dependencies.
@@ -77,12 +78,22 @@ indexmap = { version = "2", features = ["serde"] }
 tempfile = "3"
 async-trait = "0.1.43"
 async-stream = "0.3.2"
-multer = { version = "3.0.0", features = ["tokio-io"] }
+multer = { version = "3.1.0", features = ["tokio-io"] }
 tokio-stream = { version = "0.1.6", features = ["signal", "time"] }
 cookie = { version = "0.18", features = ["percent-encode"] }
 futures = { version = "0.3.30", default-features = false, features = ["std"] }
 state = "0.6"
 
+# tracing
+tracing = { version = "0.1.40", default-features = false, features = ["std"] }
+# tracing-futures = { version = "0.2", default-features = false, features = ["std-future"] }
+
+[dependencies.tracing-subscriber]
+version = "0.3.18"
+optional = true
+default-features = false
+features = ["fmt", "tracing-log"]
+
 [dependencies.rocket_codegen]
 version = "0.6.0-dev"
 path = "../codegen"
@@ -104,13 +115,13 @@ features = ["io"]
 [dependencies.rustls]
 version = "0.23"
 default-features = false
-features = ["ring", "logging", "std", "tls12"]
+features = ["ring", "std", "tls12"]
 optional = true
 
 [dependencies.tokio-rustls]
 version = "0.26"
 default-features = false
-features = ["logging", "tls12", "ring"]
+features = ["tls12", "ring"]
 optional = true
 
 [dependencies.rustls-pemfile]

core/lib/src/config/config.rs

@@ -374,7 +374,7 @@ impl Config {
         }
 
         launch_meta_!("shutdown: {}", self.shutdown.paint(VAL));
-        launch_meta_!("log level: {}", self.log_level.paint(VAL));
+        // launch_meta_!("log level: {}", self.log_level.paint(VAL));
         launch_meta_!("cli colors: {}", self.cli_colors.paint(VAL));
 
         // Check for now deprecated config values.

core/lib/src/lib.rs

@@ -120,6 +120,7 @@ pub use futures;
 pub use tokio;
 pub use figment;
 pub use time;
+pub use tracing;
 
 #[doc(hidden)]
 #[macro_use]

core/lib/src/rocket.rs

@@ -187,7 +187,7 @@ impl Rocket<Build> {
     pub fn custom<T: Provider>(provider: T) -> Self {
         // We initialize the logger here so that logging from fairings and so on
         // are visible; we use the final config to set a max log-level in ignite
-        // crate::log::init_default();
+        crate::trace::init(&Config::debug_default());
 
         let rocket: Rocket<Build> = Rocket(Building {
             figment: Figment::from(provider),
@@ -538,10 +538,10 @@ impl Rocket<Build> {
         self = Fairings::handle_ignite(self).await;
         self.fairings.audit().map_err(|f| ErrorKind::FailedFairings(f.to_vec()))?;
 
-        // Extract the configuration; initialize the logger.
+        // Extract the configuration; initialize default trace subscriber.
         #[allow(unused_mut)]
         let mut config = Config::try_from(&self.figment).map_err(ErrorKind::Config)?;
-        // crate::log::init(&config);
+        crate::trace::init(&config);
 
         // Check for safely configured secrets.
         #[cfg(feature = "secrets")]

core/lib/src/trace/mod.rs

@@ -0,0 +1,42 @@
+use rocket::Config;
+
+#[cfg(feature = "trace")]
+pub mod subscriber;
+
+pub trait PaintExt: Sized {
+    fn emoji(self) -> yansi::Painted<Self>;
+}
+
+impl PaintExt for &str {
+    /// Paint::masked(), but hidden on Windows due to broken output. See #1122.
+    fn emoji(self) -> yansi::Painted<Self> {
+        #[cfg(windows)] { yansi::Paint::new("").mask() }
+        #[cfg(not(windows))] { yansi::Paint::new(self).mask() }
+    }
+}
+
+macro_rules! declare_macro {
+    ($($name:ident),*) => (
+        $(declare_macro!([$] $name);)*
+    );
+
+    ([$d:tt] $name:ident) => (
+        #[macro_export]
+        macro_rules! $name {
+            ($d ($t:tt)*) => ({
+                #[allow(unused_imports)]
+                use $crate::trace::PaintExt as _;
+
+                $crate::tracing::event!($crate::tracing::Level::INFO, $d ($t)*);
+            })
+        }
+    );
+}
+
+declare_macro!(log, log_, launch_info, launch_info_, launch_meta, launch_meta_,
+    error, error_, info, info_, trace, trace_, debug, debug_, warn, warn_);
+
+pub fn init(_config: &Config) {
+    #[cfg(feature = "trace")]
+    subscriber::init(_config);
+}

core/lib/src/trace/subscriber.rs

@@ -0,0 +1,66 @@
+use std::sync::OnceLock;
+
+use tracing::{Level, Subscriber};
+use tracing::level_filters::LevelFilter;
+use tracing_subscriber::prelude::*;
+use tracing_subscriber::registry::LookupSpan;
+use tracing_subscriber::{reload, filter, Layer, Registry};
+use yansi::{Condition, Paint, Painted};
+
+use crate::Config;
+
+pub trait PaintExt: Sized {
+    fn emoji(self) -> Painted<Self>;
+}
+
+impl PaintExt for &str {
+    /// Paint::masked(), but hidden on Windows due to broken output. See #1122.
+    fn emoji(self) -> Painted<Self> {
+        #[cfg(windows)] { Paint::new("").mask() }
+        #[cfg(not(windows))] { Paint::new(self).mask() }
+    }
+}
+
+pub fn filter_layer(level: Level) -> filter::Targets {
+    filter::Targets::new()
+        .with_default(level)
+        .with_target("rustls", LevelFilter::OFF)
+        .with_target("hyper", LevelFilter::OFF)
+}
+
+pub fn fmt_layer<S: Subscriber + for<'span> LookupSpan<'span>>() -> impl Layer<S> {
+    let layer = tracing_subscriber::fmt::layer();
+
+    #[cfg(not(test))] { layer }
+    #[cfg(test)] { layer.with_test_writer() }
+}
+
+pub(crate) fn init(config: &Config) {
+    static HANDLE: OnceLock<reload::Handle<filter::Targets, Registry>> = OnceLock::new();
+
+    // FIXME: Read the true level from `config`.
+    let level = Level::INFO;
+
+    // Always disable colors if requested or if the stdout/err aren't TTYs.
+    let should_color = match config.cli_colors {
+        crate::config::CliColors::Always => Condition::ALWAYS,
+        crate::config::CliColors::Auto => Condition::DEFAULT,
+        crate::config::CliColors::Never => Condition::NEVER,
+    };
+
+    let (filter, reload_handle) = reload::Layer::new(filter_layer(level));
+    let result = tracing_subscriber::registry()
+        .with(filter)
+        .with(fmt_layer())
+        .try_init();
+
+    if result.is_ok() {
+        assert!(HANDLE.set(reload_handle).is_ok());
+        yansi::whenever(should_color);
+    } else if let Some(handle) = HANDLE.get() {
+        assert!(handle.modify(|filter| *filter = filter_layer(level)).is_ok());
+        yansi::whenever(should_color);
+    } else {
+        yansi::disable()
+    }
+}

scripts/test.sh

@@ -136,6 +136,7 @@ function test_core() {
     json
     msgpack
     uuid
+    trace
   )
 
   echo ":: Building and checking core [no features]..."