tracing_subscriber/fmt/
fmt_layer.rs

1use crate::{
2    field::RecordFields,
3    fmt::{format, FormatEvent, FormatFields, MakeWriter, TestWriter},
4    layer::{self, Context},
5    registry::{self, LookupSpan, SpanRef},
6};
7use format::{FmtSpan, TimingDisplay};
8use std::{
9    any::TypeId, cell::RefCell, env, fmt, io, marker::PhantomData, ops::Deref, time::Instant,
10};
11use tracing_core::{
12    field,
13    span::{Attributes, Current, Id, Record},
14    Event, Metadata, Subscriber,
15};
16
17/// A [`Layer`] that logs formatted representations of `tracing` events.
18///
19/// ## Examples
20///
21/// Constructing a layer with the default configuration:
22///
23/// ```rust
24/// use tracing_subscriber::{fmt, Registry};
25/// use tracing_subscriber::prelude::*;
26///
27/// let subscriber = Registry::default()
28///     .with(fmt::Layer::default());
29///
30/// tracing::subscriber::set_global_default(subscriber).unwrap();
31/// ```
32///
33/// Overriding the layer's behavior:
34///
35/// ```rust
36/// use tracing_subscriber::{fmt, Registry};
37/// use tracing_subscriber::prelude::*;
38///
39/// let fmt_layer = fmt::layer()
40///    .with_target(false) // don't include event targets when logging
41///    .with_level(false); // don't include event levels when logging
42///
43/// let subscriber = Registry::default().with(fmt_layer);
44/// # tracing::subscriber::set_global_default(subscriber).unwrap();
45/// ```
46///
47/// Setting a custom event formatter:
48///
49/// ```rust
50/// use tracing_subscriber::fmt::{self, format, time};
51/// use tracing_subscriber::prelude::*;
52///
53/// let fmt = format().with_timer(time::Uptime::default());
54/// let fmt_layer = fmt::layer()
55///     .event_format(fmt)
56///     .with_target(false);
57/// # let subscriber = fmt_layer.with_subscriber(tracing_subscriber::registry::Registry::default());
58/// # tracing::subscriber::set_global_default(subscriber).unwrap();
59/// ```
60///
61/// [`Layer`]: super::layer::Layer
62#[cfg_attr(docsrs, doc(cfg(all(feature = "fmt", feature = "std"))))]
63#[derive(Debug)]
64pub struct Layer<
65    S,
66    N = format::DefaultFields,
67    E = format::Format<format::Full>,
68    W = fn() -> io::Stdout,
69> {
70    make_writer: W,
71    fmt_fields: N,
72    fmt_event: E,
73    fmt_span: format::FmtSpanConfig,
74    is_ansi: bool,
75    log_internal_errors: bool,
76    _inner: PhantomData<fn(S)>,
77}
78
79impl<S> Layer<S> {
80    /// Returns a new [`Layer`][self::Layer] with the default configuration.
81    pub fn new() -> Self {
82        Self::default()
83    }
84}
85
86// This needs to be a seperate impl block because they place different bounds on the type parameters.
87impl<S, N, E, W> Layer<S, N, E, W>
88where
89    S: Subscriber + for<'a> LookupSpan<'a>,
90    N: for<'writer> FormatFields<'writer> + 'static,
91    W: for<'writer> MakeWriter<'writer> + 'static,
92{
93    /// Sets the [event formatter][`FormatEvent`] that the layer being built will
94    /// use to format events.
95    ///
96    /// The event formatter may be any type implementing the [`FormatEvent`]
97    /// trait, which is implemented for all functions taking a [`FmtContext`], a
98    /// [`Writer`], and an [`Event`].
99    ///
100    /// # Examples
101    ///
102    /// Setting a type implementing [`FormatEvent`] as the formatter:
103    /// ```rust
104    /// use tracing_subscriber::fmt::{self, format};
105    ///
106    /// let layer = fmt::layer()
107    ///     .event_format(format().compact());
108    /// # // this is necessary for type inference.
109    /// # use tracing_subscriber::Layer as _;
110    /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
111    /// ```
112    /// [`FormatEvent`]: format::FormatEvent
113    /// [`Event`]: tracing::Event
114    /// [`Writer`]: format::Writer
115    pub fn event_format<E2>(self, e: E2) -> Layer<S, N, E2, W>
116    where
117        E2: FormatEvent<S, N> + 'static,
118    {
119        Layer {
120            fmt_fields: self.fmt_fields,
121            fmt_event: e,
122            fmt_span: self.fmt_span,
123            make_writer: self.make_writer,
124            is_ansi: self.is_ansi,
125            log_internal_errors: self.log_internal_errors,
126            _inner: self._inner,
127        }
128    }
129
130    /// Updates the event formatter by applying a function to the existing event formatter.
131    ///
132    /// This sets the event formatter that the layer being built will use to record fields.
133    ///
134    /// # Examples
135    ///
136    /// Updating an event formatter:
137    ///
138    /// ```rust
139    /// let layer = tracing_subscriber::fmt::layer()
140    ///     .map_event_format(|e| e.compact());
141    /// # // this is necessary for type inference.
142    /// # use tracing_subscriber::Layer as _;
143    /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
144    /// ```
145    pub fn map_event_format<E2>(self, f: impl FnOnce(E) -> E2) -> Layer<S, N, E2, W>
146    where
147        E2: FormatEvent<S, N> + 'static,
148    {
149        Layer {
150            fmt_fields: self.fmt_fields,
151            fmt_event: f(self.fmt_event),
152            fmt_span: self.fmt_span,
153            make_writer: self.make_writer,
154            is_ansi: self.is_ansi,
155            log_internal_errors: self.log_internal_errors,
156            _inner: self._inner,
157        }
158    }
159}
160
161// This needs to be a seperate impl block because they place different bounds on the type parameters.
162impl<S, N, E, W> Layer<S, N, E, W> {
163    /// Sets the [`MakeWriter`] that the layer being built will use to write events.
164    ///
165    /// # Examples
166    ///
167    /// Using `stderr` rather than `stdout`:
168    ///
169    /// ```rust
170    /// use std::io;
171    /// use tracing_subscriber::fmt;
172    ///
173    /// let layer = fmt::layer()
174    ///     .with_writer(io::stderr);
175    /// # // this is necessary for type inference.
176    /// # use tracing_subscriber::Layer as _;
177    /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
178    /// ```
179    pub fn with_writer<W2>(self, make_writer: W2) -> Layer<S, N, E, W2>
180    where
181        W2: for<'writer> MakeWriter<'writer> + 'static,
182    {
183        Layer {
184            fmt_fields: self.fmt_fields,
185            fmt_event: self.fmt_event,
186            fmt_span: self.fmt_span,
187            is_ansi: self.is_ansi,
188            log_internal_errors: self.log_internal_errors,
189            make_writer,
190            _inner: self._inner,
191        }
192    }
193
194    /// Borrows the [writer] for this [`Layer`].
195    ///
196    /// [writer]: MakeWriter
197    pub fn writer(&self) -> &W {
198        &self.make_writer
199    }
200
201    /// Mutably borrows the [writer] for this [`Layer`].
202    ///
203    /// This method is primarily expected to be used with the
204    /// [`reload::Handle::modify`](crate::reload::Handle::modify) method.
205    ///
206    /// # Examples
207    ///
208    /// ```
209    /// # use tracing::info;
210    /// # use tracing_subscriber::{fmt,reload,Registry,prelude::*};
211    /// # fn non_blocking<T: std::io::Write>(writer: T) -> (fn() -> std::io::Stdout) {
212    /// #   std::io::stdout
213    /// # }
214    /// # fn main() {
215    /// let layer = fmt::layer().with_writer(non_blocking(std::io::stderr()));
216    /// let (layer, reload_handle) = reload::Layer::new(layer);
217    /// #
218    /// # // specifying the Registry type is required
219    /// # let _: &reload::Handle<fmt::Layer<Registry, _, _, _>, Registry> = &reload_handle;
220    /// #
221    /// info!("This will be logged to stderr");
222    /// reload_handle.modify(|layer| *layer.writer_mut() = non_blocking(std::io::stdout()));
223    /// info!("This will be logged to stdout");
224    /// # }
225    /// ```
226    ///
227    /// [writer]: MakeWriter
228    pub fn writer_mut(&mut self) -> &mut W {
229        &mut self.make_writer
230    }
231
232    /// Sets whether this layer should use ANSI terminal formatting
233    /// escape codes (such as colors).
234    ///
235    /// This method is primarily expected to be used with the
236    /// [`reload::Handle::modify`](crate::reload::Handle::modify) method when changing
237    /// the writer.
238    #[cfg(feature = "ansi")]
239    #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
240    pub fn set_ansi(&mut self, ansi: bool) {
241        self.is_ansi = ansi;
242    }
243
244    /// Modifies how synthesized events are emitted at points in the [span
245    /// lifecycle][lifecycle].
246    ///
247    /// See [`Self::with_span_events`] for documentation on the [`FmtSpan`]
248    ///
249    /// This method is primarily expected to be used with the
250    /// [`reload::Handle::modify`](crate::reload::Handle::modify) method
251    ///
252    /// Note that using this method modifies the span configuration instantly and does not take into
253    /// account any current spans. If the previous configuration was set to capture
254    /// `FmtSpan::ALL`, for example, using this method to change to `FmtSpan::NONE` will cause an
255    /// exit event for currently entered events not to be formatted
256    ///
257    /// [lifecycle]: mod@tracing::span#the-span-lifecycle
258    pub fn set_span_events(&mut self, kind: FmtSpan) {
259        self.fmt_span = format::FmtSpanConfig {
260            kind,
261            fmt_timing: self.fmt_span.fmt_timing,
262        }
263    }
264
265    /// Configures the layer to support [`libtest`'s output capturing][capturing] when used in
266    /// unit tests.
267    ///
268    /// See [`TestWriter`] for additional details.
269    ///
270    /// # Examples
271    ///
272    /// Using [`TestWriter`] to let `cargo test` capture test output:
273    ///
274    /// ```rust
275    /// use std::io;
276    /// use tracing_subscriber::fmt;
277    ///
278    /// let layer = fmt::layer()
279    ///     .with_test_writer();
280    /// # // this is necessary for type inference.
281    /// # use tracing_subscriber::Layer as _;
282    /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
283    /// ```
284    /// [capturing]:
285    /// https://doc.rust-lang.org/book/ch11-02-running-tests.html#showing-function-output
286    /// [`TestWriter`]: super::writer::TestWriter
287    pub fn with_test_writer(self) -> Layer<S, N, E, TestWriter> {
288        Layer {
289            fmt_fields: self.fmt_fields,
290            fmt_event: self.fmt_event,
291            fmt_span: self.fmt_span,
292            is_ansi: self.is_ansi,
293            log_internal_errors: self.log_internal_errors,
294            make_writer: TestWriter::default(),
295            _inner: self._inner,
296        }
297    }
298
299    /// Sets whether or not the formatter emits ANSI terminal escape codes
300    /// for colors and other text formatting.
301    ///
302    /// When the "ansi" crate feature flag is enabled, ANSI colors are enabled
303    /// by default unless the [`NO_COLOR`] environment variable is set to
304    /// a non-empty value.  If the [`NO_COLOR`] environment variable is set to
305    /// any non-empty value, then ANSI colors will be suppressed by default.
306    /// The [`with_ansi`] and [`set_ansi`] methods can be used to forcibly
307    /// enable ANSI colors, overriding any [`NO_COLOR`] environment variable.
308    ///
309    /// [`NO_COLOR`]: https://no-color.org/
310    ///
311    /// Enabling ANSI escapes (calling `with_ansi(true)`) requires the "ansi"
312    /// crate feature flag. Calling `with_ansi(true)` without the "ansi"
313    /// feature flag enabled will panic if debug assertions are enabled, or
314    /// print a warning otherwise.
315    ///
316    /// This method itself is still available without the feature flag. This
317    /// is to allow ANSI escape codes to be explicitly *disabled* without
318    /// having to opt-in to the dependencies required to emit ANSI formatting.
319    /// This way, code which constructs a formatter that should never emit
320    /// ANSI escape codes can ensure that they are not used, regardless of
321    /// whether or not other crates in the dependency graph enable the "ansi"
322    /// feature flag.
323    ///
324    /// [`with_ansi`]: Layer::with_ansi
325    /// [`set_ansi`]: Layer::set_ansi
326    pub fn with_ansi(self, ansi: bool) -> Self {
327        #[cfg(not(feature = "ansi"))]
328        if ansi {
329            const ERROR: &str =
330                "tracing-subscriber: the `ansi` crate feature is required to enable ANSI terminal colors";
331            #[cfg(debug_assertions)]
332            panic!("{}", ERROR);
333            #[cfg(not(debug_assertions))]
334            eprintln!("{}", ERROR);
335        }
336
337        Self {
338            is_ansi: ansi,
339            ..self
340        }
341    }
342
343    /// Sets whether to write errors from [`FormatEvent`] to the writer.
344    /// Defaults to true.
345    ///
346    /// By default, `fmt::Layer` will write any `FormatEvent`-internal errors to
347    /// the writer. These errors are unlikely and will only occur if there is a
348    /// bug in the `FormatEvent` implementation or its dependencies.
349    ///
350    /// If writing to the writer fails, the error message is printed to stderr
351    /// as a fallback.
352    ///
353    /// [`FormatEvent`]: crate::fmt::FormatEvent
354    pub fn log_internal_errors(self, log_internal_errors: bool) -> Self {
355        Self {
356            log_internal_errors,
357            ..self
358        }
359    }
360
361    /// Updates the [`MakeWriter`] by applying a function to the existing [`MakeWriter`].
362    ///
363    /// This sets the [`MakeWriter`] that the layer being built will use to write events.
364    ///
365    /// # Examples
366    ///
367    /// Redirect output to stderr if level is <= WARN:
368    ///
369    /// ```rust
370    /// use tracing::Level;
371    /// use tracing_subscriber::fmt::{self, writer::MakeWriterExt};
372    ///
373    /// let stderr = std::io::stderr.with_max_level(Level::WARN);
374    /// let layer = fmt::layer()
375    ///     .map_writer(move |w| stderr.or_else(w));
376    /// # // this is necessary for type inference.
377    /// # use tracing_subscriber::Layer as _;
378    /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
379    /// ```
380    pub fn map_writer<W2>(self, f: impl FnOnce(W) -> W2) -> Layer<S, N, E, W2>
381    where
382        W2: for<'writer> MakeWriter<'writer> + 'static,
383    {
384        Layer {
385            fmt_fields: self.fmt_fields,
386            fmt_event: self.fmt_event,
387            fmt_span: self.fmt_span,
388            is_ansi: self.is_ansi,
389            log_internal_errors: self.log_internal_errors,
390            make_writer: f(self.make_writer),
391            _inner: self._inner,
392        }
393    }
394}
395
396impl<S, N, L, T, W> Layer<S, N, format::Format<L, T>, W>
397where
398    N: for<'writer> FormatFields<'writer> + 'static,
399{
400    /// Use the given [`timer`] for span and event timestamps.
401    ///
402    /// See the [`time` module] for the provided timer implementations.
403    ///
404    /// Note that using the `"time`"" feature flag enables the
405    /// additional time formatters [`UtcTime`] and [`LocalTime`], which use the
406    /// [`time` crate] to provide more sophisticated timestamp formatting
407    /// options.
408    ///
409    /// [`timer`]: super::time::FormatTime
410    /// [`time` module]: mod@super::time
411    /// [`UtcTime`]: super::time::UtcTime
412    /// [`LocalTime`]: super::time::LocalTime
413    /// [`time` crate]: https://docs.rs/time/0.3
414    pub fn with_timer<T2>(self, timer: T2) -> Layer<S, N, format::Format<L, T2>, W> {
415        Layer {
416            fmt_event: self.fmt_event.with_timer(timer),
417            fmt_fields: self.fmt_fields,
418            fmt_span: self.fmt_span,
419            make_writer: self.make_writer,
420            is_ansi: self.is_ansi,
421            log_internal_errors: self.log_internal_errors,
422            _inner: self._inner,
423        }
424    }
425
426    /// Do not emit timestamps with spans and event.
427    pub fn without_time(self) -> Layer<S, N, format::Format<L, ()>, W> {
428        Layer {
429            fmt_event: self.fmt_event.without_time(),
430            fmt_fields: self.fmt_fields,
431            fmt_span: self.fmt_span.without_time(),
432            make_writer: self.make_writer,
433            is_ansi: self.is_ansi,
434            log_internal_errors: self.log_internal_errors,
435            _inner: self._inner,
436        }
437    }
438
439    /// Configures how synthesized events are emitted at points in the [span
440    /// lifecycle][lifecycle].
441    ///
442    /// The following options are available:
443    ///
444    /// - `FmtSpan::NONE`: No events will be synthesized when spans are
445    ///   created, entered, exited, or closed. Data from spans will still be
446    ///   included as the context for formatted events. This is the default.
447    /// - `FmtSpan::NEW`: An event will be synthesized when spans are created.
448    /// - `FmtSpan::ENTER`: An event will be synthesized when spans are entered.
449    /// - `FmtSpan::EXIT`: An event will be synthesized when spans are exited.
450    /// - `FmtSpan::CLOSE`: An event will be synthesized when a span closes. If
451    ///   [timestamps are enabled][time] for this formatter, the generated
452    ///   event will contain fields with the span's _busy time_ (the total
453    ///   time for which it was entered) and _idle time_ (the total time that
454    ///   the span existed but was not entered).
455    /// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered
456    ///   or exited.
457    /// - `FmtSpan::FULL`: Events will be synthesized whenever a span is
458    ///   created, entered, exited, or closed. If timestamps are enabled, the
459    ///   close event will contain the span's busy and idle time, as
460    ///   described above.
461    ///
462    /// The options can be enabled in any combination. For instance, the following
463    /// will synthesize events whenever spans are created and closed:
464    ///
465    /// ```rust
466    /// use tracing_subscriber::fmt;
467    /// use tracing_subscriber::fmt::format::FmtSpan;
468    ///
469    /// let subscriber = fmt()
470    ///     .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
471    ///     .finish();
472    /// ```
473    ///
474    /// Note that the generated events will only be part of the log output by
475    /// this formatter; they will not be recorded by other `Subscriber`s or by
476    /// `Layer`s added to this subscriber.
477    ///
478    /// [lifecycle]: https://docs.rs/tracing/latest/tracing/span/index.html#the-span-lifecycle
479    /// [time]: Layer::without_time()
480    pub fn with_span_events(self, kind: FmtSpan) -> Self {
481        Layer {
482            fmt_span: self.fmt_span.with_kind(kind),
483            ..self
484        }
485    }
486
487    /// Sets whether or not an event's target is displayed.
488    pub fn with_target(self, display_target: bool) -> Layer<S, N, format::Format<L, T>, W> {
489        Layer {
490            fmt_event: self.fmt_event.with_target(display_target),
491            ..self
492        }
493    }
494    /// Sets whether or not an event's [source code file path][file] is
495    /// displayed.
496    ///
497    /// [file]: tracing_core::Metadata::file
498    pub fn with_file(self, display_filename: bool) -> Layer<S, N, format::Format<L, T>, W> {
499        Layer {
500            fmt_event: self.fmt_event.with_file(display_filename),
501            ..self
502        }
503    }
504
505    /// Sets whether or not an event's [source code line number][line] is
506    /// displayed.
507    ///
508    /// [line]: tracing_core::Metadata::line
509    pub fn with_line_number(
510        self,
511        display_line_number: bool,
512    ) -> Layer<S, N, format::Format<L, T>, W> {
513        Layer {
514            fmt_event: self.fmt_event.with_line_number(display_line_number),
515            ..self
516        }
517    }
518
519    /// Sets whether or not an event's level is displayed.
520    pub fn with_level(self, display_level: bool) -> Layer<S, N, format::Format<L, T>, W> {
521        Layer {
522            fmt_event: self.fmt_event.with_level(display_level),
523            ..self
524        }
525    }
526
527    /// Sets whether or not the [thread ID] of the current thread is displayed
528    /// when formatting events.
529    ///
530    /// [thread ID]: std::thread::ThreadId
531    pub fn with_thread_ids(self, display_thread_ids: bool) -> Layer<S, N, format::Format<L, T>, W> {
532        Layer {
533            fmt_event: self.fmt_event.with_thread_ids(display_thread_ids),
534            ..self
535        }
536    }
537
538    /// Sets whether or not the [name] of the current thread is displayed
539    /// when formatting events.
540    ///
541    /// [name]: std::thread#naming-threads
542    pub fn with_thread_names(
543        self,
544        display_thread_names: bool,
545    ) -> Layer<S, N, format::Format<L, T>, W> {
546        Layer {
547            fmt_event: self.fmt_event.with_thread_names(display_thread_names),
548            ..self
549        }
550    }
551
552    /// Sets the layer being built to use a [less verbose formatter][super::format::Compact].
553    pub fn compact(self) -> Layer<S, N, format::Format<format::Compact, T>, W>
554    where
555        N: for<'writer> FormatFields<'writer> + 'static,
556    {
557        Layer {
558            fmt_event: self.fmt_event.compact(),
559            fmt_fields: self.fmt_fields,
560            fmt_span: self.fmt_span,
561            make_writer: self.make_writer,
562            is_ansi: self.is_ansi,
563            log_internal_errors: self.log_internal_errors,
564            _inner: self._inner,
565        }
566    }
567
568    /// Sets the layer being built to use an [excessively pretty, human-readable formatter](crate::fmt::format::Pretty).
569    #[cfg(feature = "ansi")]
570    #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
571    pub fn pretty(self) -> Layer<S, format::Pretty, format::Format<format::Pretty, T>, W> {
572        Layer {
573            fmt_event: self.fmt_event.pretty(),
574            fmt_fields: format::Pretty::default(),
575            fmt_span: self.fmt_span,
576            make_writer: self.make_writer,
577            is_ansi: self.is_ansi,
578            log_internal_errors: self.log_internal_errors,
579            _inner: self._inner,
580        }
581    }
582
583    /// Sets the layer being built to use a [JSON formatter][super::format::Json].
584    ///
585    /// The full format includes fields from all entered spans.
586    ///
587    /// # Example Output
588    ///
589    /// ```ignore,json
590    /// {"timestamp":"Feb 20 11:28:15.096","level":"INFO","target":"mycrate","fields":{"message":"some message", "key": "value"}}
591    /// ```
592    ///
593    /// # Options
594    ///
595    /// - [`Layer::flatten_event`] can be used to enable flattening event fields into the root
596    ///   object.
597    ///
598    /// [`Layer::flatten_event`]: Layer::flatten_event()
599    #[cfg(feature = "json")]
600    #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
601    pub fn json(self) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
602        Layer {
603            fmt_event: self.fmt_event.json(),
604            fmt_fields: format::JsonFields::new(),
605            fmt_span: self.fmt_span,
606            make_writer: self.make_writer,
607            // always disable ANSI escapes in JSON mode!
608            is_ansi: false,
609            log_internal_errors: self.log_internal_errors,
610            _inner: self._inner,
611        }
612    }
613}
614
615#[cfg(feature = "json")]
616#[cfg_attr(docsrs, doc(cfg(feature = "json")))]
617impl<S, T, W> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
618    /// Sets the JSON layer being built to flatten event metadata.
619    ///
620    /// See [`format::Json`][super::format::Json]
621    pub fn flatten_event(
622        self,
623        flatten_event: bool,
624    ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
625        Layer {
626            fmt_event: self.fmt_event.flatten_event(flatten_event),
627            fmt_fields: format::JsonFields::new(),
628            ..self
629        }
630    }
631
632    /// Sets whether or not the formatter will include the current span in
633    /// formatted events.
634    ///
635    /// See [`format::Json`][super::format::Json]
636    pub fn with_current_span(
637        self,
638        display_current_span: bool,
639    ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
640        Layer {
641            fmt_event: self.fmt_event.with_current_span(display_current_span),
642            fmt_fields: format::JsonFields::new(),
643            ..self
644        }
645    }
646
647    /// Sets whether or not the formatter will include a list (from root to leaf)
648    /// of all currently entered spans in formatted events.
649    ///
650    /// See [`format::Json`][super::format::Json]
651    pub fn with_span_list(
652        self,
653        display_span_list: bool,
654    ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
655        Layer {
656            fmt_event: self.fmt_event.with_span_list(display_span_list),
657            fmt_fields: format::JsonFields::new(),
658            ..self
659        }
660    }
661}
662
663impl<S, N, E, W> Layer<S, N, E, W> {
664    /// Sets the field formatter that the layer being built will use to record
665    /// fields.
666    pub fn fmt_fields<N2>(self, fmt_fields: N2) -> Layer<S, N2, E, W>
667    where
668        N2: for<'writer> FormatFields<'writer> + 'static,
669    {
670        Layer {
671            fmt_event: self.fmt_event,
672            fmt_fields,
673            fmt_span: self.fmt_span,
674            make_writer: self.make_writer,
675            is_ansi: self.is_ansi,
676            log_internal_errors: self.log_internal_errors,
677            _inner: self._inner,
678        }
679    }
680
681    /// Updates the field formatter by applying a function to the existing field formatter.
682    ///
683    /// This sets the field formatter that the layer being built will use to record fields.
684    ///
685    /// # Examples
686    ///
687    /// Updating a field formatter:
688    ///
689    /// ```rust
690    /// use tracing_subscriber::field::MakeExt;
691    /// let layer = tracing_subscriber::fmt::layer()
692    ///     .map_fmt_fields(|f| f.debug_alt());
693    /// # // this is necessary for type inference.
694    /// # use tracing_subscriber::Layer as _;
695    /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
696    /// ```
697    pub fn map_fmt_fields<N2>(self, f: impl FnOnce(N) -> N2) -> Layer<S, N2, E, W>
698    where
699        N2: for<'writer> FormatFields<'writer> + 'static,
700    {
701        Layer {
702            fmt_event: self.fmt_event,
703            fmt_fields: f(self.fmt_fields),
704            fmt_span: self.fmt_span,
705            make_writer: self.make_writer,
706            is_ansi: self.is_ansi,
707            log_internal_errors: self.log_internal_errors,
708            _inner: self._inner,
709        }
710    }
711}
712
713impl<S> Default for Layer<S> {
714    fn default() -> Self {
715        // only enable ANSI when the feature is enabled, and the NO_COLOR
716        // environment variable is unset or empty.
717        let ansi = cfg!(feature = "ansi") && env::var("NO_COLOR").map_or(true, |v| v.is_empty());
718
719        Layer {
720            fmt_fields: format::DefaultFields::default(),
721            fmt_event: format::Format::default(),
722            fmt_span: format::FmtSpanConfig::default(),
723            make_writer: io::stdout,
724            is_ansi: ansi,
725            log_internal_errors: false,
726            _inner: PhantomData,
727        }
728    }
729}
730
731impl<S, N, E, W> Layer<S, N, E, W>
732where
733    S: Subscriber + for<'a> LookupSpan<'a>,
734    N: for<'writer> FormatFields<'writer> + 'static,
735    E: FormatEvent<S, N> + 'static,
736    W: for<'writer> MakeWriter<'writer> + 'static,
737{
738    #[inline]
739    fn make_ctx<'a>(&'a self, ctx: Context<'a, S>, event: &'a Event<'a>) -> FmtContext<'a, S, N> {
740        FmtContext {
741            ctx,
742            fmt_fields: &self.fmt_fields,
743            event,
744        }
745    }
746}
747
748/// A formatted representation of a span's fields stored in its [extensions].
749///
750/// Because `FormattedFields` is generic over the type of the formatter that
751/// produced it, multiple versions of a span's formatted fields can be stored in
752/// the [`Extensions`][extensions] type-map. This means that when multiple
753/// formatters are in use, each can store its own formatted representation
754/// without conflicting.
755///
756/// [extensions]: crate::registry::Extensions
757#[derive(Default)]
758pub struct FormattedFields<E: ?Sized> {
759    _format_fields: PhantomData<fn(E)>,
760    was_ansi: bool,
761    /// The formatted fields of a span.
762    pub fields: String,
763}
764
765impl<E: ?Sized> FormattedFields<E> {
766    /// Returns a new `FormattedFields`.
767    pub fn new(fields: String) -> Self {
768        Self {
769            fields,
770            was_ansi: false,
771            _format_fields: PhantomData,
772        }
773    }
774
775    /// Returns a new [`format::Writer`] for writing to this `FormattedFields`.
776    ///
777    /// The returned [`format::Writer`] can be used with the
778    /// [`FormatFields::format_fields`] method.
779    pub fn as_writer(&mut self) -> format::Writer<'_> {
780        format::Writer::new(&mut self.fields).with_ansi(self.was_ansi)
781    }
782}
783
784impl<E: ?Sized> fmt::Debug for FormattedFields<E> {
785    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
786        f.debug_struct("FormattedFields")
787            .field("fields", &self.fields)
788            .field("formatter", &format_args!("{}", std::any::type_name::<E>()))
789            .field("was_ansi", &self.was_ansi)
790            .finish()
791    }
792}
793
794impl<E: ?Sized> fmt::Display for FormattedFields<E> {
795    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
796        fmt::Display::fmt(&self.fields, f)
797    }
798}
799
800impl<E: ?Sized> Deref for FormattedFields<E> {
801    type Target = String;
802    fn deref(&self) -> &Self::Target {
803        &self.fields
804    }
805}
806
807// === impl FmtLayer ===
808
809macro_rules! with_event_from_span {
810    ($id:ident, $span:ident, $($field:literal = $value:expr),*, |$event:ident| $code:block) => {
811        let meta = $span.metadata();
812        let cs = meta.callsite();
813        let fs = field::FieldSet::new(&[$($field),*], cs);
814        #[allow(unused)]
815        let mut iter = fs.iter();
816        let v = [$(
817            (&iter.next().unwrap(), ::core::option::Option::Some(&$value as &dyn field::Value)),
818        )*];
819        let vs = fs.value_set(&v);
820        let $event = Event::new_child_of($id, meta, &vs);
821        $code
822    };
823}
824
825impl<S, N, E, W> layer::Layer<S> for Layer<S, N, E, W>
826where
827    S: Subscriber + for<'a> LookupSpan<'a>,
828    N: for<'writer> FormatFields<'writer> + 'static,
829    E: FormatEvent<S, N> + 'static,
830    W: for<'writer> MakeWriter<'writer> + 'static,
831{
832    fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
833        let span = ctx.span(id).expect("Span not found, this is a bug");
834        let mut extensions = span.extensions_mut();
835
836        if extensions.get_mut::<FormattedFields<N>>().is_none() {
837            let mut fields = FormattedFields::<N>::new(String::new());
838            if self
839                .fmt_fields
840                .format_fields(fields.as_writer().with_ansi(self.is_ansi), attrs)
841                .is_ok()
842            {
843                fields.was_ansi = self.is_ansi;
844                extensions.insert(fields);
845            } else {
846                eprintln!(
847                    "[tracing-subscriber] Unable to format the following event, ignoring: {:?}",
848                    attrs
849                );
850            }
851        }
852
853        if self.fmt_span.fmt_timing
854            && self.fmt_span.trace_close()
855            && extensions.get_mut::<Timings>().is_none()
856        {
857            extensions.insert(Timings::new());
858        }
859
860        if self.fmt_span.trace_new() {
861            with_event_from_span!(id, span, "message" = "new", |event| {
862                drop(extensions);
863                drop(span);
864                self.on_event(&event, ctx);
865            });
866        }
867    }
868
869    fn on_record(&self, id: &Id, values: &Record<'_>, ctx: Context<'_, S>) {
870        let span = ctx.span(id).expect("Span not found, this is a bug");
871        let mut extensions = span.extensions_mut();
872        if let Some(fields) = extensions.get_mut::<FormattedFields<N>>() {
873            let _ = self.fmt_fields.add_fields(fields, values);
874            return;
875        }
876
877        let mut fields = FormattedFields::<N>::new(String::new());
878        if self
879            .fmt_fields
880            .format_fields(fields.as_writer().with_ansi(self.is_ansi), values)
881            .is_ok()
882        {
883            fields.was_ansi = self.is_ansi;
884            extensions.insert(fields);
885        }
886    }
887
888    fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
889        if self.fmt_span.trace_enter() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
890            let span = ctx.span(id).expect("Span not found, this is a bug");
891            let mut extensions = span.extensions_mut();
892            if let Some(timings) = extensions.get_mut::<Timings>() {
893                if timings.entered_count == 0 {
894                    let now = Instant::now();
895                    timings.idle += (now - timings.last).as_nanos() as u64;
896                    timings.last = now;
897                }
898                timings.entered_count += 1;
899            }
900
901            if self.fmt_span.trace_enter() {
902                with_event_from_span!(id, span, "message" = "enter", |event| {
903                    drop(extensions);
904                    drop(span);
905                    self.on_event(&event, ctx);
906                });
907            }
908        }
909    }
910
911    fn on_exit(&self, id: &Id, ctx: Context<'_, S>) {
912        if self.fmt_span.trace_exit() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
913            let span = ctx.span(id).expect("Span not found, this is a bug");
914            let mut extensions = span.extensions_mut();
915            if let Some(timings) = extensions.get_mut::<Timings>() {
916                timings.entered_count -= 1;
917                if timings.entered_count == 0 {
918                    let now = Instant::now();
919                    timings.busy += (now - timings.last).as_nanos() as u64;
920                    timings.last = now;
921                }
922            }
923
924            if self.fmt_span.trace_exit() {
925                with_event_from_span!(id, span, "message" = "exit", |event| {
926                    drop(extensions);
927                    drop(span);
928                    self.on_event(&event, ctx);
929                });
930            }
931        }
932    }
933
934    fn on_close(&self, id: Id, ctx: Context<'_, S>) {
935        if self.fmt_span.trace_close() {
936            let span = ctx.span(&id).expect("Span not found, this is a bug");
937            let extensions = span.extensions();
938            if let Some(timing) = extensions.get::<Timings>() {
939                let Timings {
940                    busy,
941                    mut idle,
942                    last,
943                    entered_count,
944                } = *timing;
945                debug_assert_eq!(entered_count, 0);
946                idle += (Instant::now() - last).as_nanos() as u64;
947
948                let t_idle = field::display(TimingDisplay(idle));
949                let t_busy = field::display(TimingDisplay(busy));
950
951                with_event_from_span!(
952                    id,
953                    span,
954                    "message" = "close",
955                    "time.busy" = t_busy,
956                    "time.idle" = t_idle,
957                    |event| {
958                        drop(extensions);
959                        drop(span);
960                        self.on_event(&event, ctx);
961                    }
962                );
963            } else {
964                with_event_from_span!(id, span, "message" = "close", |event| {
965                    drop(extensions);
966                    drop(span);
967                    self.on_event(&event, ctx);
968                });
969            }
970        }
971    }
972
973    fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
974        thread_local! {
975            static BUF: RefCell<String> = const { RefCell::new(String::new()) };
976        }
977
978        BUF.with(|buf| {
979            let borrow = buf.try_borrow_mut();
980            let mut a;
981            let mut b;
982            let mut buf = match borrow {
983                Ok(buf) => {
984                    a = buf;
985                    &mut *a
986                }
987                _ => {
988                    b = String::new();
989                    &mut b
990                }
991            };
992
993            let ctx = self.make_ctx(ctx, event);
994            if self
995                .fmt_event
996                .format_event(
997                    &ctx,
998                    format::Writer::new(&mut buf).with_ansi(self.is_ansi),
999                    event,
1000                )
1001                .is_ok()
1002            {
1003                let mut writer = self.make_writer.make_writer_for(event.metadata());
1004                let res = io::Write::write_all(&mut writer, buf.as_bytes());
1005                if self.log_internal_errors {
1006                    if let Err(e) = res {
1007                        eprintln!("[tracing-subscriber] Unable to write an event to the Writer for this Subscriber! Error: {}\n", e);
1008                    }
1009                }
1010            } else if self.log_internal_errors {
1011                let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}\n",
1012                    event.metadata().name(), event.fields());
1013                let mut writer = self.make_writer.make_writer_for(event.metadata());
1014                let res = io::Write::write_all(&mut writer, err_msg.as_bytes());
1015                if let Err(e) = res {
1016                    eprintln!("[tracing-subscriber] Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}\n", e);
1017                }
1018            }
1019
1020            buf.clear();
1021        });
1022    }
1023
1024    unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> {
1025        // This `downcast_raw` impl allows downcasting a `fmt` layer to any of
1026        // its components (event formatter, field formatter, and `MakeWriter`)
1027        // as well as to the layer's type itself. The potential use-cases for
1028        // this *may* be somewhat niche, though...
1029        match () {
1030            _ if id == TypeId::of::<Self>() => Some(self as *const Self as *const ()),
1031            _ if id == TypeId::of::<E>() => Some(&self.fmt_event as *const E as *const ()),
1032            _ if id == TypeId::of::<N>() => Some(&self.fmt_fields as *const N as *const ()),
1033            _ if id == TypeId::of::<W>() => Some(&self.make_writer as *const W as *const ()),
1034            _ => None,
1035        }
1036    }
1037}
1038
1039/// Provides the current span context to a formatter.
1040pub struct FmtContext<'a, S, N> {
1041    pub(crate) ctx: Context<'a, S>,
1042    pub(crate) fmt_fields: &'a N,
1043    pub(crate) event: &'a Event<'a>,
1044}
1045
1046impl<S, N> fmt::Debug for FmtContext<'_, S, N> {
1047    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1048        f.debug_struct("FmtContext").finish()
1049    }
1050}
1051
1052impl<'writer, S, N> FormatFields<'writer> for FmtContext<'_, S, N>
1053where
1054    S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1055    N: FormatFields<'writer> + 'static,
1056{
1057    fn format_fields<R: RecordFields>(
1058        &self,
1059        writer: format::Writer<'writer>,
1060        fields: R,
1061    ) -> fmt::Result {
1062        self.fmt_fields.format_fields(writer, fields)
1063    }
1064}
1065
1066impl<S, N> FmtContext<'_, S, N>
1067where
1068    S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1069    N: for<'writer> FormatFields<'writer> + 'static,
1070{
1071    /// Visits every span in the current context with a closure.
1072    ///
1073    /// The provided closure will be called first with the current span,
1074    /// and then with that span's parent, and then that span's parent,
1075    /// and so on until a root span is reached.
1076    pub fn visit_spans<E, F>(&self, mut f: F) -> Result<(), E>
1077    where
1078        F: FnMut(&SpanRef<'_, S>) -> Result<(), E>,
1079    {
1080        // visit all the current spans
1081        if let Some(scope) = self.event_scope() {
1082            for span in scope.from_root() {
1083                f(&span)?;
1084            }
1085        }
1086        Ok(())
1087    }
1088
1089    /// Returns metadata for the span with the given `id`, if it exists.
1090    ///
1091    /// If this returns `None`, then no span exists for that ID (either it has
1092    /// closed or the ID is invalid).
1093    #[inline]
1094    pub fn metadata(&self, id: &Id) -> Option<&'static Metadata<'static>>
1095    where
1096        S: for<'lookup> LookupSpan<'lookup>,
1097    {
1098        self.ctx.metadata(id)
1099    }
1100
1101    /// Returns [stored data] for the span with the given `id`, if it exists.
1102    ///
1103    /// If this returns `None`, then no span exists for that ID (either it has
1104    /// closed or the ID is invalid).
1105    ///
1106    /// [stored data]: crate::registry::SpanRef
1107    #[inline]
1108    pub fn span(&self, id: &Id) -> Option<SpanRef<'_, S>>
1109    where
1110        S: for<'lookup> LookupSpan<'lookup>,
1111    {
1112        self.ctx.span(id)
1113    }
1114
1115    /// Returns `true` if an active span exists for the given `Id`.
1116    #[inline]
1117    pub fn exists(&self, id: &Id) -> bool
1118    where
1119        S: for<'lookup> LookupSpan<'lookup>,
1120    {
1121        self.ctx.exists(id)
1122    }
1123
1124    /// Returns [stored data] for the span that the wrapped subscriber considers
1125    /// to be the current.
1126    ///
1127    /// If this returns `None`, then we are not currently within a span.
1128    ///
1129    /// [stored data]: crate::registry::SpanRef
1130    #[inline]
1131    pub fn lookup_current(&self) -> Option<SpanRef<'_, S>>
1132    where
1133        S: for<'lookup> LookupSpan<'lookup>,
1134    {
1135        self.ctx.lookup_current()
1136    }
1137
1138    /// Returns the current span for this formatter.
1139    pub fn current_span(&self) -> Current {
1140        self.ctx.current_span()
1141    }
1142
1143    /// Returns [stored data] for the parent span of the event currently being
1144    /// formatted.
1145    ///
1146    /// If the event has a contextual parent, this will return the current span. If
1147    /// the event has an explicit parent span, this will return that span. If
1148    /// the event does not have a parent span, this will return `None`.
1149    ///
1150    /// [stored data]: SpanRef
1151    pub fn parent_span(&self) -> Option<SpanRef<'_, S>> {
1152        self.ctx.event_span(self.event)
1153    }
1154
1155    /// Returns an iterator over the [stored data] for all the spans in the
1156    /// current context, starting with the specified span and ending with the
1157    /// root of the trace tree and ending with the current span.
1158    ///
1159    /// This is equivalent to the [`Context::span_scope`] method.
1160    ///
1161    /// <div class="information">
1162    ///     <div class="tooltip ignore" style="">ⓘ<span class="tooltiptext">Note</span></div>
1163    /// </div>
1164    /// <div class="example-wrap" style="display:inline-block">
1165    /// <pre class="ignore" style="white-space:normal;font:inherit;">
1166    /// <strong>Note</strong>: Compared to <a href="#method.scope"><code>scope</code></a> this
1167    /// returns the spans in reverse order (from leaf to root). Use
1168    /// <a href="../registry/struct.Scope.html#method.from_root"><code>Scope::from_root</code></a>
1169    /// in case root-to-leaf ordering is desired.
1170    /// </pre></div>
1171    ///
1172    /// <div class="example-wrap" style="display:inline-block">
1173    /// <pre class="ignore" style="white-space:normal;font:inherit;">
1174    /// <strong>Note</strong>: This requires the wrapped subscriber to implement the
1175    /// <a href="../registry/trait.LookupSpan.html"><code>LookupSpan</code></a> trait.
1176    /// See the documentation on <a href="./struct.Context.html"><code>Context</code>'s
1177    /// declaration</a> for details.
1178    /// </pre></div>
1179    ///
1180    /// [stored data]: crate::registry::SpanRef
1181    pub fn span_scope(&self, id: &Id) -> Option<registry::Scope<'_, S>>
1182    where
1183        S: for<'lookup> LookupSpan<'lookup>,
1184    {
1185        self.ctx.span_scope(id)
1186    }
1187
1188    /// Returns an iterator over the [stored data] for all the spans in the
1189    /// event's span context, starting with its parent span and ending with the
1190    /// root of the trace tree.
1191    ///
1192    /// This is equivalent to calling the [`Context::event_scope`] method and
1193    /// passing the event currently being formatted.
1194    ///
1195    /// <div class="example-wrap" style="display:inline-block">
1196    /// <pre class="ignore" style="white-space:normal;font:inherit;">
1197    /// <strong>Note</strong>: Compared to <a href="#method.scope"><code>scope</code></a> this
1198    /// returns the spans in reverse order (from leaf to root). Use
1199    /// <a href="../registry/struct.Scope.html#method.from_root"><code>Scope::from_root</code></a>
1200    /// in case root-to-leaf ordering is desired.
1201    /// </pre></div>
1202    ///
1203    /// <div class="example-wrap" style="display:inline-block">
1204    /// <pre class="ignore" style="white-space:normal;font:inherit;">
1205    /// <strong>Note</strong>: This requires the wrapped subscriber to implement the
1206    /// <a href="../registry/trait.LookupSpan.html"><code>LookupSpan</code></a> trait.
1207    /// See the documentation on <a href="./struct.Context.html"><code>Context</code>'s
1208    /// declaration</a> for details.
1209    /// </pre></div>
1210    ///
1211    /// [stored data]: crate::registry::SpanRef
1212    pub fn event_scope(&self) -> Option<registry::Scope<'_, S>>
1213    where
1214        S: for<'lookup> registry::LookupSpan<'lookup>,
1215    {
1216        self.ctx.event_scope(self.event)
1217    }
1218
1219    /// Returns the [field formatter] configured by the subscriber invoking
1220    /// `format_event`.
1221    ///
1222    /// The event formatter may use the returned field formatter to format the
1223    /// fields of any events it records.
1224    ///
1225    /// [field formatter]: FormatFields
1226    pub fn field_format(&self) -> &N {
1227        self.fmt_fields
1228    }
1229}
1230
1231struct Timings {
1232    idle: u64,
1233    busy: u64,
1234    last: Instant,
1235    entered_count: u64,
1236}
1237
1238impl Timings {
1239    fn new() -> Self {
1240        Self {
1241            idle: 0,
1242            busy: 0,
1243            last: Instant::now(),
1244            entered_count: 0,
1245        }
1246    }
1247}
1248
1249#[cfg(test)]
1250mod test {
1251    use super::*;
1252    use crate::fmt::{
1253        self,
1254        format::{self, test::MockTime, Format},
1255        layer::Layer as _,
1256        test::{MockMakeWriter, MockWriter},
1257        time,
1258    };
1259    use crate::Registry;
1260    use format::FmtSpan;
1261    use regex::Regex;
1262    use tracing::subscriber::with_default;
1263    use tracing_core::dispatcher::Dispatch;
1264
1265    #[test]
1266    fn impls() {
1267        let f = Format::default().with_timer(time::Uptime::default());
1268        let fmt = fmt::Layer::default().event_format(f);
1269        let subscriber = fmt.with_subscriber(Registry::default());
1270        let _dispatch = Dispatch::new(subscriber);
1271
1272        let f = format::Format::default();
1273        let fmt = fmt::Layer::default().event_format(f);
1274        let subscriber = fmt.with_subscriber(Registry::default());
1275        let _dispatch = Dispatch::new(subscriber);
1276
1277        let f = format::Format::default().compact();
1278        let fmt = fmt::Layer::default().event_format(f);
1279        let subscriber = fmt.with_subscriber(Registry::default());
1280        let _dispatch = Dispatch::new(subscriber);
1281    }
1282
1283    #[test]
1284    fn fmt_layer_downcasts() {
1285        let f = format::Format::default();
1286        let fmt = fmt::Layer::default().event_format(f);
1287        let subscriber = fmt.with_subscriber(Registry::default());
1288
1289        let dispatch = Dispatch::new(subscriber);
1290        assert!(dispatch.downcast_ref::<fmt::Layer<Registry>>().is_some());
1291    }
1292
1293    #[test]
1294    fn fmt_layer_downcasts_to_parts() {
1295        let f = format::Format::default();
1296        let fmt = fmt::Layer::default().event_format(f);
1297        let subscriber = fmt.with_subscriber(Registry::default());
1298        let dispatch = Dispatch::new(subscriber);
1299        assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some());
1300        assert!(dispatch.downcast_ref::<format::Format>().is_some())
1301    }
1302
1303    #[test]
1304    fn is_lookup_span() {
1305        fn assert_lookup_span<T: for<'a> crate::registry::LookupSpan<'a>>(_: T) {}
1306        let fmt = fmt::Layer::default();
1307        let subscriber = fmt.with_subscriber(Registry::default());
1308        assert_lookup_span(subscriber)
1309    }
1310
1311    fn sanitize_timings(s: String) -> String {
1312        let re = Regex::new("time\\.(idle|busy)=([0-9.]+)[mµn]s").unwrap();
1313        re.replace_all(s.as_str(), "timing").to_string()
1314    }
1315
1316    #[test]
1317    fn format_error_print_to_stderr() {
1318        struct AlwaysError;
1319
1320        impl std::fmt::Debug for AlwaysError {
1321            fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1322                Err(std::fmt::Error)
1323            }
1324        }
1325
1326        let make_writer = MockMakeWriter::default();
1327        let subscriber = crate::fmt::Subscriber::builder()
1328            .with_writer(make_writer.clone())
1329            .with_level(false)
1330            .with_ansi(false)
1331            .with_timer(MockTime)
1332            .finish();
1333
1334        with_default(subscriber, || {
1335            tracing::info!(?AlwaysError);
1336        });
1337        let actual = sanitize_timings(make_writer.get_string());
1338
1339        // Only assert the start because the line number and callsite may change.
1340        let expected = concat!(
1341            "Unable to format the following event. Name: event ",
1342            file!(),
1343            ":"
1344        );
1345        assert!(
1346            actual.as_str().starts_with(expected),
1347            "\nactual = {}\nshould start with expected = {}\n",
1348            actual,
1349            expected
1350        );
1351    }
1352
1353    #[test]
1354    fn format_error_ignore_if_log_internal_errors_is_false() {
1355        struct AlwaysError;
1356
1357        impl std::fmt::Debug for AlwaysError {
1358            fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1359                Err(std::fmt::Error)
1360            }
1361        }
1362
1363        let make_writer = MockMakeWriter::default();
1364        let subscriber = crate::fmt::Subscriber::builder()
1365            .with_writer(make_writer.clone())
1366            .with_level(false)
1367            .with_ansi(false)
1368            .with_timer(MockTime)
1369            .log_internal_errors(false)
1370            .finish();
1371
1372        with_default(subscriber, || {
1373            tracing::info!(?AlwaysError);
1374        });
1375        let actual = sanitize_timings(make_writer.get_string());
1376        assert_eq!("", actual.as_str());
1377    }
1378
1379    #[test]
1380    fn synthesize_span_none() {
1381        let make_writer = MockMakeWriter::default();
1382        let subscriber = crate::fmt::Subscriber::builder()
1383            .with_writer(make_writer.clone())
1384            .with_level(false)
1385            .with_ansi(false)
1386            .with_timer(MockTime)
1387            // check that FmtSpan::NONE is the default
1388            .finish();
1389
1390        with_default(subscriber, || {
1391            let span1 = tracing::info_span!("span1", x = 42);
1392            let _e = span1.enter();
1393        });
1394        let actual = sanitize_timings(make_writer.get_string());
1395        assert_eq!("", actual.as_str());
1396    }
1397
1398    #[test]
1399    fn synthesize_span_active() {
1400        let make_writer = MockMakeWriter::default();
1401        let subscriber = crate::fmt::Subscriber::builder()
1402            .with_writer(make_writer.clone())
1403            .with_level(false)
1404            .with_ansi(false)
1405            .with_timer(MockTime)
1406            .with_span_events(FmtSpan::ACTIVE)
1407            .finish();
1408
1409        with_default(subscriber, || {
1410            let span1 = tracing::info_span!("span1", x = 42);
1411            let _e = span1.enter();
1412        });
1413        let actual = sanitize_timings(make_writer.get_string());
1414        assert_eq!(
1415            "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1416             fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n",
1417            actual.as_str()
1418        );
1419    }
1420
1421    #[test]
1422    fn synthesize_span_close() {
1423        let make_writer = MockMakeWriter::default();
1424        let subscriber = crate::fmt::Subscriber::builder()
1425            .with_writer(make_writer.clone())
1426            .with_level(false)
1427            .with_ansi(false)
1428            .with_timer(MockTime)
1429            .with_span_events(FmtSpan::CLOSE)
1430            .finish();
1431
1432        with_default(subscriber, || {
1433            let span1 = tracing::info_span!("span1", x = 42);
1434            let _e = span1.enter();
1435        });
1436        let actual = sanitize_timings(make_writer.get_string());
1437        assert_eq!(
1438            "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n",
1439            actual.as_str()
1440        );
1441    }
1442
1443    #[test]
1444    fn synthesize_span_close_no_timing() {
1445        let make_writer = MockMakeWriter::default();
1446        let subscriber = crate::fmt::Subscriber::builder()
1447            .with_writer(make_writer.clone())
1448            .with_level(false)
1449            .with_ansi(false)
1450            .with_timer(MockTime)
1451            .without_time()
1452            .with_span_events(FmtSpan::CLOSE)
1453            .finish();
1454
1455        with_default(subscriber, || {
1456            let span1 = tracing::info_span!("span1", x = 42);
1457            let _e = span1.enter();
1458        });
1459        let actual = sanitize_timings(make_writer.get_string());
1460        assert_eq!(
1461            "span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close\n",
1462            actual.as_str()
1463        );
1464    }
1465
1466    #[test]
1467    fn synthesize_span_full() {
1468        let make_writer = MockMakeWriter::default();
1469        let subscriber = crate::fmt::Subscriber::builder()
1470            .with_writer(make_writer.clone())
1471            .with_level(false)
1472            .with_ansi(false)
1473            .with_timer(MockTime)
1474            .with_span_events(FmtSpan::FULL)
1475            .finish();
1476
1477        with_default(subscriber, || {
1478            let span1 = tracing::info_span!("span1", x = 42);
1479            let _e = span1.enter();
1480        });
1481        let actual = sanitize_timings(make_writer.get_string());
1482        assert_eq!(
1483            "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: new\n\
1484             fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1485             fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\
1486             fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n",
1487            actual.as_str()
1488        );
1489    }
1490
1491    #[test]
1492    fn make_writer_based_on_meta() {
1493        struct MakeByTarget {
1494            make_writer1: MockMakeWriter,
1495            make_writer2: MockMakeWriter,
1496        }
1497
1498        impl<'a> MakeWriter<'a> for MakeByTarget {
1499            type Writer = MockWriter;
1500
1501            fn make_writer(&'a self) -> Self::Writer {
1502                self.make_writer1.make_writer()
1503            }
1504
1505            fn make_writer_for(&'a self, meta: &Metadata<'_>) -> Self::Writer {
1506                if meta.target() == "writer2" {
1507                    return self.make_writer2.make_writer();
1508                }
1509                self.make_writer()
1510            }
1511        }
1512
1513        let make_writer1 = MockMakeWriter::default();
1514        let make_writer2 = MockMakeWriter::default();
1515
1516        let make_writer = MakeByTarget {
1517            make_writer1: make_writer1.clone(),
1518            make_writer2: make_writer2.clone(),
1519        };
1520
1521        let subscriber = crate::fmt::Subscriber::builder()
1522            .with_writer(make_writer)
1523            .with_level(false)
1524            .with_target(false)
1525            .with_ansi(false)
1526            .with_timer(MockTime)
1527            .with_span_events(FmtSpan::CLOSE)
1528            .finish();
1529
1530        with_default(subscriber, || {
1531            let span1 = tracing::info_span!("writer1_span", x = 42);
1532            let _e = span1.enter();
1533            tracing::info!(target: "writer2", "hello writer2!");
1534            let span2 = tracing::info_span!(target: "writer2", "writer2_span");
1535            let _e = span2.enter();
1536            tracing::warn!(target: "writer1", "hello writer1!");
1537        });
1538
1539        let actual = sanitize_timings(make_writer1.get_string());
1540        assert_eq!(
1541            "fake time writer1_span{x=42}:writer2_span: hello writer1!\n\
1542             fake time writer1_span{x=42}: close timing timing\n",
1543            actual.as_str()
1544        );
1545        let actual = sanitize_timings(make_writer2.get_string());
1546        assert_eq!(
1547            "fake time writer1_span{x=42}: hello writer2!\n\
1548             fake time writer1_span{x=42}:writer2_span: close timing timing\n",
1549            actual.as_str()
1550        );
1551    }
1552
1553    // Because we need to modify an environment variable for these test cases,
1554    // we do them all in a single test.
1555    #[cfg(feature = "ansi")]
1556    #[test]
1557    fn layer_no_color() {
1558        const NO_COLOR: &str = "NO_COLOR";
1559
1560        // Restores the previous value of the `NO_COLOR` env variable when
1561        // dropped.
1562        //
1563        // This is done in a `Drop` implementation, rather than just resetting
1564        // the value at the end of the test, so that the previous value is
1565        // restored even if the test panics.
1566        struct RestoreEnvVar(Result<String, env::VarError>);
1567        impl Drop for RestoreEnvVar {
1568            fn drop(&mut self) {
1569                match self.0 {
1570                    Ok(ref var) => env::set_var(NO_COLOR, var),
1571                    Err(_) => env::remove_var(NO_COLOR),
1572                }
1573            }
1574        }
1575
1576        let _saved_no_color = RestoreEnvVar(env::var(NO_COLOR));
1577
1578        let cases: Vec<(Option<&str>, bool)> = vec![
1579            (Some("0"), false),   // any non-empty value disables ansi
1580            (Some("off"), false), // any non-empty value disables ansi
1581            (Some("1"), false),
1582            (Some(""), true), // empty value does not disable ansi
1583            (None, true),
1584        ];
1585
1586        for (var, ansi) in cases {
1587            if let Some(value) = var {
1588                env::set_var(NO_COLOR, value);
1589            } else {
1590                env::remove_var(NO_COLOR);
1591            }
1592
1593            let layer: Layer<()> = fmt::Layer::default();
1594            assert_eq!(
1595                layer.is_ansi, ansi,
1596                "NO_COLOR={:?}; Layer::default().is_ansi should be {}",
1597                var, ansi
1598            );
1599
1600            // with_ansi should override any `NO_COLOR` value
1601            let layer: Layer<()> = fmt::Layer::default().with_ansi(true);
1602            assert!(
1603                layer.is_ansi,
1604                "NO_COLOR={:?}; Layer::default().with_ansi(true).is_ansi should be true",
1605                var
1606            );
1607
1608            // set_ansi should override any `NO_COLOR` value
1609            let mut layer: Layer<()> = fmt::Layer::default();
1610            layer.set_ansi(true);
1611            assert!(
1612                layer.is_ansi,
1613                "NO_COLOR={:?}; layer.set_ansi(true); layer.is_ansi should be true",
1614                var
1615            );
1616        }
1617
1618        // dropping `_saved_no_color` will restore the previous value of
1619        // `NO_COLOR`.
1620    }
1621
1622    // Validates that span event configuration can be modified with a reload handle
1623    #[test]
1624    fn modify_span_events() {
1625        let make_writer = MockMakeWriter::default();
1626
1627        let inner_layer = fmt::Layer::default()
1628            .with_writer(make_writer.clone())
1629            .with_level(false)
1630            .with_ansi(false)
1631            .with_timer(MockTime)
1632            .with_span_events(FmtSpan::ACTIVE);
1633
1634        let (reloadable_layer, reload_handle) =
1635            crate::reload::Layer::new(inner_layer);
1636        let reload = reloadable_layer.with_subscriber(Registry::default());
1637
1638        with_default(reload, || {
1639            {
1640                let span1 = tracing::info_span!("span1", x = 42);
1641                let _e = span1.enter();
1642            }
1643
1644            let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::NONE));
1645
1646            // this span should not be logged at all!
1647            {
1648                let span2 = tracing::info_span!("span2", x = 100);
1649                let _e = span2.enter();
1650            }
1651
1652            {
1653                let span3 = tracing::info_span!("span3", x = 42);
1654                let _e = span3.enter();
1655
1656                // The span config was modified after span3 was already entered.
1657                // We should only see an exit
1658                let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::ACTIVE));
1659            }
1660        });
1661        let actual = sanitize_timings(make_writer.get_string());
1662        assert_eq!(
1663            "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1664             fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\
1665             fake time span3{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n",
1666            actual.as_str()
1667        );
1668    }
1669}