Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tracing: don't emit log events if a subscriber has been set #346

Merged
merged 7 commits into from Sep 13, 2019
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
2 changes: 1 addition & 1 deletion tracing/Cargo.toml
Expand Up @@ -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"
Expand Down
12 changes: 8 additions & 4 deletions tracing/src/lib.rs
Expand Up @@ -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`:
Expand Down Expand Up @@ -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;

Expand Down
52 changes: 36 additions & 16 deletions tracing/src/macros.rs
Expand Up @@ -2291,23 +2291,43 @@ 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());
if $crate::__tracing_should_log!() {
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(all(feature = "log", not(feature = "log-always")))]
#[doc(hidden)]
#[macro_export]
macro_rules! __tracing_should_log {
() => {
!$crate::dispatcher::has_been_set()
};
}

#[cfg(all(feature = "log", feature = "log-always"))]
#[doc(hidden)]
#[macro_export]
macro_rules! __tracing_should_log {
() => {
true
};
}
41 changes: 26 additions & 15 deletions tracing/src/span.rs
Expand Up @@ -386,6 +386,20 @@ pub struct Entered<'a> {

// ===== impl Span =====

macro_rules! if_log {
($e:expr;) => {
if_log! { $e }
};
($if_log:expr) => {
#[cfg(feature = "log")]
{
if __tracing_should_log!() {
$if_log
}
}
};
}

impl Span {
/// Constructs a new `Span` with the given [metadata] and set of
/// [field values].
Expand Down Expand Up @@ -505,8 +519,9 @@ impl Span {
meta: Some(meta),
};

#[cfg(feature = "log")]
span.log(format_args!("++ {}; {}", meta.name(), FmtAttrs(attrs)));
if_log! {
span.log(format_args!("++ {}; {}", meta.name(), FmtAttrs(attrs)));
}

span
}
Expand Down Expand Up @@ -588,8 +603,7 @@ impl Span {
inner.subscriber.enter(&inner.id);
}

#[cfg(feature = "log")]
{
if_log! {
if let Some(ref meta) = self.meta {
self.log(format_args!("-> {}", meta.name()));
}
Expand Down Expand Up @@ -690,8 +704,7 @@ impl Span {
inner.record(&record);
}

#[cfg(feature = "log")]
{
if_log! {
if let Some(ref meta) = self.meta {
self.log(format_args!("{}; {}", meta.name(), FmtValues(&record)));
}
Expand Down Expand Up @@ -839,13 +852,12 @@ 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! {
if let Some(ref meta) = self.meta {
self.log(format_args!("-- {}", meta.name()));
}
}
}
Expand Down Expand Up @@ -924,8 +936,7 @@ impl<'a> Drop for Entered<'a> {
inner.subscriber.exit(&inner.id);
}

#[cfg(feature = "log")]
{
if_log! {
if let Some(ref meta) = self.span.meta {
self.span.log(format_args!("<- {}", meta.name()));
}
Expand Down