diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs index f3906d9bb2..d0eb5148de 100644 --- a/tracing-attributes/src/lib.rs +++ b/tracing-attributes/src/lib.rs @@ -455,39 +455,45 @@ pub fn instrument( // the future instead of the wrapper if let Some(internal_fun) = get_async_trait_info(&input.block, input.sig.asyncness.is_some()) { // let's rewrite some statements! - let mut out_stmts = Vec::with_capacity(input.block.stmts.len()); - for stmt in &input.block.stmts { - if stmt == internal_fun.source_stmt { - match internal_fun.kind { - // async-trait <= 0.1.43 - AsyncTraitKind::Function(fun) => { - out_stmts.push(gen_function( - fun, - args, - instrumented_function_name, - internal_fun.self_type, - )); - } - // async-trait >= 0.1.44 - AsyncTraitKind::Async(async_expr) => { - // fallback if we couldn't find the '__async_trait' binding, might be - // useful for crates exhibiting the same behaviors as async-trait - let instrumented_block = gen_block( - &async_expr.block, - &input.sig.inputs, - true, - args, - instrumented_function_name, - None, - ); - let async_attrs = &async_expr.attrs; - out_stmts.push(quote! { - Box::pin(#(#async_attrs) * async move { #instrumented_block }) - }); + let mut out_stmts: Vec = input + .block + .stmts + .iter() + .map(|stmt| stmt.to_token_stream()) + .collect(); + + if let Some((iter, _stmt)) = input + .block + .stmts + .iter() + .enumerate() + .find(|(_iter, stmt)| *stmt == internal_fun.source_stmt) + { + // instrument the future by rewriting the corresponding statement + out_stmts[iter] = match internal_fun.kind { + // async-trait <= 0.1.43 + AsyncTraitKind::Function(fun) => gen_function( + fun, + args, + instrumented_function_name.as_str(), + internal_fun.self_type.as_ref(), + ), + // async-trait >= 0.1.44 + AsyncTraitKind::Async(async_expr) => { + let instrumented_block = gen_block( + &async_expr.block, + &input.sig.inputs, + true, + args, + instrumented_function_name.as_str(), + None, + ); + let async_attrs = &async_expr.attrs; + quote! { + Box::pin(#(#async_attrs) * async move { #instrumented_block }) } } - break; - } + }; } let vis = &input.vis; @@ -501,7 +507,7 @@ pub fn instrument( ) .into() } else { - gen_function(&input, args, instrumented_function_name, None).into() + gen_function(&input, args, instrumented_function_name.as_str(), None).into() } } @@ -509,8 +515,8 @@ pub fn instrument( fn gen_function( input: &ItemFn, args: InstrumentArgs, - instrumented_function_name: String, - self_type: Option, + instrumented_function_name: &str, + self_type: Option<&syn::TypePath>, ) -> proc_macro2::TokenStream { // these are needed ahead of time, as ItemFn contains the function body _and_ // isn't representable inside a quote!/quote_spanned! macro @@ -568,8 +574,8 @@ fn gen_block( params: &Punctuated, async_context: bool, mut args: InstrumentArgs, - instrumented_function_name: String, - self_type: Option, + instrumented_function_name: &str, + self_type: Option<&syn::TypePath>, ) -> proc_macro2::TokenStream { let err = args.err; @@ -656,7 +662,7 @@ fn gen_block( // when async-trait <=0.1.43 is in use, replace instances // of the "Self" type inside the fields values if let Some(self_type) = self_type { - replacer.types.push(("Self", self_type)); + replacer.types.push(("Self", self_type.clone())); } for e in fields.iter_mut().filter_map(|f| f.value.as_mut()) { diff --git a/tracing-attributes/tests/async_fn.rs b/tracing-attributes/tests/async_fn.rs index 6147ced2eb..c6225c1d71 100644 --- a/tracing-attributes/tests/async_fn.rs +++ b/tracing-attributes/tests/async_fn.rs @@ -4,6 +4,7 @@ mod support; use support::*; +use std::{future::Future, pin::Pin, sync::Arc}; use tracing::subscriber::with_default; use tracing_attributes::instrument; @@ -214,6 +215,18 @@ fn async_fn_with_async_trait_and_fields_expressions_with_generic_parameter() { #[derive(Clone, Debug)] struct TestImpl; + // we also test sync functions that return futures, as they should be handled just like + // async-trait (>= 0.1.44) functions + impl TestImpl { + #[instrument(fields(Self=std::any::type_name::()))] + fn sync_fun(&self) -> Pin + Send + '_>> { + let val = self.clone(); + Box::pin(async move { + let _ = val; + }) + } + } + #[async_trait] impl Test for TestImpl { // instrumenting this is currently not possible, see https://github.com/tokio-rs/tracing/issues/864#issuecomment-667508801 @@ -221,7 +234,9 @@ fn async_fn_with_async_trait_and_fields_expressions_with_generic_parameter() { async fn call() {} #[instrument(fields(Self=std::any::type_name::()))] - async fn call_with_self(&self) {} + async fn call_with_self(&self) { + self.sync_fun().await; + } #[instrument(fields(Self=std::any::type_name::()))] async fn call_with_mut_self(&mut self) {} @@ -230,6 +245,7 @@ fn async_fn_with_async_trait_and_fields_expressions_with_generic_parameter() { //let span = span::mock().named("call"); let span2 = span::mock().named("call_with_self"); let span3 = span::mock().named("call_with_mut_self"); + let span4 = span::mock().named("sync_fun"); let (subscriber, handle) = subscriber::mock() /*.new_span(span.clone() .with_field( @@ -243,6 +259,13 @@ fn async_fn_with_async_trait_and_fields_expressions_with_generic_parameter() { .with_field(field::mock("Self").with_value(&std::any::type_name::())), ) .enter(span2.clone()) + .new_span( + span4 + .clone() + .with_field(field::mock("Self").with_value(&std::any::type_name::())), + ) + .enter(span4.clone()) + .exit(span4) .exit(span2.clone()) .drop_span(span2) .new_span( @@ -266,3 +289,45 @@ fn async_fn_with_async_trait_and_fields_expressions_with_generic_parameter() { handle.assert_finished(); } + +#[test] +fn out_of_scope_fields() { + // Reproduces tokio-rs/tracing#1296 + + struct Thing { + metrics: Arc<()>, + } + + impl Thing { + #[instrument(skip(self, _req), fields(app_id))] + fn call(&mut self, _req: ()) -> Pin> + Send + Sync>> { + // ... + let metrics = self.metrics.clone(); + // ... + Box::pin(async move { + // ... + metrics // cannot find value `metrics` in this scope + }) + } + } + + let span = span::mock().named("call"); + let (subscriber, handle) = subscriber::mock() + .new_span(span.clone()) + .enter(span.clone()) + .exit(span.clone()) + .drop_span(span) + .done() + .run_with_handle(); + + with_default(subscriber, || { + block_on_future(async { + let mut my_thing = Thing { + metrics: Arc::new(()), + }; + my_thing.call(()).await; + }); + }); + + handle.assert_finished(); +} diff --git a/tracing-subscriber/src/fmt/fmt_layer.rs b/tracing-subscriber/src/fmt/fmt_layer.rs index 3918fe0126..e2040b4a91 100644 --- a/tracing-subscriber/src/fmt/fmt_layer.rs +++ b/tracing-subscriber/src/fmt/fmt_layer.rs @@ -8,7 +8,7 @@ use format::{FmtSpan, TimingDisplay}; use std::{any::TypeId, cell::RefCell, fmt, io, marker::PhantomData, ops::Deref, time::Instant}; use tracing_core::{ field, - span::{Attributes, Id, Record}, + span::{Attributes, Current, Id, Record}, Event, Metadata, Subscriber, }; @@ -259,18 +259,33 @@ where /// - `FmtSpan::NONE`: No events will be synthesized when spans are /// created, entered, exited, or closed. Data from spans will still be /// included as the context for formatted events. This is the default. - /// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered - /// or exited. + /// - `FmtSpan::NEW`: An event will be synthesized when spans are created. + /// - `FmtSpan::ENTER`: An event will be synthesized when spans are entered. + /// - `FmtSpan::EXIT`: An event will be synthesized when spans are exited. /// - `FmtSpan::CLOSE`: An event will be synthesized when a span closes. If /// [timestamps are enabled][time] for this formatter, the generated /// event will contain fields with the span's _busy time_ (the total /// time for which it was entered) and _idle time_ (the total time that /// the span existed but was not entered). + /// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered + /// or exited. /// - `FmtSpan::FULL`: Events will be synthesized whenever a span is /// created, entered, exited, or closed. If timestamps are enabled, the /// close event will contain the span's busy and idle time, as /// described above. /// + /// The options can be enabled in any combination. For instance, the following + /// will synthesize events whenever spans are created and closed: + /// + /// ```rust + /// use tracing_subscriber::fmt; + /// use tracing_subscriber::fmt::format::FmtSpan; + /// + /// let subscriber = fmt() + /// .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE) + /// .finish(); + /// ``` + /// /// Note that the generated events will only be part of the log output by /// this formatter; they will not be recorded by other `Subscriber`s or by /// `Layer`s added to this subscriber. @@ -279,11 +294,8 @@ where /// [time]: #method.without_time pub fn with_span_events(self, kind: FmtSpan) -> Self { Layer { - fmt_event: self.fmt_event, - fmt_fields: self.fmt_fields, fmt_span: self.fmt_span.with_kind(kind), - make_writer: self.make_writer, - _inner: self._inner, + ..self } } @@ -293,10 +305,7 @@ where pub fn with_ansi(self, ansi: bool) -> Layer, W> { Layer { fmt_event: self.fmt_event.with_ansi(ansi), - fmt_fields: self.fmt_fields, - fmt_span: self.fmt_span, - make_writer: self.make_writer, - _inner: self._inner, + ..self } } @@ -304,10 +313,7 @@ where pub fn with_target(self, display_target: bool) -> Layer, W> { Layer { fmt_event: self.fmt_event.with_target(display_target), - fmt_fields: self.fmt_fields, - fmt_span: self.fmt_span, - make_writer: self.make_writer, - _inner: self._inner, + ..self } } @@ -315,10 +321,7 @@ where pub fn with_level(self, display_level: bool) -> Layer, W> { Layer { fmt_event: self.fmt_event.with_level(display_level), - fmt_fields: self.fmt_fields, - fmt_span: self.fmt_span, - make_writer: self.make_writer, - _inner: self._inner, + ..self } } @@ -329,10 +332,7 @@ where pub fn with_thread_ids(self, display_thread_ids: bool) -> Layer, W> { Layer { fmt_event: self.fmt_event.with_thread_ids(display_thread_ids), - fmt_fields: self.fmt_fields, - fmt_span: self.fmt_span, - make_writer: self.make_writer, - _inner: self._inner, + ..self } } @@ -346,10 +346,7 @@ where ) -> Layer, W> { Layer { fmt_event: self.fmt_event.with_thread_names(display_thread_names), - fmt_fields: self.fmt_fields, - fmt_span: self.fmt_span, - make_writer: self.make_writer, - _inner: self._inner, + ..self } } @@ -422,9 +419,7 @@ impl Layer, W> { Layer { fmt_event: self.fmt_event.flatten_event(flatten_event), fmt_fields: format::JsonFields::new(), - fmt_span: self.fmt_span, - make_writer: self.make_writer, - _inner: self._inner, + ..self } } @@ -439,9 +434,7 @@ impl Layer, W> { Layer { fmt_event: self.fmt_event.with_current_span(display_current_span), fmt_fields: format::JsonFields::new(), - fmt_span: self.fmt_span, - make_writer: self.make_writer, - _inner: self._inner, + ..self } } @@ -456,9 +449,7 @@ impl Layer, W> { Layer { fmt_event: self.fmt_event.with_span_list(display_span_list), fmt_fields: format::JsonFields::new(), - fmt_span: self.fmt_span, - make_writer: self.make_writer, - _inner: self._inner, + ..self } } } @@ -651,7 +642,7 @@ where } fn on_enter(&self, id: &Id, ctx: Context<'_, S>) { - if self.fmt_span.trace_active() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing { + if self.fmt_span.trace_enter() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing { let span = ctx.span(id).expect("Span not found, this is a bug"); let mut extensions = span.extensions_mut(); if let Some(timings) = extensions.get_mut::() { @@ -660,7 +651,7 @@ where timings.last = now; } - if self.fmt_span.trace_active() { + if self.fmt_span.trace_enter() { with_event_from_span!(id, span, "message" = "enter", |event| { drop(extensions); drop(span); @@ -671,7 +662,7 @@ where } fn on_exit(&self, id: &Id, ctx: Context<'_, S>) { - if self.fmt_span.trace_active() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing { + if self.fmt_span.trace_exit() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing { let span = ctx.span(id).expect("Span not found, this is a bug"); let mut extensions = span.extensions_mut(); if let Some(timings) = extensions.get_mut::() { @@ -680,7 +671,7 @@ where timings.last = now; } - if self.fmt_span.trace_active() { + if self.fmt_span.trace_exit() { with_event_from_span!(id, span, "message" = "exit", |event| { drop(extensions); drop(span); @@ -880,6 +871,11 @@ where self.ctx.scope() } + /// Returns the current span for this formatter. + pub fn current_span(&self) -> Current { + self.ctx.current_span() + } + /// Returns the [field formatter] configured by the subscriber invoking /// `format_event`. /// diff --git a/tracing-subscriber/src/fmt/format/mod.rs b/tracing-subscriber/src/fmt/format/mod.rs index c00825ac06..e8ea89cb3d 100644 --- a/tracing-subscriber/src/fmt/format/mod.rs +++ b/tracing-subscriber/src/fmt/format/mod.rs @@ -293,6 +293,23 @@ impl Format { /// See [`Pretty`]. /// /// Note that this requires the "ansi" feature to be enabled. + /// + /// # Options + /// + /// [`Format::with_ansi`] can be used to disable ANSI terminal escape codes (which enable + /// formatting such as colors, bold, italic, etc) in event formatting. However, a field + /// formatter must be manually provided to avoid ANSI in the formatting of parent spans, like + /// so: + /// + /// ``` + /// # use tracing_subscriber::fmt::format; + /// tracing_subscriber::fmt() + /// .pretty() + /// .with_ansi(false) + /// .fmt_fields(format::PrettyFields::new().with_ansi(false)) + /// // ... other settings ... + /// .init(); + /// ``` #[cfg(feature = "ansi")] #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))] pub fn pretty(self) -> Format { @@ -1088,40 +1105,89 @@ impl<'a, F> fmt::Debug for FieldFnVisitor<'a, F> { /// /// See also [`with_span_events`](../struct.SubscriberBuilder.html#method.with_span_events). #[derive(Clone, Eq, PartialEq, Ord, PartialOrd)] -pub struct FmtSpan(FmtSpanInner); +pub struct FmtSpan(u8); impl FmtSpan { + /// one event when span is created + pub const NEW: FmtSpan = FmtSpan(1 << 0); + /// one event per enter of a span + pub const ENTER: FmtSpan = FmtSpan(1 << 1); + /// one event per exit of a span + pub const EXIT: FmtSpan = FmtSpan(1 << 2); + /// one event when the span is dropped + pub const CLOSE: FmtSpan = FmtSpan(1 << 3); + /// spans are ignored (this is the default) - pub const NONE: FmtSpan = FmtSpan(FmtSpanInner::None); + pub const NONE: FmtSpan = FmtSpan(0); /// one event per enter/exit of a span - pub const ACTIVE: FmtSpan = FmtSpan(FmtSpanInner::Active); - /// one event when the span is dropped - pub const CLOSE: FmtSpan = FmtSpan(FmtSpanInner::Close); + pub const ACTIVE: FmtSpan = FmtSpan(FmtSpan::ENTER.0 | FmtSpan::EXIT.0); /// events at all points (new, enter, exit, drop) - pub const FULL: FmtSpan = FmtSpan(FmtSpanInner::Full); + pub const FULL: FmtSpan = + FmtSpan(FmtSpan::NEW.0 | FmtSpan::ENTER.0 | FmtSpan::EXIT.0 | FmtSpan::CLOSE.0); + + /// Check whether or not a certain flag is set for this [`FmtSpan`] + fn contains(&self, other: FmtSpan) -> bool { + self.clone() & other.clone() == other + } } +macro_rules! impl_fmt_span_bit_op { + ($trait:ident, $func:ident, $op:tt) => { + impl std::ops::$trait for FmtSpan { + type Output = FmtSpan; + + fn $func(self, rhs: Self) -> Self::Output { + FmtSpan(self.0 $op rhs.0) + } + } + }; +} + +macro_rules! impl_fmt_span_bit_assign_op { + ($trait:ident, $func:ident, $op:tt) => { + impl std::ops::$trait for FmtSpan { + fn $func(&mut self, rhs: Self) { + *self = FmtSpan(self.0 $op rhs.0) + } + } + }; +} + +impl_fmt_span_bit_op!(BitAnd, bitand, &); +impl_fmt_span_bit_op!(BitOr, bitor, |); +impl_fmt_span_bit_op!(BitXor, bitxor, ^); + +impl_fmt_span_bit_assign_op!(BitAndAssign, bitand_assign, &); +impl_fmt_span_bit_assign_op!(BitOrAssign, bitor_assign, |); +impl_fmt_span_bit_assign_op!(BitXorAssign, bitxor_assign, ^); + impl Debug for FmtSpan { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { - match self.0 { - FmtSpanInner::None => f.write_str("FmtSpan::NONE"), - FmtSpanInner::Active => f.write_str("FmtSpan::ACTIVE"), - FmtSpanInner::Close => f.write_str("FmtSpan::CLOSE"), - FmtSpanInner::Full => f.write_str("FmtSpan::FULL"), + let mut wrote_flag = false; + let mut write_flags = |flag, flag_str| -> fmt::Result { + if self.contains(flag) { + if wrote_flag { + f.write_str(" | ")?; + } + + f.write_str(flag_str)?; + wrote_flag = true; + } + + Ok(()) + }; + + if FmtSpan::NONE | self.clone() == FmtSpan::NONE { + f.write_str("FmtSpan::NONE")?; + } else { + write_flags(FmtSpan::NEW, "FmtSpan::NEW")?; + write_flags(FmtSpan::ENTER, "FmtSpan::ENTER")?; + write_flags(FmtSpan::EXIT, "FmtSpan::EXIT")?; + write_flags(FmtSpan::CLOSE, "FmtSpan::CLOSE")?; } - } -} -#[derive(Copy, Clone, Debug, Eq, PartialEq, Hash, Ord, PartialOrd)] -enum FmtSpanInner { - /// spans are ignored (this is the default) - None, - /// one event per enter/exit of a span - Active, - /// one event when the span is dropped - Close, - /// events at all points (new, enter, exit, drop) - Full, + Ok(()) + } } pub(super) struct FmtSpanConfig { @@ -1143,13 +1209,16 @@ impl FmtSpanConfig { } } pub(super) fn trace_new(&self) -> bool { - matches!(self.kind, FmtSpan::FULL) + self.kind.contains(FmtSpan::NEW) + } + pub(super) fn trace_enter(&self) -> bool { + self.kind.contains(FmtSpan::ENTER) } - pub(super) fn trace_active(&self) -> bool { - matches!(self.kind, FmtSpan::ACTIVE | FmtSpan::FULL) + pub(super) fn trace_exit(&self) -> bool { + self.kind.contains(FmtSpan::EXIT) } pub(super) fn trace_close(&self) -> bool { - matches!(self.kind, FmtSpan::CLOSE | FmtSpan::FULL) + self.kind.contains(FmtSpan::CLOSE) } } @@ -1168,7 +1237,6 @@ impl Default for FmtSpanConfig { } } -#[repr(transparent)] pub(super) struct TimingDisplay(pub(super) u64); impl Display for TimingDisplay { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { @@ -1194,7 +1262,7 @@ pub(super) mod test { use lazy_static::lazy_static; use tracing::{self, subscriber::with_default}; - use super::TimingDisplay; + use super::{FmtSpan, TimingDisplay}; use std::{fmt, sync::Mutex}; pub(crate) struct MockTime; @@ -1381,4 +1449,31 @@ pub(super) mod test { assert_eq!(fmt(123456789012), "123s"); assert_eq!(fmt(1234567890123), "1235s"); } + + #[test] + fn fmt_span_combinations() { + let f = FmtSpan::NONE; + assert_eq!(f.contains(FmtSpan::NEW), false); + assert_eq!(f.contains(FmtSpan::ENTER), false); + assert_eq!(f.contains(FmtSpan::EXIT), false); + assert_eq!(f.contains(FmtSpan::CLOSE), false); + + let f = FmtSpan::ACTIVE; + assert_eq!(f.contains(FmtSpan::NEW), false); + assert_eq!(f.contains(FmtSpan::ENTER), true); + assert_eq!(f.contains(FmtSpan::EXIT), true); + assert_eq!(f.contains(FmtSpan::CLOSE), false); + + let f = FmtSpan::FULL; + assert_eq!(f.contains(FmtSpan::NEW), true); + assert_eq!(f.contains(FmtSpan::ENTER), true); + assert_eq!(f.contains(FmtSpan::EXIT), true); + assert_eq!(f.contains(FmtSpan::CLOSE), true); + + let f = FmtSpan::NEW | FmtSpan::CLOSE; + assert_eq!(f.contains(FmtSpan::NEW), true); + assert_eq!(f.contains(FmtSpan::ENTER), false); + assert_eq!(f.contains(FmtSpan::EXIT), false); + assert_eq!(f.contains(FmtSpan::CLOSE), true); + } } diff --git a/tracing-subscriber/src/fmt/format/pretty.rs b/tracing-subscriber/src/fmt/format/pretty.rs index d3d269493b..61be844e9c 100644 --- a/tracing-subscriber/src/fmt/format/pretty.rs +++ b/tracing-subscriber/src/fmt/format/pretty.rs @@ -33,10 +33,19 @@ pub struct Pretty { pub struct PrettyVisitor<'a> { writer: &'a mut dyn Write, is_empty: bool, + ansi: bool, style: Style, result: fmt::Result, } +/// An excessively pretty, human-readable [`MakeVisitor`] implementation. +/// +/// [`MakeVisitor`]: crate::field::MakeVisitor +#[derive(Debug)] +pub struct PrettyFields { + ansi: bool, +} + // === impl Pretty === impl Default for Pretty { @@ -99,30 +108,40 @@ where #[cfg(not(feature = "tracing-log"))] let meta = event.metadata(); write!(writer, " ")?; - time::write(&self.timer, writer, true)?; + time::write(&self.timer, writer, self.ansi)?; - let style = if self.display_level { + let style = if self.display_level && self.ansi { Pretty::style_for(meta.level()) } else { Style::new() }; + if self.display_level { + write!(writer, "{}", super::FmtLevel::new(meta.level(), self.ansi))?; + } + if self.display_target { - let bold = style.bold(); + let target_style = if self.ansi { style.bold() } else { style }; write!( writer, "{}{}{}: ", - bold.prefix(), + target_style.prefix(), meta.target(), - bold.infix(style) + target_style.infix(style) )?; } - let mut v = PrettyVisitor::new(writer, true).with_style(style); + let mut v = PrettyVisitor::new(writer, true) + .with_style(style) + .with_ansi(self.ansi); event.record(&mut v); v.finish()?; writer.write_char('\n')?; - let dimmed = Style::new().dimmed().italic(); + let dimmed = if self.ansi { + Style::new().dimmed().italic() + } else { + Style::new() + }; let thread = self.display_thread_name || self.display_thread_id; if let (true, Some(file), Some(line)) = (self.format.display_location, meta.file(), meta.line()) @@ -157,7 +176,11 @@ where writer.write_char('\n')?; } - let bold = Style::new().bold(); + let bold = if self.ansi { + Style::new().bold() + } else { + Style::new() + }; let span = event .parent() .and_then(|id| ctx.span(&id)) @@ -220,6 +243,35 @@ impl<'writer> FormatFields<'writer> for Pretty { } } +// === impl PrettyFields === + +impl Default for PrettyFields { + fn default() -> Self { + Self::new() + } +} + +impl PrettyFields { + /// Returns a new default [`PrettyFields`] implementation. + pub fn new() -> Self { + Self { ansi: true } + } + + /// Enable ANSI encoding for formatted fields. + pub fn with_ansi(self, ansi: bool) -> Self { + Self { ansi, ..self } + } +} + +impl<'a> MakeVisitor<&'a mut dyn Write> for PrettyFields { + type Visitor = PrettyVisitor<'a>; + + #[inline] + fn make_visitor(&self, target: &'a mut dyn Write) -> Self::Visitor { + PrettyVisitor::new(target, true).with_ansi(self.ansi) + } +} + // === impl PrettyVisitor === impl<'a> PrettyVisitor<'a> { @@ -233,6 +285,7 @@ impl<'a> PrettyVisitor<'a> { Self { writer, is_empty, + ansi: true, style: Style::default(), result: Ok(()), } @@ -242,11 +295,25 @@ impl<'a> PrettyVisitor<'a> { Self { style, ..self } } - fn maybe_pad(&mut self) { - if self.is_empty { + pub(crate) fn with_ansi(self, ansi: bool) -> Self { + Self { ansi, ..self } + } + + fn write_padded(&mut self, value: &impl fmt::Debug) { + let padding = if self.is_empty { self.is_empty = false; + "" + } else { + ", " + }; + self.result = write!(self.writer, "{}{:?}", padding, value); + } + + fn bold(&self) -> Style { + if self.ansi { + self.style.bold() } else { - self.result = write!(self.writer, ", "); + Style::new() } } } @@ -266,7 +333,7 @@ impl<'a> field::Visit for PrettyVisitor<'a> { fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) { if let Some(source) = value.source() { - let bold = self.style.bold(); + let bold = self.bold(); self.record_debug( field, &format_args!( @@ -287,29 +354,26 @@ impl<'a> field::Visit for PrettyVisitor<'a> { if self.result.is_err() { return; } - let bold = self.style.bold(); - self.maybe_pad(); - self.result = match field.name() { - "message" => write!(self.writer, "{}{:?}", self.style.prefix(), value,), + let bold = self.bold(); + match field.name() { + "message" => self.write_padded(&format_args!("{}{:?}", self.style.prefix(), value,)), // Skip fields that are actually log metadata that have already been handled #[cfg(feature = "tracing-log")] - name if name.starts_with("log.") => Ok(()), - name if name.starts_with("r#") => write!( - self.writer, + name if name.starts_with("log.") => self.result = Ok(()), + name if name.starts_with("r#") => self.write_padded(&format_args!( "{}{}{}: {:?}", bold.prefix(), &name[2..], bold.infix(self.style), value - ), - name => write!( - self.writer, + )), + name => self.write_padded(&format_args!( "{}{}{}: {:?}", bold.prefix(), name, bold.infix(self.style), value - ), + )), }; } } @@ -334,6 +398,7 @@ impl<'a> fmt::Debug for PrettyVisitor<'a> { .field("is_empty", &self.is_empty) .field("result", &self.result) .field("style", &self.style) + .field("ansi", &self.ansi) .finish() } } diff --git a/tracing-subscriber/src/fmt/mod.rs b/tracing-subscriber/src/fmt/mod.rs index 5880e6550d..0a90864766 100644 --- a/tracing-subscriber/src/fmt/mod.rs +++ b/tracing-subscriber/src/fmt/mod.rs @@ -623,18 +623,33 @@ where /// - `FmtSpan::NONE`: No events will be synthesized when spans are /// created, entered, exited, or closed. Data from spans will still be /// included as the context for formatted events. This is the default. - /// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered - /// or exited. + /// - `FmtSpan::NEW`: An event will be synthesized when spans are created. + /// - `FmtSpan::ENTER`: An event will be synthesized when spans are entered. + /// - `FmtSpan::EXIT`: An event will be synthesized when spans are exited. /// - `FmtSpan::CLOSE`: An event will be synthesized when a span closes. If /// [timestamps are enabled][time] for this formatter, the generated /// event will contain fields with the span's _busy time_ (the total /// time for which it was entered) and _idle time_ (the total time that /// the span existed but was not entered). + /// - `FmtSpan::ACTIVE`: An event will be synthesized when spans are entered + /// or exited. /// - `FmtSpan::FULL`: Events will be synthesized whenever a span is /// created, entered, exited, or closed. If timestamps are enabled, the /// close event will contain the span's busy and idle time, as /// described above. /// + /// The options can be enabled in any combination. For instance, the following + /// will synthesize events whenever spans are created and closed: + /// + /// ```rust + /// use tracing_subscriber::fmt::format::FmtSpan; + /// use tracing_subscriber::fmt; + /// + /// let subscriber = fmt() + /// .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE) + /// .finish(); + /// ``` + /// /// Note that the generated events will only be part of the log output by /// this formatter; they will not be recorded by other `Subscriber`s or by /// `Layer`s added to this subscriber. @@ -643,8 +658,8 @@ where /// [time]: #method.without_time pub fn with_span_events(self, kind: format::FmtSpan) -> Self { SubscriberBuilder { - filter: self.filter, inner: self.inner.with_span_events(kind), + ..self } } @@ -653,8 +668,8 @@ where #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))] pub fn with_ansi(self, ansi: bool) -> SubscriberBuilder, F, W> { SubscriberBuilder { - filter: self.filter, inner: self.inner.with_ansi(ansi), + ..self } } @@ -664,8 +679,8 @@ where display_target: bool, ) -> SubscriberBuilder, F, W> { SubscriberBuilder { - filter: self.filter, inner: self.inner.with_target(display_target), + ..self } } @@ -675,8 +690,8 @@ where display_level: bool, ) -> SubscriberBuilder, F, W> { SubscriberBuilder { - filter: self.filter, inner: self.inner.with_level(display_level), + ..self } } @@ -689,8 +704,8 @@ where display_thread_names: bool, ) -> SubscriberBuilder, F, W> { SubscriberBuilder { - filter: self.filter, inner: self.inner.with_thread_names(display_thread_names), + ..self } } @@ -703,8 +718,8 @@ where display_thread_ids: bool, ) -> SubscriberBuilder, F, W> { SubscriberBuilder { - filter: self.filter, inner: self.inner.with_thread_ids(display_thread_ids), + ..self } }