diff --git a/tracing/Cargo.toml b/tracing/Cargo.toml index fc66b65e22..fb53881d18 100644 --- a/tracing/Cargo.toml +++ b/tracing/Cargo.toml @@ -28,7 +28,7 @@ keywords = ["logging", "tracing", "metrics", "async"] edition = "2018" [dependencies] -tracing-core = { version = "0.1.5", path = "../tracing-core", default-features = false } +tracing-core = { version = "0.1.6", default-features = false } log = { version = "0.4", optional = true } tracing-attributes = "0.1.2" cfg-if = "0.1.9" @@ -59,6 +59,7 @@ release_max_level_trace = [] async-await = [] std = ["tracing-core/std"] +log-always = ["log"] [[bench]] name = "subscriber" diff --git a/tracing/src/lib.rs b/tracing/src/lib.rs index 3bcab355d8..1872a32b32 100644 --- a/tracing/src/lib.rs +++ b/tracing/src/lib.rs @@ -577,10 +577,16 @@ //! //! * A set of features controlling the [static verbosity level]. //! * `log`: causes trace instrumentation points to emit [`log`] records as well -//! as trace events. This is intended for use in libraries whose users may be -//! using either `tracing` or `log`. +//! as trace events, if a default `tracing` subscriber has not been set. This +//! is intended for use in libraries whose users may be using either `tracing` +//! or `log`. //! **Note:** `log` support will not work when `tracing` is renamed in `Cargo.toml`, //! due to oddities in macro expansion. +//! * `log-always`: Emit `log` records from all `tracing` spans and events, even +//! a `tracing` subscriber has been set. This should be set only by +//! applications which intend to collect traces and logs separately; if an +//! adapter is used to convert `log` records into `tracing` events, this will +//! cause duplicate events to occur. //! * `std`: Depend on the Rust standard library (enabled by default). //! //! `no_std` users may disable this feature with `default-features = false`: @@ -669,8 +675,6 @@ pub mod subscriber; pub mod __macro_support { pub use crate::stdlib::sync::atomic::{AtomicUsize, Ordering}; - pub const LOG_ENABLED: bool = cfg!(feature = "log"); - #[cfg(feature = "std")] pub use crate::stdlib::sync::Once; diff --git a/tracing/src/macros.rs b/tracing/src/macros.rs index 8dcd649cc3..806d8cb687 100644 --- a/tracing/src/macros.rs +++ b/tracing/src/macros.rs @@ -2141,9 +2141,13 @@ macro_rules! __tracing_mk_span { &$crate::valueset!(meta.fields(), $($fields)*), ) } else { - let span = $crate::Span::new_disabled(meta); - span.record_all(&$crate::valueset!(meta.fields(), $($fields)*)); - span + $crate::if_log_enabled! {{ + let span = $crate::Span::new_disabled(meta); + span.record_all(&$crate::valueset!(meta.fields(), $($fields)*)); + span + } else { + $crate::Span::none() + }} } } }; @@ -2165,9 +2169,13 @@ macro_rules! __tracing_mk_span { &$crate::valueset!(meta.fields(), $($fields)*), ) } else { - let span = $crate::Span::new_disabled(meta); - span.record_all(&$crate::valueset!(meta.fields(), $($fields)*)); - span + $crate::if_log_enabled! {{ + let span = $crate::Span::new_disabled(meta); + span.record_all(&$crate::valueset!(meta.fields(), $($fields)*)); + span + } else { + $crate::Span::none() + }} } } }; @@ -2291,23 +2299,74 @@ macro_rules! __mk_format_args { #[macro_export] macro_rules! __tracing_log { (target: $target:expr, $level:expr, $($field:tt)+ ) => { - use $crate::log; - let level = $crate::level_to_log!(&$level); - if level <= log::STATIC_MAX_LEVEL { - let log_meta = log::Metadata::builder() - .level(level) - .target($target) - .build(); - let logger = log::logger(); - if logger.enabled(&log_meta) { - logger.log(&log::Record::builder() - .file(Some(file!())) - .module_path(Some(module_path!())) - .line(Some(line!())) - .metadata(log_meta) - .args($crate::__mk_format_args!($($field)+)) - .build()); + $crate::if_log_enabled! {{ + use $crate::log; + let level = $crate::level_to_log!(&$level); + if level <= log::STATIC_MAX_LEVEL { + let log_meta = log::Metadata::builder() + .level(level) + .target($target) + .build(); + let logger = log::logger(); + if logger.enabled(&log_meta) { + logger.log(&log::Record::builder() + .file(Some(file!())) + .module_path(Some(module_path!())) + .line(Some(line!())) + .metadata(log_meta) + .args($crate::__mk_format_args!($($field)+)) + .build()); + } } + }} + }; +} + +#[cfg(not(feature = "log"))] +#[doc(hidden)] +#[macro_export] +macro_rules! if_log_enabled { + ($e:expr;) => { + $crate::if_log_enabled! {{ $e }} + }; + ($if_log:block) => { + $crate::if_log_enabled! { $if_log else {} } + }; + ($if_log:block else $else_block:block) => { + $else_block + }; +} + +#[cfg(all(feature = "log", not(feature = "log-always")))] +#[doc(hidden)] +#[macro_export] +macro_rules! if_log_enabled { + ($e:expr;) => { + $crate::if_log_enabled! {{ $e }} + }; + ($if_log:block) => { + $crate::if_log_enabled! { $if_log else {} } + }; + ($if_log:block else $else_block:block) => { + if !$crate::dispatcher::has_been_set() { + $if_log + } else { + $else_block } }; } + +#[cfg(all(feature = "log", feature = "log-always"))] +#[doc(hidden)] +#[macro_export] +macro_rules! if_log_enabled { + ($e:expr;) => { + $crate::if_log_enabled! {{ $e }} + }; + ($if_log:block) => { + $crate::if_log_enabled! { $if_log else {} } + }; + ($if_log:block else $else_block:block) => { + $if_log + }; +} diff --git a/tracing/src/span.rs b/tracing/src/span.rs index 1883bbb4a9..23cf4e35ed 100644 --- a/tracing/src/span.rs +++ b/tracing/src/span.rs @@ -505,8 +505,9 @@ impl Span { meta: Some(meta), }; - #[cfg(feature = "log")] - span.log(format_args!("++ {}; {}", meta.name(), FmtAttrs(attrs))); + if_log_enabled! {{ + span.log(format_args!("++ {}; {}", meta.name(), FmtAttrs(attrs))); + }} span } @@ -588,12 +589,11 @@ impl Span { inner.subscriber.enter(&inner.id); } - #[cfg(feature = "log")] - { + if_log_enabled! {{ if let Some(ref meta) = self.meta { self.log(format_args!("-> {}", meta.name())); } - } + }} Entered { span: self } } @@ -690,12 +690,11 @@ impl Span { inner.record(&record); } - #[cfg(feature = "log")] - { + if_log_enabled! {{ if let Some(ref meta) = self.meta { self.log(format_args!("{}; {}", meta.name(), FmtValues(&record))); } - } + }} self } @@ -839,15 +838,14 @@ impl Drop for Span { ref subscriber, }) = self.inner { - if subscriber.try_close(id.clone()) { - #[cfg(feature = "log")] - { - if let Some(ref meta) = self.meta { - self.log(format_args!("-- {}", meta.name())); - } - } - } + subscriber.try_close(id.clone()); } + + if_log_enabled!({ + if let Some(ref meta) = self.meta { + self.log(format_args!("-- {}", meta.name())); + } + }) } } @@ -924,12 +922,11 @@ impl<'a> Drop for Entered<'a> { inner.subscriber.exit(&inner.id); } - #[cfg(feature = "log")] - { + if_log_enabled! {{ if let Some(ref meta) = self.span.meta { self.span.log(format_args!("<- {}", meta.name())); } - } + }} } } diff --git a/tracing/test-log-support/Cargo.toml b/tracing/test-log-support/Cargo.toml index 54f0e22630..68675928c3 100644 --- a/tracing/test-log-support/Cargo.toml +++ b/tracing/test-log-support/Cargo.toml @@ -7,5 +7,5 @@ publish = false edition = "2018" [dependencies] -tracing = { path = "..", features = ["log"] } +tracing = { path = "..", features = ["log", "log-always"] } log = { version = "0.4", features = ["std"] } diff --git a/tracing/test-log-support/tests/log_no_trace.rs b/tracing/test-log-support/tests/log_no_trace.rs index 86c54db429..787e78ef82 100644 --- a/tracing/test-log-support/tests/log_no_trace.rs +++ b/tracing/test-log-support/tests/log_no_trace.rs @@ -29,14 +29,12 @@ fn test_always_log() { }); test.assert_logged("<- foo"); - span!(Level::TRACE, "foo", bar = 3, baz = false); + drop(foo); + test.assert_logged("-- foo"); + + + let foo = span!(Level::TRACE, "foo", bar = 3, baz = false); test.assert_logged("foo; bar=3 baz=false"); - // TODO(#1138): determine a new syntax for uninitialized span fields, and - // re-enable these. - // let span = span!(Level::TRACE, "foo", bar = _, baz = _); - // span.record("bar", &3); - // test.assert_logged("foo; bar=3"); - // span.record("baz", &"a string"); - // test.assert_logged("foo; baz=\"a string\""); + drop(foo); }