1 //! Formatters for logging `tracing` events.
2 use super::time::{FormatTime, SystemTime};
3 use crate::{
4     field::{MakeOutput, MakeVisitor, RecordFields, VisitFmt, VisitOutput},
5     fmt::fmt_layer::FmtContext,
6     fmt::fmt_layer::FormattedFields,
7     registry::LookupSpan,
8 };
9 
10 use std::fmt::{self, Write};
11 use tracing_core::{
12     field::{self, Field, Visit},
13     span, Event, Level, Subscriber,
14 };
15 
16 #[cfg(feature = "tracing-log")]
17 use tracing_log::NormalizeEvent;
18 
19 #[cfg(feature = "ansi")]
20 use ansi_term::{Colour, Style};
21 
22 #[cfg(feature = "json")]
23 mod json;
24 #[cfg(feature = "json")]
25 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
26 pub use json::*;
27 
28 #[cfg(feature = "ansi")]
29 mod pretty;
30 #[cfg(feature = "ansi")]
31 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
32 pub use pretty::*;
33 
34 use fmt::{Debug, Display};
35 
36 /// A type that can format a tracing `Event` for a `fmt::Write`.
37 ///
38 /// `FormatEvent` is primarily used in the context of [`fmt::Subscriber`] or [`fmt::Layer`]. Each time an event is
39 /// dispatched to [`fmt::Subscriber`] or [`fmt::Layer`], the subscriber or layer forwards it to
40 /// its associated `FormatEvent` to emit a log message.
41 ///
42 /// This trait is already implemented for function pointers with the same
43 /// signature as `format_event`.
44 ///
45 /// # Examples
46 ///
47 /// ```rust
48 /// use std::fmt::{self, Write};
49 /// use tracing_core::{Subscriber, Event};
50 /// use tracing_subscriber::fmt::{FormatEvent, FormatFields, FmtContext, FormattedFields};
51 /// use tracing_subscriber::registry::LookupSpan;
52 ///
53 /// struct MyFormatter;
54 ///
55 /// impl<S, N> FormatEvent<S, N> for MyFormatter
56 /// where
57 ///     S: Subscriber + for<'a> LookupSpan<'a>,
58 ///     N: for<'a> FormatFields<'a> + 'static,
59 /// {
60 ///     fn format_event(
61 ///         &self,
62 ///         ctx: &FmtContext<'_, S, N>,
63 ///         writer: &mut dyn fmt::Write,
64 ///         event: &Event<'_>,
65 ///     ) -> fmt::Result {
66 ///         // Write level and target
67 ///         let level = *event.metadata().level();
68 ///         let target = event.metadata().target();
69 ///         write!(
70 ///             writer,
71 ///             "{} {}: ",
72 ///             level,
73 ///             target,
74 ///         )?;
75 ///
76 ///         // Write spans and fields of each span
77 ///         ctx.visit_spans(|span| {
78 ///             write!(writer, "{}", span.name())?;
79 ///
80 ///             let ext = span.extensions();
81 ///
82 ///             // `FormattedFields` is a a formatted representation of the span's
83 ///             // fields, which is stored in its extensions by the `fmt` layer's
84 ///             // `new_span` method. The fields will have been formatted
85 ///             // by the same field formatter that's provided to the event
86 ///             // formatter in the `FmtContext`.
87 ///             let fields = &ext
88 ///                 .get::<FormattedFields<N>>()
89 ///                 .expect("will never be `None`");
90 ///
91 ///             if !fields.is_empty() {
92 ///                 write!(writer, "{{{}}}", fields)?;
93 ///             }
94 ///             write!(writer, ": ")?;
95 ///
96 ///             Ok(())
97 ///         })?;
98 ///
99 ///         // Write fields on the event
100 ///         ctx.field_format().format_fields(writer, event)?;
101 ///
102 ///         writeln!(writer)
103 ///     }
104 /// }
105 /// ```
106 ///
107 /// This formatter will print events like this:
108 ///
109 /// ```text
110 /// DEBUG yak_shaving::shaver: some-span{field-on-span=foo}: started shaving yak
111 /// ```
112 ///
113 /// [`fmt::Subscriber`]: ../struct.Subscriber.html
114 /// [`fmt::Layer`]: ../struct.Layer.html
115 pub trait FormatEvent<S, N>
116 where
117     S: Subscriber + for<'a> LookupSpan<'a>,
118     N: for<'a> FormatFields<'a> + 'static,
119 {
120     /// Write a log message for `Event` in `Context` to the given `Write`.
format_event( &self, ctx: &FmtContext<'_, S, N>, writer: &mut dyn fmt::Write, event: &Event<'_>, ) -> fmt::Result121     fn format_event(
122         &self,
123         ctx: &FmtContext<'_, S, N>,
124         writer: &mut dyn fmt::Write,
125         event: &Event<'_>,
126     ) -> fmt::Result;
127 }
128 
129 impl<S, N> FormatEvent<S, N>
130     for fn(ctx: &FmtContext<'_, S, N>, &mut dyn fmt::Write, &Event<'_>) -> fmt::Result
131 where
132     S: Subscriber + for<'a> LookupSpan<'a>,
133     N: for<'a> FormatFields<'a> + 'static,
134 {
format_event( &self, ctx: &FmtContext<'_, S, N>, writer: &mut dyn fmt::Write, event: &Event<'_>, ) -> fmt::Result135     fn format_event(
136         &self,
137         ctx: &FmtContext<'_, S, N>,
138         writer: &mut dyn fmt::Write,
139         event: &Event<'_>,
140     ) -> fmt::Result {
141         (*self)(ctx, writer, event)
142     }
143 }
144 /// A type that can format a [set of fields] to a `fmt::Write`.
145 ///
146 /// `FormatFields` is primarily used in the context of [`FmtSubscriber`]. Each
147 /// time a span or event with fields is recorded, the subscriber will format
148 /// those fields with its associated `FormatFields` implementation.
149 ///
150 /// [set of fields]: ../field/trait.RecordFields.html
151 /// [`FmtSubscriber`]: ../fmt/struct.Subscriber.html
152 pub trait FormatFields<'writer> {
153     /// Format the provided `fields` to the provided `writer`, returning a result.
format_fields<R: RecordFields>( &self, writer: &'writer mut dyn fmt::Write, fields: R, ) -> fmt::Result154     fn format_fields<R: RecordFields>(
155         &self,
156         writer: &'writer mut dyn fmt::Write,
157         fields: R,
158     ) -> fmt::Result;
159 
160     /// Record additional field(s) on an existing span.
161     ///
162     /// By default, this appends a space to the current set of fields if it is
163     /// non-empty, and then calls `self.format_fields`. If different behavior is
164     /// required, the default implementation of this method can be overridden.
add_fields(&self, current: &'writer mut String, fields: &span::Record<'_>) -> fmt::Result165     fn add_fields(&self, current: &'writer mut String, fields: &span::Record<'_>) -> fmt::Result {
166         if !current.is_empty() {
167             current.push(' ');
168         }
169         self.format_fields(current, fields)
170     }
171 }
172 
173 /// Returns the default configuration for an [event formatter].
174 ///
175 /// Methods on the returned event formatter can be used for further
176 /// configuration. For example:
177 ///
178 /// ```rust
179 /// let format = tracing_subscriber::fmt::format()
180 ///     .without_time()         // Don't include timestamps
181 ///     .with_target(false)     // Don't include event targets.
182 ///     .with_level(false)      // Don't include event levels.
183 ///     .compact();             // Use a more compact, abbreviated format.
184 ///
185 /// // Use the configured formatter when building a new subscriber.
186 /// tracing_subscriber::fmt()
187 ///     .event_format(format)
188 ///     .init();
189 /// ```
format() -> Format190 pub fn format() -> Format {
191     Format::default()
192 }
193 
194 /// Returns the default configuration for a JSON [event formatter].
195 #[cfg(feature = "json")]
196 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
json() -> Format<Json>197 pub fn json() -> Format<Json> {
198     format().json()
199 }
200 
201 /// Returns a [`FormatFields`] implementation that formats fields using the
202 /// provided function or closure.
203 ///
204 /// [`FormatFields`]: trait.FormatFields.html
debug_fn<F>(f: F) -> FieldFn<F> where F: Fn(&mut dyn fmt::Write, &Field, &dyn fmt::Debug) -> fmt::Result + Clone,205 pub fn debug_fn<F>(f: F) -> FieldFn<F>
206 where
207     F: Fn(&mut dyn fmt::Write, &Field, &dyn fmt::Debug) -> fmt::Result + Clone,
208 {
209     FieldFn(f)
210 }
211 
212 /// A [`FormatFields`] implementation that formats fields by calling a function
213 /// or closure.
214 ///
215 /// [`FormatFields`]: trait.FormatFields.html
216 #[derive(Debug, Clone)]
217 pub struct FieldFn<F>(F);
218 /// The [visitor] produced by [`FieldFn`]'s [`MakeVisitor`] implementation.
219 ///
220 /// [visitor]: ../../field/trait.Visit.html
221 /// [`FieldFn`]: struct.FieldFn.html
222 /// [`MakeVisitor`]: ../../field/trait.MakeVisitor.html
223 pub struct FieldFnVisitor<'a, F> {
224     f: F,
225     writer: &'a mut dyn fmt::Write,
226     result: fmt::Result,
227 }
228 /// Marker for `Format` that indicates that the compact log format should be used.
229 ///
230 /// The compact format only includes the fields from the most recently entered span.
231 #[derive(Default, Debug, Copy, Clone, Eq, PartialEq)]
232 pub struct Compact;
233 
234 /// Marker for `Format` that indicates that the verbose log format should be used.
235 ///
236 /// The full format includes fields from all entered spans.
237 #[derive(Default, Debug, Copy, Clone, Eq, PartialEq)]
238 pub struct Full;
239 
240 /// A pre-configured event formatter.
241 ///
242 /// You will usually want to use this as the `FormatEvent` for a `FmtSubscriber`.
243 ///
244 /// The default logging format, [`Full`] includes all fields in each event and its containing
245 /// spans. The [`Compact`] logging format includes only the fields from the most-recently-entered
246 /// span.
247 #[derive(Debug, Clone)]
248 pub struct Format<F = Full, T = SystemTime> {
249     format: F,
250     pub(crate) timer: T,
251     pub(crate) ansi: bool,
252     pub(crate) display_timestamp: bool,
253     pub(crate) display_target: bool,
254     pub(crate) display_level: bool,
255     pub(crate) display_thread_id: bool,
256     pub(crate) display_thread_name: bool,
257 }
258 
259 impl Default for Format<Full, SystemTime> {
default() -> Self260     fn default() -> Self {
261         Format {
262             format: Full,
263             timer: SystemTime,
264             ansi: true,
265             display_timestamp: true,
266             display_target: true,
267             display_level: true,
268             display_thread_id: false,
269             display_thread_name: false,
270         }
271     }
272 }
273 
274 impl<F, T> Format<F, T> {
275     /// Use a less verbose output format.
276     ///
277     /// See [`Compact`].
compact(self) -> Format<Compact, T>278     pub fn compact(self) -> Format<Compact, T> {
279         Format {
280             format: Compact,
281             timer: self.timer,
282             ansi: self.ansi,
283             display_target: self.display_target,
284             display_timestamp: self.display_timestamp,
285             display_level: self.display_level,
286             display_thread_id: self.display_thread_id,
287             display_thread_name: self.display_thread_name,
288         }
289     }
290 
291     /// Use an excessively pretty, human-readable output format.
292     ///
293     /// See [`Pretty`].
294     ///
295     /// Note that this requires the "ansi" feature to be enabled.
296     ///
297     /// # Options
298     ///
299     /// [`Format::with_ansi`] can be used to disable ANSI terminal escape codes (which enable
300     /// formatting such as colors, bold, italic, etc) in event formatting. However, a field
301     /// formatter must be manually provided to avoid ANSI in the formatting of parent spans, like
302     /// so:
303     ///
304     /// ```
305     /// # use tracing_subscriber::fmt::format;
306     /// tracing_subscriber::fmt()
307     ///    .pretty()
308     ///    .with_ansi(false)
309     ///    .fmt_fields(format::PrettyFields::new().with_ansi(false))
310     ///    // ... other settings ...
311     ///    .init();
312     /// ```
313     #[cfg(feature = "ansi")]
314     #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
pretty(self) -> Format<Pretty, T>315     pub fn pretty(self) -> Format<Pretty, T> {
316         Format {
317             format: Pretty::default(),
318             timer: self.timer,
319             ansi: self.ansi,
320             display_target: self.display_target,
321             display_timestamp: self.display_timestamp,
322             display_level: self.display_level,
323             display_thread_id: self.display_thread_id,
324             display_thread_name: self.display_thread_name,
325         }
326     }
327 
328     /// Use the full JSON format.
329     ///
330     /// The full format includes fields from all entered spans.
331     ///
332     /// # Example Output
333     ///
334     /// ```ignore,json
335     /// {"timestamp":"Feb 20 11:28:15.096","level":"INFO","target":"mycrate","fields":{"message":"some message", "key": "value"}}
336     /// ```
337     ///
338     /// # Options
339     ///
340     /// - [`Format::flatten_event`] can be used to enable flattening event fields into the root
341     /// object.
342     ///
343     /// [`Format::flatten_event`]: #method.flatten_event
344     #[cfg(feature = "json")]
345     #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
json(self) -> Format<Json, T>346     pub fn json(self) -> Format<Json, T> {
347         Format {
348             format: Json::default(),
349             timer: self.timer,
350             ansi: self.ansi,
351             display_target: self.display_target,
352             display_timestamp: self.display_timestamp,
353             display_level: self.display_level,
354             display_thread_id: self.display_thread_id,
355             display_thread_name: self.display_thread_name,
356         }
357     }
358 
359     /// Use the given [`timer`] for log message timestamps.
360     ///
361     /// See [`time` module] for the provided timer implementations.
362     ///
363     /// Note that using the `chrono` feature flag enables the
364     /// additional time formatters [`ChronoUtc`] and [`ChronoLocal`].
365     ///
366     /// [`timer`]: super::time::FormatTime
367     /// [`time` module]: mod@super::time
368     /// [`ChronoUtc`]: super::time::ChronoUtc
369     /// [`ChronoLocal`]: super::time::ChronoLocal
with_timer<T2>(self, timer: T2) -> Format<F, T2>370     pub fn with_timer<T2>(self, timer: T2) -> Format<F, T2> {
371         Format {
372             format: self.format,
373             timer,
374             ansi: self.ansi,
375             display_target: self.display_target,
376             display_timestamp: self.display_timestamp,
377             display_level: self.display_level,
378             display_thread_id: self.display_thread_id,
379             display_thread_name: self.display_thread_name,
380         }
381     }
382 
383     /// Do not emit timestamps with log messages.
without_time(self) -> Format<F, ()>384     pub fn without_time(self) -> Format<F, ()> {
385         Format {
386             format: self.format,
387             timer: (),
388             ansi: self.ansi,
389             display_timestamp: false,
390             display_target: self.display_target,
391             display_level: self.display_level,
392             display_thread_id: self.display_thread_id,
393             display_thread_name: self.display_thread_name,
394         }
395     }
396 
397     /// Enable ANSI terminal colors for formatted output.
with_ansi(self, ansi: bool) -> Format<F, T>398     pub fn with_ansi(self, ansi: bool) -> Format<F, T> {
399         Format { ansi, ..self }
400     }
401 
402     /// Sets whether or not an event's target is displayed.
with_target(self, display_target: bool) -> Format<F, T>403     pub fn with_target(self, display_target: bool) -> Format<F, T> {
404         Format {
405             display_target,
406             ..self
407         }
408     }
409 
410     /// Sets whether or not an event's level is displayed.
with_level(self, display_level: bool) -> Format<F, T>411     pub fn with_level(self, display_level: bool) -> Format<F, T> {
412         Format {
413             display_level,
414             ..self
415         }
416     }
417 
418     /// Sets whether or not the [thread ID] of the current thread is displayed
419     /// when formatting events
420     ///
421     /// [thread ID]: https://doc.rust-lang.org/stable/std/thread/struct.ThreadId.html
with_thread_ids(self, display_thread_id: bool) -> Format<F, T>422     pub fn with_thread_ids(self, display_thread_id: bool) -> Format<F, T> {
423         Format {
424             display_thread_id,
425             ..self
426         }
427     }
428 
429     /// Sets whether or not the [name] of the current thread is displayed
430     /// when formatting events
431     ///
432     /// [name]: https://doc.rust-lang.org/stable/std/thread/index.html#naming-threads
with_thread_names(self, display_thread_name: bool) -> Format<F, T>433     pub fn with_thread_names(self, display_thread_name: bool) -> Format<F, T> {
434         Format {
435             display_thread_name,
436             ..self
437         }
438     }
439 
440     #[inline]
format_timestamp(&self, writer: &mut dyn fmt::Write) -> fmt::Result where T: FormatTime,441     fn format_timestamp(&self, writer: &mut dyn fmt::Write) -> fmt::Result
442     where
443         T: FormatTime,
444     {
445         // If timestamps are disabled, do nothing.
446         if !self.display_timestamp {
447             return Ok(());
448         }
449 
450         // If ANSI color codes are enabled, format the timestamp with ANSI
451         // colors.
452         #[cfg(feature = "ansi")]
453         {
454             if self.ansi {
455                 let style = Style::new().dimmed();
456                 write!(writer, "{}", style.prefix())?;
457                 self.timer.format_time(writer)?;
458                 write!(writer, "{} ", style.suffix())?;
459                 return Ok(());
460             }
461         }
462 
463         // Otherwise, just format the timestamp without ANSI formatting.
464         self.timer.format_time(writer)?;
465         writer.write_char(' ')
466     }
467 }
468 
469 #[cfg(feature = "json")]
470 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
471 impl<T> Format<Json, T> {
472     /// Use the full JSON format with the event's event fields flattened.
473     ///
474     /// # Example Output
475     ///
476     /// ```ignore,json
477     /// {"timestamp":"Feb 20 11:28:15.096","level":"INFO","target":"mycrate", "message":"some message", "key": "value"}
478     /// ```
479     /// See [`Json`](../format/struct.Json.html).
480     #[cfg(feature = "json")]
481     #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
flatten_event(mut self, flatten_event: bool) -> Format<Json, T>482     pub fn flatten_event(mut self, flatten_event: bool) -> Format<Json, T> {
483         self.format.flatten_event(flatten_event);
484         self
485     }
486 
487     /// Sets whether or not the formatter will include the current span in
488     /// formatted events.
489     ///
490     /// See [`format::Json`](../fmt/format/struct.Json.html)
491     #[cfg(feature = "json")]
492     #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
with_current_span(mut self, display_current_span: bool) -> Format<Json, T>493     pub fn with_current_span(mut self, display_current_span: bool) -> Format<Json, T> {
494         self.format.with_current_span(display_current_span);
495         self
496     }
497 
498     /// Sets whether or not the formatter will include a list (from root to
499     /// leaf) of all currently entered spans in formatted events.
500     ///
501     /// See [`format::Json`](../fmt/format/struct.Json.html)
502     #[cfg(feature = "json")]
503     #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
with_span_list(mut self, display_span_list: bool) -> Format<Json, T>504     pub fn with_span_list(mut self, display_span_list: bool) -> Format<Json, T> {
505         self.format.with_span_list(display_span_list);
506         self
507     }
508 }
509 
510 impl<S, N, T> FormatEvent<S, N> for Format<Full, T>
511 where
512     S: Subscriber + for<'a> LookupSpan<'a>,
513     N: for<'a> FormatFields<'a> + 'static,
514     T: FormatTime,
515 {
format_event( &self, ctx: &FmtContext<'_, S, N>, writer: &mut dyn fmt::Write, event: &Event<'_>, ) -> fmt::Result516     fn format_event(
517         &self,
518         ctx: &FmtContext<'_, S, N>,
519         writer: &mut dyn fmt::Write,
520         event: &Event<'_>,
521     ) -> fmt::Result {
522         #[cfg(feature = "tracing-log")]
523         let normalized_meta = event.normalized_metadata();
524         #[cfg(feature = "tracing-log")]
525         let meta = normalized_meta.as_ref().unwrap_or_else(|| event.metadata());
526         #[cfg(not(feature = "tracing-log"))]
527         let meta = event.metadata();
528 
529         self.format_timestamp(writer)?;
530 
531         if self.display_level {
532             let fmt_level = {
533                 #[cfg(feature = "ansi")]
534                 {
535                     FmtLevel::new(meta.level(), self.ansi)
536                 }
537                 #[cfg(not(feature = "ansi"))]
538                 {
539                     FmtLevel::new(meta.level())
540                 }
541             };
542             write!(writer, "{} ", fmt_level)?;
543         }
544 
545         if self.display_thread_name {
546             let current_thread = std::thread::current();
547             match current_thread.name() {
548                 Some(name) => {
549                     write!(writer, "{} ", FmtThreadName::new(name))?;
550                 }
551                 // fall-back to thread id when name is absent and ids are not enabled
552                 None if !self.display_thread_id => {
553                     write!(writer, "{:0>2?} ", current_thread.id())?;
554                 }
555                 _ => {}
556             }
557         }
558 
559         if self.display_thread_id {
560             write!(writer, "{:0>2?} ", std::thread::current().id())?;
561         }
562 
563         let full_ctx = {
564             #[cfg(feature = "ansi")]
565             {
566                 FullCtx::new(ctx, event.parent(), self.ansi)
567             }
568             #[cfg(not(feature = "ansi"))]
569             {
570                 FullCtx::new(ctx, event.parent())
571             }
572         };
573 
574         write!(writer, "{}", full_ctx)?;
575         if self.display_target {
576             write!(writer, "{}: ", meta.target())?;
577         }
578         ctx.format_fields(writer, event)?;
579         writeln!(writer)
580     }
581 }
582 
583 impl<S, N, T> FormatEvent<S, N> for Format<Compact, T>
584 where
585     S: Subscriber + for<'a> LookupSpan<'a>,
586     N: for<'a> FormatFields<'a> + 'static,
587     T: FormatTime,
588 {
format_event( &self, ctx: &FmtContext<'_, S, N>, writer: &mut dyn fmt::Write, event: &Event<'_>, ) -> fmt::Result589     fn format_event(
590         &self,
591         ctx: &FmtContext<'_, S, N>,
592         writer: &mut dyn fmt::Write,
593         event: &Event<'_>,
594     ) -> fmt::Result {
595         #[cfg(feature = "tracing-log")]
596         let normalized_meta = event.normalized_metadata();
597         #[cfg(feature = "tracing-log")]
598         let meta = normalized_meta.as_ref().unwrap_or_else(|| event.metadata());
599         #[cfg(not(feature = "tracing-log"))]
600         let meta = event.metadata();
601 
602         self.format_timestamp(writer)?;
603 
604         if self.display_level {
605             let fmt_level = {
606                 #[cfg(feature = "ansi")]
607                 {
608                     FmtLevel::new(meta.level(), self.ansi)
609                 }
610                 #[cfg(not(feature = "ansi"))]
611                 {
612                     FmtLevel::new(meta.level())
613                 }
614             };
615             write!(writer, "{} ", fmt_level)?;
616         }
617 
618         if self.display_thread_name {
619             let current_thread = std::thread::current();
620             match current_thread.name() {
621                 Some(name) => {
622                     write!(writer, "{} ", FmtThreadName::new(name))?;
623                 }
624                 // fall-back to thread id when name is absent and ids are not enabled
625                 None if !self.display_thread_id => {
626                     write!(writer, "{:0>2?} ", current_thread.id())?;
627                 }
628                 _ => {}
629             }
630         }
631 
632         if self.display_thread_id {
633             write!(writer, "{:0>2?} ", std::thread::current().id())?;
634         }
635 
636         let fmt_ctx = {
637             #[cfg(feature = "ansi")]
638             {
639                 FmtCtx::new(ctx, event.parent(), self.ansi)
640             }
641             #[cfg(not(feature = "ansi"))]
642             {
643                 FmtCtx::new(&ctx, event.parent())
644             }
645         };
646         write!(writer, "{}", fmt_ctx)?;
647         if self.display_target {
648             write!(writer, "{}:", meta.target())?;
649         }
650         ctx.format_fields(writer, event)?;
651 
652         let span = event
653             .parent()
654             .and_then(|id| ctx.ctx.span(id))
655             .or_else(|| ctx.ctx.lookup_current());
656 
657         let scope = span.into_iter().flat_map(|span| span.scope());
658         #[cfg(feature = "ansi")]
659         let dimmed = if self.ansi {
660             Style::new().dimmed()
661         } else {
662             Style::new()
663         };
664         for span in scope {
665             let exts = span.extensions();
666             if let Some(fields) = exts.get::<FormattedFields<N>>() {
667                 if !fields.is_empty() {
668                     #[cfg(feature = "ansi")]
669                     let fields = dimmed.paint(fields.as_str());
670                     write!(writer, " {}", fields)?;
671                 }
672             }
673         }
674         writeln!(writer)
675     }
676 }
677 
678 // === impl FormatFields ===
679 
680 impl<'writer, M> FormatFields<'writer> for M
681 where
682     M: MakeOutput<&'writer mut dyn fmt::Write, fmt::Result>,
683     M::Visitor: VisitFmt + VisitOutput<fmt::Result>,
684 {
format_fields<R: RecordFields>( &self, writer: &'writer mut dyn fmt::Write, fields: R, ) -> fmt::Result685     fn format_fields<R: RecordFields>(
686         &self,
687         writer: &'writer mut dyn fmt::Write,
688         fields: R,
689     ) -> fmt::Result {
690         let mut v = self.make_visitor(writer);
691         fields.record(&mut v);
692         v.finish()
693     }
694 }
695 /// The default [`FormatFields`] implementation.
696 ///
697 /// [`FormatFields`]: trait.FormatFields.html
698 #[derive(Debug)]
699 pub struct DefaultFields {
700     // reserve the ability to add fields to this without causing a breaking
701     // change in the future.
702     _private: (),
703 }
704 
705 /// The [visitor] produced by [`DefaultFields`]'s [`MakeVisitor`] implementation.
706 ///
707 /// [visitor]: ../../field/trait.Visit.html
708 /// [`DefaultFields`]: struct.DefaultFields.html
709 /// [`MakeVisitor`]: ../../field/trait.MakeVisitor.html
710 pub struct DefaultVisitor<'a> {
711     writer: &'a mut dyn Write,
712     is_empty: bool,
713     result: fmt::Result,
714 }
715 
716 impl DefaultFields {
717     /// Returns a new default [`FormatFields`] implementation.
718     ///
719     /// [`FormatFields`]: trait.FormatFields.html
new() -> Self720     pub fn new() -> Self {
721         Self { _private: () }
722     }
723 }
724 
725 impl Default for DefaultFields {
default() -> Self726     fn default() -> Self {
727         Self::new()
728     }
729 }
730 
731 impl<'a> MakeVisitor<&'a mut dyn Write> for DefaultFields {
732     type Visitor = DefaultVisitor<'a>;
733 
734     #[inline]
make_visitor(&self, target: &'a mut dyn Write) -> Self::Visitor735     fn make_visitor(&self, target: &'a mut dyn Write) -> Self::Visitor {
736         DefaultVisitor::new(target, true)
737     }
738 }
739 
740 // === impl DefaultVisitor ===
741 
742 impl<'a> DefaultVisitor<'a> {
743     /// Returns a new default visitor that formats to the provided `writer`.
744     ///
745     /// # Arguments
746     /// - `writer`: the writer to format to.
747     /// - `is_empty`: whether or not any fields have been previously written to
748     ///   that writer.
new(writer: &'a mut dyn Write, is_empty: bool) -> Self749     pub fn new(writer: &'a mut dyn Write, is_empty: bool) -> Self {
750         Self {
751             writer,
752             is_empty,
753             result: Ok(()),
754         }
755     }
756 
maybe_pad(&mut self)757     fn maybe_pad(&mut self) {
758         if self.is_empty {
759             self.is_empty = false;
760         } else {
761             self.result = write!(self.writer, " ");
762         }
763     }
764 }
765 
766 impl<'a> field::Visit for DefaultVisitor<'a> {
record_str(&mut self, field: &Field, value: &str)767     fn record_str(&mut self, field: &Field, value: &str) {
768         if self.result.is_err() {
769             return;
770         }
771 
772         if field.name() == "message" {
773             self.record_debug(field, &format_args!("{}", value))
774         } else {
775             self.record_debug(field, &value)
776         }
777     }
778 
record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static))779     fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) {
780         if let Some(source) = value.source() {
781             self.record_debug(
782                 field,
783                 &format_args!("{} {}.sources={}", value, field, ErrorSourceList(source)),
784             )
785         } else {
786             self.record_debug(field, &format_args!("{}", value))
787         }
788     }
789 
record_debug(&mut self, field: &Field, value: &dyn fmt::Debug)790     fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
791         if self.result.is_err() {
792             return;
793         }
794 
795         self.maybe_pad();
796         self.result = match field.name() {
797             "message" => write!(self.writer, "{:?}", value),
798             // Skip fields that are actually log metadata that have already been handled
799             #[cfg(feature = "tracing-log")]
800             name if name.starts_with("log.") => Ok(()),
801             name if name.starts_with("r#") => write!(self.writer, "{}={:?}", &name[2..], value),
802             name => write!(self.writer, "{}={:?}", name, value),
803         };
804     }
805 }
806 
807 impl<'a> crate::field::VisitOutput<fmt::Result> for DefaultVisitor<'a> {
finish(self) -> fmt::Result808     fn finish(self) -> fmt::Result {
809         self.result
810     }
811 }
812 
813 impl<'a> crate::field::VisitFmt for DefaultVisitor<'a> {
writer(&mut self) -> &mut dyn fmt::Write814     fn writer(&mut self) -> &mut dyn fmt::Write {
815         self.writer
816     }
817 }
818 
819 impl<'a> fmt::Debug for DefaultVisitor<'a> {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result820     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
821         f.debug_struct("DefaultVisitor")
822             .field("writer", &format_args!("<dyn fmt::Write>"))
823             .field("is_empty", &self.is_empty)
824             .field("result", &self.result)
825             .finish()
826     }
827 }
828 
829 /// Renders an error into a list of sources, *including* the error
830 struct ErrorSourceList<'a>(&'a (dyn std::error::Error + 'static));
831 
832 impl<'a> Display for ErrorSourceList<'a> {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result833     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
834         let mut list = f.debug_list();
835         let mut curr = Some(self.0);
836         while let Some(curr_err) = curr {
837             list.entry(&format_args!("{}", curr_err));
838             curr = curr_err.source();
839         }
840         list.finish()
841     }
842 }
843 
844 struct FmtCtx<'a, S, N> {
845     ctx: &'a FmtContext<'a, S, N>,
846     span: Option<&'a span::Id>,
847     #[cfg(feature = "ansi")]
848     ansi: bool,
849 }
850 
851 impl<'a, S, N: 'a> FmtCtx<'a, S, N>
852 where
853     S: Subscriber + for<'lookup> LookupSpan<'lookup>,
854     N: for<'writer> FormatFields<'writer> + 'static,
855 {
856     #[cfg(feature = "ansi")]
new( ctx: &'a FmtContext<'_, S, N>, span: Option<&'a span::Id>, ansi: bool, ) -> Self857     pub(crate) fn new(
858         ctx: &'a FmtContext<'_, S, N>,
859         span: Option<&'a span::Id>,
860         ansi: bool,
861     ) -> Self {
862         Self { ctx, span, ansi }
863     }
864 
865     #[cfg(not(feature = "ansi"))]
new(ctx: &'a FmtContext<'_, S, N>, span: Option<&'a span::Id>) -> Self866     pub(crate) fn new(ctx: &'a FmtContext<'_, S, N>, span: Option<&'a span::Id>) -> Self {
867         Self { ctx, span }
868     }
869 
bold(&self) -> Style870     fn bold(&self) -> Style {
871         #[cfg(feature = "ansi")]
872         {
873             if self.ansi {
874                 return Style::new().bold();
875             }
876         }
877 
878         Style::new()
879     }
880 }
881 
882 impl<'a, S, N: 'a> fmt::Display for FmtCtx<'a, S, N>
883 where
884     S: Subscriber + for<'lookup> LookupSpan<'lookup>,
885     N: for<'writer> FormatFields<'writer> + 'static,
886 {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result887     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
888         let bold = self.bold();
889         let mut seen = false;
890 
891         let span = self
892             .span
893             .and_then(|id| self.ctx.ctx.span(id))
894             .or_else(|| self.ctx.ctx.lookup_current());
895 
896         let scope = span.into_iter().flat_map(|span| span.scope().from_root());
897 
898         for span in scope {
899             seen = true;
900             write!(f, "{}:", bold.paint(span.metadata().name()))?;
901         }
902 
903         if seen {
904             f.write_char(' ')?;
905         }
906         Ok(())
907     }
908 }
909 
910 struct FullCtx<'a, S, N>
911 where
912     S: Subscriber + for<'lookup> LookupSpan<'lookup>,
913     N: for<'writer> FormatFields<'writer> + 'static,
914 {
915     ctx: &'a FmtContext<'a, S, N>,
916     span: Option<&'a span::Id>,
917     #[cfg(feature = "ansi")]
918     ansi: bool,
919 }
920 
921 impl<'a, S, N: 'a> FullCtx<'a, S, N>
922 where
923     S: Subscriber + for<'lookup> LookupSpan<'lookup>,
924     N: for<'writer> FormatFields<'writer> + 'static,
925 {
926     #[cfg(feature = "ansi")]
new( ctx: &'a FmtContext<'a, S, N>, span: Option<&'a span::Id>, ansi: bool, ) -> Self927     pub(crate) fn new(
928         ctx: &'a FmtContext<'a, S, N>,
929         span: Option<&'a span::Id>,
930         ansi: bool,
931     ) -> Self {
932         Self { ctx, span, ansi }
933     }
934 
935     #[cfg(not(feature = "ansi"))]
new(ctx: &'a FmtContext<'a, S, N>, span: Option<&'a span::Id>) -> Self936     pub(crate) fn new(ctx: &'a FmtContext<'a, S, N>, span: Option<&'a span::Id>) -> Self {
937         Self { ctx, span }
938     }
939 
bold(&self) -> Style940     fn bold(&self) -> Style {
941         #[cfg(feature = "ansi")]
942         {
943             if self.ansi {
944                 return Style::new().bold();
945             }
946         }
947 
948         Style::new()
949     }
950 }
951 
952 impl<'a, S, N> fmt::Display for FullCtx<'a, S, N>
953 where
954     S: Subscriber + for<'lookup> LookupSpan<'lookup>,
955     N: for<'writer> FormatFields<'writer> + 'static,
956 {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result957     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
958         let bold = self.bold();
959         let mut seen = false;
960 
961         let span = self
962             .span
963             .and_then(|id| self.ctx.ctx.span(id))
964             .or_else(|| self.ctx.ctx.lookup_current());
965 
966         let scope = span.into_iter().flat_map(|span| span.scope().from_root());
967 
968         for span in scope {
969             write!(f, "{}", bold.paint(span.metadata().name()))?;
970             seen = true;
971 
972             let ext = span.extensions();
973             let fields = &ext
974                 .get::<FormattedFields<N>>()
975                 .expect("Unable to find FormattedFields in extensions; this is a bug");
976             if !fields.is_empty() {
977                 write!(f, "{}{}{}", bold.paint("{"), fields, bold.paint("}"))?;
978             }
979             f.write_char(':')?;
980         }
981 
982         if seen {
983             f.write_char(' ')?;
984         }
985         Ok(())
986     }
987 }
988 
989 #[cfg(not(feature = "ansi"))]
990 struct Style;
991 
992 #[cfg(not(feature = "ansi"))]
993 impl Style {
new() -> Self994     fn new() -> Self {
995         Style
996     }
paint(&self, d: impl fmt::Display) -> impl fmt::Display997     fn paint(&self, d: impl fmt::Display) -> impl fmt::Display {
998         d
999     }
1000 }
1001 
1002 struct FmtThreadName<'a> {
1003     name: &'a str,
1004 }
1005 
1006 impl<'a> FmtThreadName<'a> {
new(name: &'a str) -> Self1007     pub(crate) fn new(name: &'a str) -> Self {
1008         Self { name }
1009     }
1010 }
1011 
1012 impl<'a> fmt::Display for FmtThreadName<'a> {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1013     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1014         use std::sync::atomic::{
1015             AtomicUsize,
1016             Ordering::{AcqRel, Acquire, Relaxed},
1017         };
1018 
1019         // Track the longest thread name length we've seen so far in an atomic,
1020         // so that it can be updated by any thread.
1021         static MAX_LEN: AtomicUsize = AtomicUsize::new(0);
1022         let len = self.name.len();
1023         // Snapshot the current max thread name length.
1024         let mut max_len = MAX_LEN.load(Relaxed);
1025 
1026         while len > max_len {
1027             // Try to set a new max length, if it is still the value we took a
1028             // snapshot of.
1029             match MAX_LEN.compare_exchange(max_len, len, AcqRel, Acquire) {
1030                 // We successfully set the new max value
1031                 Ok(_) => break,
1032                 // Another thread set a new max value since we last observed
1033                 // it! It's possible that the new length is actually longer than
1034                 // ours, so we'll loop again and check whether our length is
1035                 // still the longest. If not, we'll just use the newer value.
1036                 Err(actual) => max_len = actual,
1037             }
1038         }
1039 
1040         // pad thread name using `max_len`
1041         write!(f, "{:>width$}", self.name, width = max_len)
1042     }
1043 }
1044 
1045 struct FmtLevel<'a> {
1046     level: &'a Level,
1047     #[cfg(feature = "ansi")]
1048     ansi: bool,
1049 }
1050 
1051 impl<'a> FmtLevel<'a> {
1052     #[cfg(feature = "ansi")]
new(level: &'a Level, ansi: bool) -> Self1053     pub(crate) fn new(level: &'a Level, ansi: bool) -> Self {
1054         Self { level, ansi }
1055     }
1056 
1057     #[cfg(not(feature = "ansi"))]
new(level: &'a Level) -> Self1058     pub(crate) fn new(level: &'a Level) -> Self {
1059         Self { level }
1060     }
1061 }
1062 
1063 const TRACE_STR: &str = "TRACE";
1064 const DEBUG_STR: &str = "DEBUG";
1065 const INFO_STR: &str = " INFO";
1066 const WARN_STR: &str = " WARN";
1067 const ERROR_STR: &str = "ERROR";
1068 
1069 #[cfg(not(feature = "ansi"))]
1070 impl<'a> fmt::Display for FmtLevel<'a> {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1071     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1072         match *self.level {
1073             Level::TRACE => f.pad(TRACE_STR),
1074             Level::DEBUG => f.pad(DEBUG_STR),
1075             Level::INFO => f.pad(INFO_STR),
1076             Level::WARN => f.pad(WARN_STR),
1077             Level::ERROR => f.pad(ERROR_STR),
1078         }
1079     }
1080 }
1081 
1082 #[cfg(feature = "ansi")]
1083 impl<'a> fmt::Display for FmtLevel<'a> {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1084     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1085         if self.ansi {
1086             match *self.level {
1087                 Level::TRACE => write!(f, "{}", Colour::Purple.paint(TRACE_STR)),
1088                 Level::DEBUG => write!(f, "{}", Colour::Blue.paint(DEBUG_STR)),
1089                 Level::INFO => write!(f, "{}", Colour::Green.paint(INFO_STR)),
1090                 Level::WARN => write!(f, "{}", Colour::Yellow.paint(WARN_STR)),
1091                 Level::ERROR => write!(f, "{}", Colour::Red.paint(ERROR_STR)),
1092             }
1093         } else {
1094             match *self.level {
1095                 Level::TRACE => f.pad(TRACE_STR),
1096                 Level::DEBUG => f.pad(DEBUG_STR),
1097                 Level::INFO => f.pad(INFO_STR),
1098                 Level::WARN => f.pad(WARN_STR),
1099                 Level::ERROR => f.pad(ERROR_STR),
1100             }
1101         }
1102     }
1103 }
1104 
1105 // === impl FieldFn ===
1106 
1107 impl<'a, F> MakeVisitor<&'a mut dyn fmt::Write> for FieldFn<F>
1108 where
1109     F: Fn(&mut dyn fmt::Write, &Field, &dyn fmt::Debug) -> fmt::Result + Clone,
1110 {
1111     type Visitor = FieldFnVisitor<'a, F>;
1112 
make_visitor(&self, writer: &'a mut dyn fmt::Write) -> Self::Visitor1113     fn make_visitor(&self, writer: &'a mut dyn fmt::Write) -> Self::Visitor {
1114         FieldFnVisitor {
1115             writer,
1116             f: self.0.clone(),
1117             result: Ok(()),
1118         }
1119     }
1120 }
1121 
1122 impl<'a, F> Visit for FieldFnVisitor<'a, F>
1123 where
1124     F: Fn(&mut dyn fmt::Write, &Field, &dyn fmt::Debug) -> fmt::Result,
1125 {
record_debug(&mut self, field: &Field, value: &dyn fmt::Debug)1126     fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
1127         if self.result.is_ok() {
1128             self.result = (self.f)(&mut self.writer, field, value)
1129         }
1130     }
1131 }
1132 
1133 impl<'a, F> VisitOutput<fmt::Result> for FieldFnVisitor<'a, F>
1134 where
1135     F: Fn(&mut dyn fmt::Write, &Field, &dyn fmt::Debug) -> fmt::Result,
1136 {
finish(self) -> fmt::Result1137     fn finish(self) -> fmt::Result {
1138         self.result
1139     }
1140 }
1141 
1142 impl<'a, F> VisitFmt for FieldFnVisitor<'a, F>
1143 where
1144     F: Fn(&mut dyn fmt::Write, &Field, &dyn fmt::Debug) -> fmt::Result,
1145 {
writer(&mut self) -> &mut dyn fmt::Write1146     fn writer(&mut self) -> &mut dyn fmt::Write {
1147         &mut *self.writer
1148     }
1149 }
1150 
1151 impl<'a, F> fmt::Debug for FieldFnVisitor<'a, F> {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1152     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1153         f.debug_struct("FieldFnVisitor")
1154             .field("f", &format_args!("<Fn>"))
1155             .field("writer", &format_args!("<dyn fmt::Write>"))
1156             .field("result", &self.result)
1157             .finish()
1158     }
1159 }
1160 
1161 // === printing synthetic Span events ===
1162 
1163 /// Configures what points in the span lifecycle are logged as events.
1164 ///
1165 /// See also [`with_span_events`](../struct.SubscriberBuilder.html#method.with_span_events).
1166 #[derive(Clone, Eq, PartialEq, Ord, PartialOrd)]
1167 pub struct FmtSpan(u8);
1168 
1169 impl FmtSpan {
1170     /// one event when span is created
1171     pub const NEW: FmtSpan = FmtSpan(1 << 0);
1172     /// one event per enter of a span
1173     pub const ENTER: FmtSpan = FmtSpan(1 << 1);
1174     /// one event per exit of a span
1175     pub const EXIT: FmtSpan = FmtSpan(1 << 2);
1176     /// one event when the span is dropped
1177     pub const CLOSE: FmtSpan = FmtSpan(1 << 3);
1178 
1179     /// spans are ignored (this is the default)
1180     pub const NONE: FmtSpan = FmtSpan(0);
1181     /// one event per enter/exit of a span
1182     pub const ACTIVE: FmtSpan = FmtSpan(FmtSpan::ENTER.0 | FmtSpan::EXIT.0);
1183     /// events at all points (new, enter, exit, drop)
1184     pub const FULL: FmtSpan =
1185         FmtSpan(FmtSpan::NEW.0 | FmtSpan::ENTER.0 | FmtSpan::EXIT.0 | FmtSpan::CLOSE.0);
1186 
1187     /// Check whether or not a certain flag is set for this [`FmtSpan`]
contains(&self, other: FmtSpan) -> bool1188     fn contains(&self, other: FmtSpan) -> bool {
1189         self.clone() & other.clone() == other
1190     }
1191 }
1192 
1193 macro_rules! impl_fmt_span_bit_op {
1194     ($trait:ident, $func:ident, $op:tt) => {
1195         impl std::ops::$trait for FmtSpan {
1196             type Output = FmtSpan;
1197 
1198             fn $func(self, rhs: Self) -> Self::Output {
1199                 FmtSpan(self.0 $op rhs.0)
1200             }
1201         }
1202     };
1203 }
1204 
1205 macro_rules! impl_fmt_span_bit_assign_op {
1206     ($trait:ident, $func:ident, $op:tt) => {
1207         impl std::ops::$trait for FmtSpan {
1208             fn $func(&mut self, rhs: Self) {
1209                 *self = FmtSpan(self.0 $op rhs.0)
1210             }
1211         }
1212     };
1213 }
1214 
1215 impl_fmt_span_bit_op!(BitAnd, bitand, &);
1216 impl_fmt_span_bit_op!(BitOr, bitor, |);
1217 impl_fmt_span_bit_op!(BitXor, bitxor, ^);
1218 
1219 impl_fmt_span_bit_assign_op!(BitAndAssign, bitand_assign, &);
1220 impl_fmt_span_bit_assign_op!(BitOrAssign, bitor_assign, |);
1221 impl_fmt_span_bit_assign_op!(BitXorAssign, bitxor_assign, ^);
1222 
1223 impl Debug for FmtSpan {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1224     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1225         let mut wrote_flag = false;
1226         let mut write_flags = |flag, flag_str| -> fmt::Result {
1227             if self.contains(flag) {
1228                 if wrote_flag {
1229                     f.write_str(" | ")?;
1230                 }
1231 
1232                 f.write_str(flag_str)?;
1233                 wrote_flag = true;
1234             }
1235 
1236             Ok(())
1237         };
1238 
1239         if FmtSpan::NONE | self.clone() == FmtSpan::NONE {
1240             f.write_str("FmtSpan::NONE")?;
1241         } else {
1242             write_flags(FmtSpan::NEW, "FmtSpan::NEW")?;
1243             write_flags(FmtSpan::ENTER, "FmtSpan::ENTER")?;
1244             write_flags(FmtSpan::EXIT, "FmtSpan::EXIT")?;
1245             write_flags(FmtSpan::CLOSE, "FmtSpan::CLOSE")?;
1246         }
1247 
1248         Ok(())
1249     }
1250 }
1251 
1252 pub(super) struct FmtSpanConfig {
1253     pub(super) kind: FmtSpan,
1254     pub(super) fmt_timing: bool,
1255 }
1256 
1257 impl FmtSpanConfig {
without_time(self) -> Self1258     pub(super) fn without_time(self) -> Self {
1259         Self {
1260             kind: self.kind,
1261             fmt_timing: false,
1262         }
1263     }
with_kind(self, kind: FmtSpan) -> Self1264     pub(super) fn with_kind(self, kind: FmtSpan) -> Self {
1265         Self {
1266             kind,
1267             fmt_timing: self.fmt_timing,
1268         }
1269     }
trace_new(&self) -> bool1270     pub(super) fn trace_new(&self) -> bool {
1271         self.kind.contains(FmtSpan::NEW)
1272     }
trace_enter(&self) -> bool1273     pub(super) fn trace_enter(&self) -> bool {
1274         self.kind.contains(FmtSpan::ENTER)
1275     }
trace_exit(&self) -> bool1276     pub(super) fn trace_exit(&self) -> bool {
1277         self.kind.contains(FmtSpan::EXIT)
1278     }
trace_close(&self) -> bool1279     pub(super) fn trace_close(&self) -> bool {
1280         self.kind.contains(FmtSpan::CLOSE)
1281     }
1282 }
1283 
1284 impl Debug for FmtSpanConfig {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1285     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1286         self.kind.fmt(f)
1287     }
1288 }
1289 
1290 impl Default for FmtSpanConfig {
default() -> Self1291     fn default() -> Self {
1292         Self {
1293             kind: FmtSpan::NONE,
1294             fmt_timing: true,
1295         }
1296     }
1297 }
1298 
1299 pub(super) struct TimingDisplay(pub(super) u64);
1300 impl Display for TimingDisplay {
fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1301     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1302         let mut t = self.0 as f64;
1303         for unit in ["ns", "µs", "ms", "s"].iter() {
1304             if t < 10.0 {
1305                 return write!(f, "{:.2}{}", t, unit);
1306             } else if t < 100.0 {
1307                 return write!(f, "{:.1}{}", t, unit);
1308             } else if t < 1000.0 {
1309                 return write!(f, "{:.0}{}", t, unit);
1310             }
1311             t /= 1000.0;
1312         }
1313         write!(f, "{:.0}s", t * 1000.0)
1314     }
1315 }
1316 
1317 #[cfg(test)]
1318 pub(super) mod test {
1319 
1320     use crate::fmt::{test::MockWriter, time::FormatTime};
1321     use lazy_static::lazy_static;
1322     use tracing::{self, subscriber::with_default};
1323 
1324     use super::{FmtSpan, TimingDisplay};
1325     use std::{fmt, sync::Mutex};
1326 
1327     pub(crate) struct MockTime;
1328     impl FormatTime for MockTime {
format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result1329         fn format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result {
1330             write!(w, "fake time")
1331         }
1332     }
1333 
1334     #[test]
disable_everything()1335     fn disable_everything() {
1336         // This test reproduces https://github.com/tokio-rs/tracing/issues/1354
1337         lazy_static! {
1338             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1339         }
1340 
1341         let make_writer = || MockWriter::new(&BUF);
1342         let subscriber = crate::fmt::Subscriber::builder()
1343             .with_writer(make_writer)
1344             .without_time()
1345             .with_level(false)
1346             .with_target(false)
1347             .with_thread_ids(false)
1348             .with_thread_names(false);
1349         #[cfg(feature = "ansi")]
1350         let subscriber = subscriber.with_ansi(false);
1351 
1352         with_default(subscriber.finish(), || {
1353             tracing::info!("hello");
1354         });
1355 
1356         let actual = String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap();
1357         assert_eq!("hello\n", actual.as_str());
1358     }
1359 
1360     #[cfg(feature = "ansi")]
1361     #[test]
with_ansi_true()1362     fn with_ansi_true() {
1363         lazy_static! {
1364             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1365         }
1366 
1367         let make_writer = || MockWriter::new(&BUF);
1368         let expected = "\u{1b}[2mfake time\u{1b}[0m \u{1b}[32m INFO\u{1b}[0m tracing_subscriber::fmt::format::test: some ansi test\n";
1369         test_ansi(make_writer, expected, true, &BUF);
1370     }
1371 
1372     #[cfg(feature = "ansi")]
1373     #[test]
with_ansi_false()1374     fn with_ansi_false() {
1375         lazy_static! {
1376             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1377         }
1378 
1379         let make_writer = || MockWriter::new(&BUF);
1380         let expected = "fake time  INFO tracing_subscriber::fmt::format::test: some ansi test\n";
1381 
1382         test_ansi(make_writer, expected, false, &BUF);
1383     }
1384 
1385     #[cfg(not(feature = "ansi"))]
1386     #[test]
without_ansi()1387     fn without_ansi() {
1388         lazy_static! {
1389             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1390         }
1391 
1392         let make_writer = || MockWriter::new(&BUF);
1393         let expected = "fake time  INFO tracing_subscriber::fmt::format::test: some ansi test\n";
1394         let subscriber = crate::fmt::Subscriber::builder()
1395             .with_writer(make_writer)
1396             .with_timer(MockTime)
1397             .finish();
1398 
1399         with_default(subscriber, || {
1400             tracing::info!("some ansi test");
1401         });
1402 
1403         let actual = String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap();
1404         assert_eq!(expected, actual.as_str());
1405     }
1406 
1407     #[cfg(feature = "ansi")]
test_ansi<T>(make_writer: T, expected: &str, is_ansi: bool, buf: &Mutex<Vec<u8>>) where T: crate::fmt::MakeWriter + Send + Sync + 'static,1408     fn test_ansi<T>(make_writer: T, expected: &str, is_ansi: bool, buf: &Mutex<Vec<u8>>)
1409     where
1410         T: crate::fmt::MakeWriter + Send + Sync + 'static,
1411     {
1412         let subscriber = crate::fmt::Subscriber::builder()
1413             .with_writer(make_writer)
1414             .with_ansi(is_ansi)
1415             .with_timer(MockTime)
1416             .finish();
1417 
1418         with_default(subscriber, || {
1419             tracing::info!("some ansi test");
1420         });
1421 
1422         let actual = String::from_utf8(buf.try_lock().unwrap().to_vec()).unwrap();
1423         assert_eq!(expected, actual.as_str());
1424     }
1425 
1426     #[test]
without_level()1427     fn without_level() {
1428         lazy_static! {
1429             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1430         }
1431 
1432         let make_writer = || MockWriter::new(&BUF);
1433         let subscriber = crate::fmt::Subscriber::builder()
1434             .with_writer(make_writer)
1435             .with_level(false)
1436             .with_ansi(false)
1437             .with_timer(MockTime)
1438             .finish();
1439 
1440         with_default(subscriber, || {
1441             tracing::info!("hello");
1442         });
1443         let actual = String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap();
1444         assert_eq!(
1445             "fake time tracing_subscriber::fmt::format::test: hello\n",
1446             actual.as_str()
1447         );
1448     }
1449 
1450     #[test]
overridden_parents()1451     fn overridden_parents() {
1452         lazy_static! {
1453             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1454         }
1455 
1456         let make_writer = || MockWriter::new(&BUF);
1457         let subscriber = crate::fmt::Subscriber::builder()
1458             .with_writer(make_writer)
1459             .with_level(false)
1460             .with_ansi(false)
1461             .with_timer(MockTime)
1462             .finish();
1463 
1464         with_default(subscriber, || {
1465             let span1 = tracing::info_span!("span1");
1466             let span2 = tracing::info_span!(parent: &span1, "span2");
1467             tracing::info!(parent: &span2, "hello");
1468         });
1469         let actual = String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap();
1470         assert_eq!(
1471             "fake time span1:span2: tracing_subscriber::fmt::format::test: hello\n",
1472             actual.as_str()
1473         );
1474     }
1475 
1476     #[test]
overridden_parents_in_scope()1477     fn overridden_parents_in_scope() {
1478         lazy_static! {
1479             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1480         }
1481 
1482         let make_writer = || MockWriter::new(&BUF);
1483         let subscriber = crate::fmt::Subscriber::builder()
1484             .with_writer(make_writer)
1485             .with_level(false)
1486             .with_ansi(false)
1487             .with_timer(MockTime)
1488             .finish();
1489 
1490         let actual = || {
1491             let mut buf = BUF.try_lock().unwrap();
1492             let val = String::from_utf8(buf.to_vec()).unwrap();
1493             buf.clear();
1494             val
1495         };
1496 
1497         with_default(subscriber, || {
1498             let span1 = tracing::info_span!("span1");
1499             let span2 = tracing::info_span!(parent: &span1, "span2");
1500             let span3 = tracing::info_span!("span3");
1501             let _e3 = span3.enter();
1502 
1503             tracing::info!("hello");
1504             assert_eq!(
1505                 "fake time span3: tracing_subscriber::fmt::format::test: hello\n",
1506                 actual().as_str()
1507             );
1508 
1509             tracing::info!(parent: &span2, "hello");
1510             assert_eq!(
1511                 "fake time span1:span2: tracing_subscriber::fmt::format::test: hello\n",
1512                 actual().as_str()
1513             );
1514         });
1515     }
1516 
1517     #[test]
format_nanos()1518     fn format_nanos() {
1519         fn fmt(t: u64) -> String {
1520             TimingDisplay(t).to_string()
1521         }
1522 
1523         assert_eq!(fmt(1), "1.00ns");
1524         assert_eq!(fmt(12), "12.0ns");
1525         assert_eq!(fmt(123), "123ns");
1526         assert_eq!(fmt(1234), "1.23µs");
1527         assert_eq!(fmt(12345), "12.3µs");
1528         assert_eq!(fmt(123456), "123µs");
1529         assert_eq!(fmt(1234567), "1.23ms");
1530         assert_eq!(fmt(12345678), "12.3ms");
1531         assert_eq!(fmt(123456789), "123ms");
1532         assert_eq!(fmt(1234567890), "1.23s");
1533         assert_eq!(fmt(12345678901), "12.3s");
1534         assert_eq!(fmt(123456789012), "123s");
1535         assert_eq!(fmt(1234567890123), "1235s");
1536     }
1537 
1538     #[test]
fmt_span_combinations()1539     fn fmt_span_combinations() {
1540         let f = FmtSpan::NONE;
1541         assert!(!f.contains(FmtSpan::NEW));
1542         assert!(!f.contains(FmtSpan::ENTER));
1543         assert!(!f.contains(FmtSpan::EXIT));
1544         assert!(!f.contains(FmtSpan::CLOSE));
1545 
1546         let f = FmtSpan::ACTIVE;
1547         assert!(!f.contains(FmtSpan::NEW));
1548         assert!(f.contains(FmtSpan::ENTER));
1549         assert!(f.contains(FmtSpan::EXIT));
1550         assert!(!f.contains(FmtSpan::CLOSE));
1551 
1552         let f = FmtSpan::FULL;
1553         assert!(f.contains(FmtSpan::NEW));
1554         assert!(f.contains(FmtSpan::ENTER));
1555         assert!(f.contains(FmtSpan::EXIT));
1556         assert!(f.contains(FmtSpan::CLOSE));
1557 
1558         let f = FmtSpan::NEW | FmtSpan::CLOSE;
1559         assert!(f.contains(FmtSpan::NEW));
1560         assert!(!f.contains(FmtSpan::ENTER));
1561         assert!(!f.contains(FmtSpan::EXIT));
1562         assert!(f.contains(FmtSpan::CLOSE));
1563     }
1564 }
1565