tracing_subscriber/fmt/format/mod.rs
1//! Formatters for logging [`tracing`] events.
2//!
3//! This module provides several formatter implementations, as well as utilities
4//! for implementing custom formatters.
5//!
6//! # Formatters
7//! This module provides a number of formatter implementations:
8//!
9//! * [`Full`]: The default formatter. This emits human-readable,
10//! single-line logs for each event that occurs, with the current span context
11//! displayed before the formatted representation of the event. See
12//! [here](Full#example-output) for sample output.
13//!
14//! * [`Compact`]: A variant of the default formatter, optimized for
15//! short line lengths. Fields from the current span context are appended to
16//! the fields of the formatted event, and span names are not shown; the
17//! verbosity level is abbreviated to a single character. See
18//! [here](Compact#example-output) for sample output.
19//!
20//! * [`Pretty`]: Emits excessively pretty, multi-line logs, optimized
21//! for human readability. This is primarily intended to be used in local
22//! development and debugging, or for command-line applications, where
23//! automated analysis and compact storage of logs is less of a priority than
24//! readability and visual appeal. See [here](Pretty#example-output)
25//! for sample output.
26//!
27//! * [`Json`]: Outputs newline-delimited JSON logs. This is intended
28//! for production use with systems where structured logs are consumed as JSON
29//! by analysis and viewing tools. The JSON output is not optimized for human
30//! readability. See [here](Json#example-output) for sample output.
31use super::time::{FormatTime, SystemTime};
32use crate::{
33 field::{MakeOutput, MakeVisitor, RecordFields, VisitFmt, VisitOutput},
34 fmt::fmt_layer::FmtContext,
35 fmt::fmt_layer::FormattedFields,
36 registry::LookupSpan,
37};
38
39use std::fmt::{self, Debug, Display, Write};
40use tracing_core::{
41 field::{self, Field, Visit},
42 span, Event, Level, Subscriber,
43};
44
45#[cfg(feature = "tracing-log")]
46use tracing_log::NormalizeEvent;
47
48#[cfg(feature = "ansi")]
49use nu_ansi_term::{Color, Style};
50
51mod escape;
52use escape::EscapeGuard;
53
54#[cfg(feature = "json")]
55mod json;
56#[cfg(feature = "json")]
57#[cfg_attr(docsrs, doc(cfg(feature = "json")))]
58pub use json::*;
59
60#[cfg(feature = "ansi")]
61mod pretty;
62#[cfg(feature = "ansi")]
63#[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
64pub use pretty::*;
65
66/// A type that can format a tracing [`Event`] to a [`Writer`].
67///
68/// [`FormatEvent`] is primarily used in the context of [`fmt::Subscriber`] or
69/// [`fmt::Layer`]. Each time an event is dispatched to [`fmt::Subscriber`] or
70/// [`fmt::Layer`], the subscriber or layer
71/// forwards it to its associated [`FormatEvent`] to emit a log message.
72///
73/// This trait is already implemented for function pointers with the same
74/// signature as `format_event`.
75///
76/// # Arguments
77///
78/// The following arguments are passed to [`FormatEvent::format_event`]:
79///
80/// * A [`FmtContext`]. This is an extension of the [`layer::Context`] type,
81/// which can be used for accessing stored information such as the current
82/// span context an event occurred in.
83///
84/// In addition, [`FmtContext`] exposes access to the [`FormatFields`]
85/// implementation that the subscriber was configured to use via the
86/// [`FmtContext::field_format`] method. This can be used when the
87/// [`FormatEvent`] implementation needs to format the event's fields.
88///
89/// For convenience, [`FmtContext`] also implements [`FormatFields`],
90/// forwarding to the configured [`FormatFields`] type.
91///
92/// * A [`Writer`] to which the formatted representation of the event is
93/// written. This type implements the [`std::fmt::Write`] trait, and therefore
94/// can be used with the [`std::write!`] and [`std::writeln!`] macros, as well
95/// as calling [`std::fmt::Write`] methods directly.
96///
97/// The [`Writer`] type also implements additional methods that provide
98/// information about how the event should be formatted. The
99/// [`Writer::has_ansi_escapes`] method indicates whether [ANSI terminal
100/// escape codes] are supported by the underlying I/O writer that the event
101/// will be written to. If this returns `true`, the formatter is permitted to
102/// use ANSI escape codes to add colors and other text formatting to its
103/// output. If it returns `false`, the event will be written to an output that
104/// does not support ANSI escape codes (such as a log file), and they should
105/// not be emitted.
106///
107/// Crates like [`nu_ansi_term`] and [`owo-colors`] can be used to add ANSI
108/// escape codes to formatted output.
109///
110/// * The actual [`Event`] to be formatted.
111///
112/// # Examples
113///
114/// This example re-implements a simplified version of this crate's [default
115/// formatter]:
116///
117/// ```rust
118/// use std::fmt;
119/// use tracing_core::{Subscriber, Event};
120/// use tracing_subscriber::fmt::{
121/// format::{self, FormatEvent, FormatFields},
122/// FmtContext,
123/// FormattedFields,
124/// };
125/// use tracing_subscriber::registry::LookupSpan;
126///
127/// struct MyFormatter;
128///
129/// impl<S, N> FormatEvent<S, N> for MyFormatter
130/// where
131/// S: Subscriber + for<'a> LookupSpan<'a>,
132/// N: for<'a> FormatFields<'a> + 'static,
133/// {
134/// fn format_event(
135/// &self,
136/// ctx: &FmtContext<'_, S, N>,
137/// mut writer: format::Writer<'_>,
138/// event: &Event<'_>,
139/// ) -> fmt::Result {
140/// // Format values from the event's's metadata:
141/// let metadata = event.metadata();
142/// write!(&mut writer, "{} {}: ", metadata.level(), metadata.target())?;
143///
144/// // Format all the spans in the event's span context.
145/// if let Some(scope) = ctx.event_scope() {
146/// for span in scope.from_root() {
147/// write!(writer, "{}", span.name())?;
148///
149/// // `FormattedFields` is a formatted representation of the span's
150/// // fields, which is stored in its extensions by the `fmt` layer's
151/// // `new_span` method. The fields will have been formatted
152/// // by the same field formatter that's provided to the event
153/// // formatter in the `FmtContext`.
154/// let ext = span.extensions();
155/// let fields = &ext
156/// .get::<FormattedFields<N>>()
157/// .expect("will never be `None`");
158///
159/// // Skip formatting the fields if the span had no fields.
160/// if !fields.is_empty() {
161/// write!(writer, "{{{}}}", fields)?;
162/// }
163/// write!(writer, ": ")?;
164/// }
165/// }
166///
167/// // Write fields on the event
168/// ctx.field_format().format_fields(writer.by_ref(), event)?;
169///
170/// writeln!(writer)
171/// }
172/// }
173///
174/// let _subscriber = tracing_subscriber::fmt()
175/// .event_format(MyFormatter)
176/// .init();
177///
178/// let _span = tracing::info_span!("my_span", answer = 42).entered();
179/// tracing::info!(question = "life, the universe, and everything", "hello world");
180/// ```
181///
182/// This formatter will print events like this:
183///
184/// ```text
185/// DEBUG yak_shaving::shaver: some-span{field-on-span=foo}: started shaving yak
186/// ```
187///
188/// [`layer::Context`]: crate::layer::Context
189/// [`fmt::Layer`]: super::Layer
190/// [`fmt::Subscriber`]: super::Subscriber
191/// [`Event`]: tracing::Event
192/// [implements `FormatFields`]: super::FmtContext#impl-FormatFields<'writer>
193/// [ANSI terminal escape codes]: https://en.wikipedia.org/wiki/ANSI_escape_code
194/// [`Writer::has_ansi_escapes`]: Writer::has_ansi_escapes
195/// [`nu_ansi_term`]: https://crates.io/crates/nu_ansi_term
196/// [`owo-colors`]: https://crates.io/crates/owo-colors
197/// [default formatter]: Full
198pub trait FormatEvent<S, N>
199where
200 S: Subscriber + for<'a> LookupSpan<'a>,
201 N: for<'a> FormatFields<'a> + 'static,
202{
203 /// Write a log message for [`Event`] in [`FmtContext`] to the given [`Writer`].
204 fn format_event(
205 &self,
206 ctx: &FmtContext<'_, S, N>,
207 writer: Writer<'_>,
208 event: &Event<'_>,
209 ) -> fmt::Result;
210}
211
212impl<S, N> FormatEvent<S, N>
213 for fn(ctx: &FmtContext<'_, S, N>, Writer<'_>, &Event<'_>) -> fmt::Result
214where
215 S: Subscriber + for<'a> LookupSpan<'a>,
216 N: for<'a> FormatFields<'a> + 'static,
217{
218 fn format_event(
219 &self,
220 ctx: &FmtContext<'_, S, N>,
221 writer: Writer<'_>,
222 event: &Event<'_>,
223 ) -> fmt::Result {
224 (*self)(ctx, writer, event)
225 }
226}
227/// A type that can format a [set of fields] to a [`Writer`].
228///
229/// [`FormatFields`] is primarily used in the context of [`FmtSubscriber`]. Each
230/// time a span or event with fields is recorded, the subscriber will format
231/// those fields with its associated [`FormatFields`] implementation.
232///
233/// [set of fields]: crate::field::RecordFields
234/// [`FmtSubscriber`]: super::Subscriber
235pub trait FormatFields<'writer> {
236 /// Format the provided `fields` to the provided [`Writer`], returning a result.
237 fn format_fields<R: RecordFields>(&self, writer: Writer<'writer>, fields: R) -> fmt::Result;
238
239 /// Record additional field(s) on an existing span.
240 ///
241 /// By default, this appends a space to the current set of fields if it is
242 /// non-empty, and then calls `self.format_fields`. If different behavior is
243 /// required, the default implementation of this method can be overridden.
244 fn add_fields(
245 &self,
246 current: &'writer mut FormattedFields<Self>,
247 fields: &span::Record<'_>,
248 ) -> fmt::Result {
249 if !current.fields.is_empty() {
250 current.fields.push(' ');
251 }
252 self.format_fields(current.as_writer(), fields)
253 }
254}
255
256/// Returns the default configuration for an event formatter.
257///
258/// Methods on the returned event formatter can be used for further
259/// configuration. For example:
260///
261/// ```rust
262/// let format = tracing_subscriber::fmt::format()
263/// .without_time() // Don't include timestamps
264/// .with_target(false) // Don't include event targets.
265/// .with_level(false) // Don't include event levels.
266/// .compact(); // Use a more compact, abbreviated format.
267///
268/// // Use the configured formatter when building a new subscriber.
269/// tracing_subscriber::fmt()
270/// .event_format(format)
271/// .init();
272/// ```
273pub fn format() -> Format {
274 Format::default()
275}
276
277/// Returns the default configuration for a JSON event formatter.
278#[cfg(feature = "json")]
279#[cfg_attr(docsrs, doc(cfg(feature = "json")))]
280pub fn json() -> Format<Json> {
281 format().json()
282}
283
284/// Returns a [`FormatFields`] implementation that formats fields using the
285/// provided function or closure.
286///
287pub fn debug_fn<F>(f: F) -> FieldFn<F>
288where
289 F: Fn(&mut Writer<'_>, &Field, &dyn fmt::Debug) -> fmt::Result + Clone,
290{
291 FieldFn(f)
292}
293
294/// A writer to which formatted representations of spans and events are written.
295///
296/// This type is provided as input to the [`FormatEvent::format_event`] and
297/// [`FormatFields::format_fields`] methods, which will write formatted
298/// representations of [`Event`]s and [fields] to the [`Writer`].
299///
300/// This type implements the [`std::fmt::Write`] trait, allowing it to be used
301/// with any function that takes an instance of [`std::fmt::Write`].
302/// Additionally, it can be used with the standard library's [`std::write!`] and
303/// [`std::writeln!`] macros.
304///
305/// Additionally, a [`Writer`] may expose additional [`tracing`]-specific
306/// information to the formatter implementation.
307///
308/// [fields]: tracing_core::field
309pub struct Writer<'writer> {
310 writer: &'writer mut dyn fmt::Write,
311 // TODO(eliza): add ANSI support
312 is_ansi: bool,
313 ansi_sanitization: bool,
314}
315
316/// A [`FormatFields`] implementation that formats fields by calling a function
317/// or closure.
318///
319#[derive(Debug, Clone)]
320pub struct FieldFn<F>(F);
321/// The [visitor] produced by [`FieldFn`]'s [`MakeVisitor`] implementation.
322///
323/// [visitor]: super::super::field::Visit
324/// [`MakeVisitor`]: super::super::field::MakeVisitor
325pub struct FieldFnVisitor<'a, F> {
326 f: F,
327 writer: Writer<'a>,
328 result: fmt::Result,
329}
330/// Marker for [`Format`] that indicates that the compact log format should be used.
331///
332/// The compact format includes fields from all currently entered spans, after
333/// the event's fields. Span fields are ordered (but not grouped) by
334/// span, and span names are not shown. A more compact representation of the
335/// event's [`Level`] is used, and additional information—such as the event's
336/// target—is disabled by default.
337///
338/// # Example Output
339///
340/// <pre><font color="#4E9A06"><b>:;</b></font> <font color="#4E9A06">cargo</font> run --example fmt-compact
341/// <font color="#4E9A06"><b> Finished</b></font> dev [unoptimized + debuginfo] target(s) in 0.08s
342/// <font color="#4E9A06"><b> Running</b></font> `target/debug/examples/fmt-compact`
343/// <font color="#AAAAAA">2022-02-17T19:51:05.809287Z </font><font color="#4E9A06"> INFO</font> <b>fmt_compact</b><font color="#AAAAAA">: preparing to shave yaks </font><i>number_of_yaks</i><font color="#AAAAAA">=3</font>
344/// <font color="#AAAAAA">2022-02-17T19:51:05.809367Z </font><font color="#4E9A06"> INFO</font> <b>shaving_yaks</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: shaving yaks </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3</font>
345/// <font color="#AAAAAA">2022-02-17T19:51:05.809414Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks</b>:<b>shave</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: hello! I'm gonna shave a yak </font><i>excitement</i><font color="#AAAAAA">="yay!" </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3 </font><font color="#AAAAAA"><i>yak</i></font><font color="#AAAAAA">=1</font>
346/// <font color="#AAAAAA">2022-02-17T19:51:05.809443Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks</b>:<b>shave</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: yak shaved successfully </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3 </font><font color="#AAAAAA"><i>yak</i></font><font color="#AAAAAA">=1</font>
347/// <font color="#AAAAAA">2022-02-17T19:51:05.809477Z </font><font color="#3465A4">DEBUG</font> <b>shaving_yaks</b>: <b>yak_events</b><font color="#AAAAAA">: </font><i>yak</i><font color="#AAAAAA">=1 </font><i>shaved</i><font color="#AAAAAA">=true </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3</font>
348/// <font color="#AAAAAA">2022-02-17T19:51:05.809500Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: </font><i>yaks_shaved</i><font color="#AAAAAA">=1 </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3</font>
349/// <font color="#AAAAAA">2022-02-17T19:51:05.809531Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks</b>:<b>shave</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: hello! I'm gonna shave a yak </font><i>excitement</i><font color="#AAAAAA">="yay!" </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3 </font><font color="#AAAAAA"><i>yak</i></font><font color="#AAAAAA">=2</font>
350/// <font color="#AAAAAA">2022-02-17T19:51:05.809554Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks</b>:<b>shave</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: yak shaved successfully </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3 </font><font color="#AAAAAA"><i>yak</i></font><font color="#AAAAAA">=2</font>
351/// <font color="#AAAAAA">2022-02-17T19:51:05.809581Z </font><font color="#3465A4">DEBUG</font> <b>shaving_yaks</b>: <b>yak_events</b><font color="#AAAAAA">: </font><i>yak</i><font color="#AAAAAA">=2 </font><i>shaved</i><font color="#AAAAAA">=true </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3</font>
352/// <font color="#AAAAAA">2022-02-17T19:51:05.809606Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: </font><i>yaks_shaved</i><font color="#AAAAAA">=2 </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3</font>
353/// <font color="#AAAAAA">2022-02-17T19:51:05.809635Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks</b>:<b>shave</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: hello! I'm gonna shave a yak </font><i>excitement</i><font color="#AAAAAA">="yay!" </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3 </font><font color="#AAAAAA"><i>yak</i></font><font color="#AAAAAA">=3</font>
354/// <font color="#AAAAAA">2022-02-17T19:51:05.809664Z </font><font color="#C4A000"> WARN</font> <b>shaving_yaks</b>:<b>shave</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: could not locate yak </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3 </font><font color="#AAAAAA"><i>yak</i></font><font color="#AAAAAA">=3</font>
355/// <font color="#AAAAAA">2022-02-17T19:51:05.809693Z </font><font color="#3465A4">DEBUG</font> <b>shaving_yaks</b>: <b>yak_events</b><font color="#AAAAAA">: </font><i>yak</i><font color="#AAAAAA">=3 </font><i>shaved</i><font color="#AAAAAA">=false </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3</font>
356/// <font color="#AAAAAA">2022-02-17T19:51:05.809717Z </font><font color="#CC0000">ERROR</font> <b>shaving_yaks</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: failed to shave yak </font><i>yak</i><font color="#AAAAAA">=3 </font><i>error</i><font color="#AAAAAA">=missing yak </font><i>error.sources</i><font color="#AAAAAA">=[out of space, out of cash] </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3</font>
357/// <font color="#AAAAAA">2022-02-17T19:51:05.809743Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks</b>: <b>fmt_compact::yak_shave</b><font color="#AAAAAA">: </font><i>yaks_shaved</i><font color="#AAAAAA">=2 </font><font color="#AAAAAA"><i>yaks</i></font><font color="#AAAAAA">=3</font>
358/// <font color="#AAAAAA">2022-02-17T19:51:05.809768Z </font><font color="#4E9A06"> INFO</font> <b>fmt_compact</b><font color="#AAAAAA">: yak shaving completed </font><i>all_yaks_shaved</i><font color="#AAAAAA">=false</font>
359///
360/// </pre>
361#[derive(Default, Debug, Copy, Clone, Eq, PartialEq)]
362pub struct Compact;
363
364/// Marker for [`Format`] that indicates that the default log format should be used.
365///
366/// This formatter shows the span context before printing event data. Spans are
367/// displayed including their names and fields.
368///
369/// # Example Output
370///
371/// <pre><font color="#4E9A06"><b>:;</b></font> <font color="#4E9A06">cargo</font> run --example fmt
372/// <font color="#4E9A06"><b> Finished</b></font> dev [unoptimized + debuginfo] target(s) in 0.08s
373/// <font color="#4E9A06"><b> Running</b></font> `target/debug/examples/fmt`
374/// <font color="#AAAAAA">2022-02-15T18:40:14.289898Z </font><font color="#4E9A06"> INFO</font> fmt: preparing to shave yaks <i>number_of_yaks</i><font color="#AAAAAA">=3</font>
375/// <font color="#AAAAAA">2022-02-15T18:40:14.289974Z </font><font color="#4E9A06"> INFO</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: shaving yaks</font>
376/// <font color="#AAAAAA">2022-02-15T18:40:14.290011Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">:</font><b>shave{</b><i>yak</i><font color="#AAAAAA">=1</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: hello! I'm gonna shave a yak </font><i>excitement</i><font color="#AAAAAA">="yay!"</font>
377/// <font color="#AAAAAA">2022-02-15T18:40:14.290038Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">:</font><b>shave{</b><i>yak</i><font color="#AAAAAA">=1</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: yak shaved successfully</font>
378/// <font color="#AAAAAA">2022-02-15T18:40:14.290070Z </font><font color="#3465A4">DEBUG</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: yak_events: </font><i>yak</i><font color="#AAAAAA">=1 </font><i>shaved</i><font color="#AAAAAA">=true</font>
379/// <font color="#AAAAAA">2022-02-15T18:40:14.290089Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: </font><i>yaks_shaved</i><font color="#AAAAAA">=1</font>
380/// <font color="#AAAAAA">2022-02-15T18:40:14.290114Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">:</font><b>shave{</b><i>yak</i><font color="#AAAAAA">=2</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: hello! I'm gonna shave a yak </font><i>excitement</i><font color="#AAAAAA">="yay!"</font>
381/// <font color="#AAAAAA">2022-02-15T18:40:14.290134Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">:</font><b>shave{</b><i>yak</i><font color="#AAAAAA">=2</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: yak shaved successfully</font>
382/// <font color="#AAAAAA">2022-02-15T18:40:14.290157Z </font><font color="#3465A4">DEBUG</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: yak_events: </font><i>yak</i><font color="#AAAAAA">=2 </font><i>shaved</i><font color="#AAAAAA">=true</font>
383/// <font color="#AAAAAA">2022-02-15T18:40:14.290174Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: </font><i>yaks_shaved</i><font color="#AAAAAA">=2</font>
384/// <font color="#AAAAAA">2022-02-15T18:40:14.290198Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">:</font><b>shave{</b><i>yak</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: hello! I'm gonna shave a yak </font><i>excitement</i><font color="#AAAAAA">="yay!"</font>
385/// <font color="#AAAAAA">2022-02-15T18:40:14.290222Z </font><font color="#C4A000"> WARN</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">:</font><b>shave{</b><i>yak</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: could not locate yak</font>
386/// <font color="#AAAAAA">2022-02-15T18:40:14.290247Z </font><font color="#3465A4">DEBUG</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: yak_events: </font><i>yak</i><font color="#AAAAAA">=3 </font><i>shaved</i><font color="#AAAAAA">=false</font>
387/// <font color="#AAAAAA">2022-02-15T18:40:14.290268Z </font><font color="#CC0000">ERROR</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: failed to shave yak </font><i>yak</i><font color="#AAAAAA">=3 </font><i>error</i><font color="#AAAAAA">=missing yak </font><i>error.sources</i><font color="#AAAAAA">=[out of space, out of cash]</font>
388/// <font color="#AAAAAA">2022-02-15T18:40:14.290287Z </font><font color="#75507B">TRACE</font> <b>shaving_yaks{</b><i>yaks</i><font color="#AAAAAA">=3</font><b>}</b><font color="#AAAAAA">: fmt::yak_shave: </font><i>yaks_shaved</i><font color="#AAAAAA">=2</font>
389/// <font color="#AAAAAA">2022-02-15T18:40:14.290309Z </font><font color="#4E9A06"> INFO</font> fmt: yak shaving completed. <i>all_yaks_shaved</i><font color="#AAAAAA">=false</font>
390/// </pre>
391#[derive(Default, Debug, Copy, Clone, Eq, PartialEq)]
392pub struct Full;
393
394/// A pre-configured event formatter.
395///
396/// You will usually want to use this as the [`FormatEvent`] for a [`FmtSubscriber`].
397///
398/// The default logging format, [`Full`] includes all fields in each event and its containing
399/// spans. The [`Compact`] logging format is intended to produce shorter log
400/// lines; it displays each event's fields, along with fields from the current
401/// span context, but other information is abbreviated. The [`Pretty`] logging
402/// format is an extra-verbose, multi-line human-readable logging format
403/// intended for use in development.
404///
405/// [`FmtSubscriber`]: super::Subscriber
406#[derive(Debug, Clone)]
407pub struct Format<F = Full, T = SystemTime> {
408 format: F,
409 pub(crate) timer: T,
410 pub(crate) ansi: Option<bool>,
411 pub(crate) display_timestamp: bool,
412 pub(crate) display_target: bool,
413 pub(crate) display_level: bool,
414 pub(crate) display_thread_id: bool,
415 pub(crate) display_thread_name: bool,
416 pub(crate) display_filename: bool,
417 pub(crate) display_line_number: bool,
418}
419
420// === impl Writer ===
421
422impl<'writer> Writer<'writer> {
423 // TODO(eliza): consider making this a public API?
424 // We may not want to do that if we choose to expose specialized
425 // constructors instead (e.g. `from_string` that stores whether the string
426 // is empty...?)
427 //(@kaifastromai) I suppose having dedicated constructors may have certain benefits
428 // but I am not privy to the larger direction of tracing/subscriber.
429 /// Create a new [`Writer`] from any type that implements [`fmt::Write`].
430 ///
431 /// The returned `Writer` value may be passed as an argument to methods
432 /// such as [`Format::format_event`]. Since constructing a [`Writer`]
433 /// mutably borrows the underlying [`fmt::Write`] instance, that value may
434 /// be accessed again once the [`Writer`] is dropped. For example, if the
435 /// value implementing [`fmt::Write`] is a [`String`], it will contain
436 /// the formatted output of [`Format::format_event`], which may then be
437 /// used for other purposes.
438 ///
439 /// [`String`]: alloc::string::String
440 #[must_use]
441 pub fn new(writer: &'writer mut impl fmt::Write) -> Self {
442 Self {
443 writer: writer as &mut dyn fmt::Write,
444 is_ansi: false,
445 ansi_sanitization: true,
446 }
447 }
448
449 // TODO(eliza): consider making this a public API?
450 pub(crate) fn with_ansi(self, is_ansi: bool) -> Self {
451 Self { is_ansi, ..self }
452 }
453
454 pub(crate) fn with_ansi_sanitization(self, ansi_sanitization: bool) -> Self {
455 Self {
456 ansi_sanitization,
457 ..self
458 }
459 }
460
461 /// Return a new [`Writer`] that mutably borrows [`self`].
462 ///
463 /// This can be used to temporarily borrow a [`Writer`] to pass a new [`Writer`]
464 /// to a function that takes a [`Writer`] by value, allowing the original writer
465 /// to still be used once that function returns.
466 pub fn by_ref(&mut self) -> Writer<'_> {
467 let is_ansi = self.is_ansi;
468 let ansi_sanitization = self.ansi_sanitization;
469 Writer {
470 writer: self as &mut dyn fmt::Write,
471 is_ansi,
472 ansi_sanitization,
473 }
474 }
475
476 /// Writes a string slice into this [`Writer`], returning whether the write succeeded.
477 ///
478 /// This method can only succeed if the entire string slice was successfully
479 /// written, and this method will not return until all data has been written
480 /// or an error occurs.
481 ///
482 /// This is identical to calling the [`write_str` method] from the [`Writer`]'s
483 /// [`std::fmt::Write`] implementation. However, it is also provided as an
484 /// inherent method, so that [`Writer`]s can be used without needing to import the
485 /// [`std::fmt::Write`] trait.
486 ///
487 /// # Errors
488 ///
489 /// This function will return an instance of [`std::fmt::Error`] on error.
490 ///
491 /// [`write_str` method]: std::fmt::Write::write_str
492 #[inline]
493 pub fn write_str(&mut self, s: &str) -> fmt::Result {
494 self.writer.write_str(s)
495 }
496
497 /// Writes a [`char`] into this writer, returning whether the write succeeded.
498 ///
499 /// A single [`char`] may be encoded as more than one byte.
500 /// This method can only succeed if the entire byte sequence was successfully
501 /// written, and this method will not return until all data has been
502 /// written or an error occurs.
503 ///
504 /// This is identical to calling the [`write_char` method] from the [`Writer`]'s
505 /// [`std::fmt::Write`] implementation. However, it is also provided as an
506 /// inherent method, so that [`Writer`]s can be used without needing to import the
507 /// [`std::fmt::Write`] trait.
508 ///
509 /// # Errors
510 ///
511 /// This function will return an instance of [`std::fmt::Error`] on error.
512 ///
513 /// [`write_char` method]: std::fmt::Write::write_char
514 #[inline]
515 pub fn write_char(&mut self, c: char) -> fmt::Result {
516 self.writer.write_char(c)
517 }
518
519 /// Glue for usage of the [`write!`] macro with [`Writer`]s.
520 ///
521 /// This method should generally not be invoked manually, but rather through
522 /// the [`write!`] macro itself.
523 ///
524 /// This is identical to calling the [`write_fmt` method] from the [`Writer`]'s
525 /// [`std::fmt::Write`] implementation. However, it is also provided as an
526 /// inherent method, so that [`Writer`]s can be used with the [`write!`] macro
527 /// without needing to import the
528 /// [`std::fmt::Write`] trait.
529 ///
530 /// [`write_fmt` method]: std::fmt::Write::write_fmt
531 pub fn write_fmt(&mut self, args: fmt::Arguments<'_>) -> fmt::Result {
532 self.writer.write_fmt(args)
533 }
534
535 /// Returns `true` if [ANSI escape codes] may be used to add colors
536 /// and other formatting when writing to this `Writer`.
537 ///
538 /// If this returns `false`, formatters should not emit ANSI escape codes.
539 ///
540 /// [ANSI escape codes]: https://en.wikipedia.org/wiki/ANSI_escape_code
541 pub fn has_ansi_escapes(&self) -> bool {
542 self.is_ansi
543 }
544
545 /// Returns `true` if ANSI escape codes should be sanitized.
546 pub fn sanitizes_ansi_escapes(&self) -> bool {
547 self.ansi_sanitization
548 }
549
550 pub(in crate::fmt::format) fn bold(&self) -> Style {
551 #[cfg(feature = "ansi")]
552 {
553 if self.is_ansi {
554 return Style::new().bold();
555 }
556 }
557
558 Style::new()
559 }
560
561 pub(in crate::fmt::format) fn dimmed(&self) -> Style {
562 #[cfg(feature = "ansi")]
563 {
564 if self.is_ansi {
565 return Style::new().dimmed();
566 }
567 }
568
569 Style::new()
570 }
571
572 pub(in crate::fmt::format) fn italic(&self) -> Style {
573 #[cfg(feature = "ansi")]
574 {
575 if self.is_ansi {
576 return Style::new().italic();
577 }
578 }
579
580 Style::new()
581 }
582}
583
584impl fmt::Write for Writer<'_> {
585 #[inline]
586 fn write_str(&mut self, s: &str) -> fmt::Result {
587 Writer::write_str(self, s)
588 }
589
590 #[inline]
591 fn write_char(&mut self, c: char) -> fmt::Result {
592 Writer::write_char(self, c)
593 }
594
595 #[inline]
596 fn write_fmt(&mut self, args: fmt::Arguments<'_>) -> fmt::Result {
597 Writer::write_fmt(self, args)
598 }
599}
600
601impl fmt::Debug for Writer<'_> {
602 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
603 f.debug_struct("Writer")
604 .field("writer", &format_args!("<&mut dyn fmt::Write>"))
605 .field("is_ansi", &self.is_ansi)
606 .field("ansi_sanitization", &self.ansi_sanitization)
607 .finish()
608 }
609}
610
611// === impl Format ===
612
613impl Default for Format<Full, SystemTime> {
614 fn default() -> Self {
615 Format {
616 format: Full,
617 timer: SystemTime,
618 ansi: None,
619 display_timestamp: true,
620 display_target: true,
621 display_level: true,
622 display_thread_id: false,
623 display_thread_name: false,
624 display_filename: false,
625 display_line_number: false,
626 }
627 }
628}
629
630impl<F, T> Format<F, T> {
631 /// Use a less verbose output format.
632 ///
633 /// See [`Compact`].
634 pub fn compact(self) -> Format<Compact, T> {
635 Format {
636 format: Compact,
637 timer: self.timer,
638 ansi: self.ansi,
639 display_target: self.display_target,
640 display_timestamp: self.display_timestamp,
641 display_level: self.display_level,
642 display_thread_id: self.display_thread_id,
643 display_thread_name: self.display_thread_name,
644 display_filename: self.display_filename,
645 display_line_number: self.display_line_number,
646 }
647 }
648
649 /// Use an excessively pretty, human-readable output format.
650 ///
651 /// See [`Pretty`].
652 ///
653 /// Note that this requires the `"ansi"` feature to be enabled.
654 ///
655 /// # Options
656 ///
657 /// [`Format::with_ansi`] can be used to disable ANSI terminal escape codes (which enable
658 /// formatting such as colors, bold, italic, etc) in event formatting. However, a field
659 /// formatter must be manually provided to avoid ANSI in the formatting of parent spans, like
660 /// so:
661 ///
662 /// ```
663 /// # use tracing_subscriber::fmt::format;
664 /// tracing_subscriber::fmt()
665 /// .pretty()
666 /// .with_ansi(false)
667 /// .fmt_fields(format::PrettyFields::new().with_ansi(false))
668 /// // ... other settings ...
669 /// .init();
670 /// ```
671 #[cfg(feature = "ansi")]
672 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
673 pub fn pretty(self) -> Format<Pretty, T> {
674 Format {
675 format: Pretty::default(),
676 timer: self.timer,
677 ansi: self.ansi,
678 display_target: self.display_target,
679 display_timestamp: self.display_timestamp,
680 display_level: self.display_level,
681 display_thread_id: self.display_thread_id,
682 display_thread_name: self.display_thread_name,
683 display_filename: true,
684 display_line_number: true,
685 }
686 }
687
688 /// Use the full JSON format.
689 ///
690 /// The full format includes fields from all entered spans.
691 ///
692 /// # Example Output
693 ///
694 /// ```ignore,json
695 /// {"timestamp":"Feb 20 11:28:15.096","level":"INFO","target":"mycrate","fields":{"message":"some message", "key": "value"}}
696 /// ```
697 ///
698 /// # Options
699 ///
700 /// - [`Format::flatten_event`] can be used to enable flattening event fields into the root
701 /// object.
702 #[cfg(feature = "json")]
703 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
704 pub fn json(self) -> Format<Json, T> {
705 Format {
706 format: Json::default(),
707 timer: self.timer,
708 ansi: self.ansi,
709 display_target: self.display_target,
710 display_timestamp: self.display_timestamp,
711 display_level: self.display_level,
712 display_thread_id: self.display_thread_id,
713 display_thread_name: self.display_thread_name,
714 display_filename: self.display_filename,
715 display_line_number: self.display_line_number,
716 }
717 }
718
719 /// Use the given [`timer`] for log message timestamps.
720 ///
721 /// See [`time` module] for the provided timer implementations.
722 ///
723 /// Note that using the `"time"` feature flag enables the
724 /// additional time formatters [`UtcTime`] and [`LocalTime`], which use the
725 /// [`time` crate] to provide more sophisticated timestamp formatting
726 /// options.
727 ///
728 /// [`timer`]: super::time::FormatTime
729 /// [`time` module]: mod@super::time
730 /// [`UtcTime`]: super::time::UtcTime
731 /// [`LocalTime`]: super::time::LocalTime
732 /// [`time` crate]: https://docs.rs/time/0.3
733 pub fn with_timer<T2>(self, timer: T2) -> Format<F, T2> {
734 Format {
735 format: self.format,
736 timer,
737 ansi: self.ansi,
738 display_target: self.display_target,
739 display_timestamp: self.display_timestamp,
740 display_level: self.display_level,
741 display_thread_id: self.display_thread_id,
742 display_thread_name: self.display_thread_name,
743 display_filename: self.display_filename,
744 display_line_number: self.display_line_number,
745 }
746 }
747
748 /// Do not emit timestamps with log messages.
749 pub fn without_time(self) -> Format<F, ()> {
750 Format {
751 format: self.format,
752 timer: (),
753 ansi: self.ansi,
754 display_timestamp: false,
755 display_target: self.display_target,
756 display_level: self.display_level,
757 display_thread_id: self.display_thread_id,
758 display_thread_name: self.display_thread_name,
759 display_filename: self.display_filename,
760 display_line_number: self.display_line_number,
761 }
762 }
763
764 /// Enable ANSI terminal colors for formatted output.
765 pub fn with_ansi(self, ansi: bool) -> Format<F, T> {
766 Format {
767 ansi: Some(ansi),
768 ..self
769 }
770 }
771
772 /// Sets whether or not an event's target is displayed.
773 pub fn with_target(self, display_target: bool) -> Format<F, T> {
774 Format {
775 display_target,
776 ..self
777 }
778 }
779
780 /// Sets whether or not an event's level is displayed.
781 pub fn with_level(self, display_level: bool) -> Format<F, T> {
782 Format {
783 display_level,
784 ..self
785 }
786 }
787
788 /// Sets whether or not the [thread ID] of the current thread is displayed
789 /// when formatting events.
790 ///
791 /// [thread ID]: std::thread::ThreadId
792 pub fn with_thread_ids(self, display_thread_id: bool) -> Format<F, T> {
793 Format {
794 display_thread_id,
795 ..self
796 }
797 }
798
799 /// Sets whether or not the [name] of the current thread is displayed
800 /// when formatting events.
801 ///
802 /// [name]: std::thread#naming-threads
803 pub fn with_thread_names(self, display_thread_name: bool) -> Format<F, T> {
804 Format {
805 display_thread_name,
806 ..self
807 }
808 }
809
810 /// Sets whether or not an event's [source code file path][file] is
811 /// displayed.
812 ///
813 /// [file]: tracing_core::Metadata::file
814 pub fn with_file(self, display_filename: bool) -> Format<F, T> {
815 Format {
816 display_filename,
817 ..self
818 }
819 }
820
821 /// Sets whether or not an event's [source code line number][line] is
822 /// displayed.
823 ///
824 /// [line]: tracing_core::Metadata::line
825 pub fn with_line_number(self, display_line_number: bool) -> Format<F, T> {
826 Format {
827 display_line_number,
828 ..self
829 }
830 }
831
832 /// Sets whether or not the source code location from which an event
833 /// originated is displayed.
834 ///
835 /// This is equivalent to calling [`Format::with_file`] and
836 /// [`Format::with_line_number`] with the same value.
837 pub fn with_source_location(self, display_location: bool) -> Self {
838 self.with_line_number(display_location)
839 .with_file(display_location)
840 }
841
842 #[inline]
843 fn format_timestamp(&self, writer: &mut Writer<'_>) -> fmt::Result
844 where
845 T: FormatTime,
846 {
847 // If timestamps are disabled, do nothing.
848 if !self.display_timestamp {
849 return Ok(());
850 }
851
852 // If ANSI color codes are enabled, format the timestamp with ANSI
853 // colors.
854 #[cfg(feature = "ansi")]
855 {
856 if writer.has_ansi_escapes() {
857 let style = Style::new().dimmed();
858 write!(writer, "{}", style.prefix())?;
859
860 // If getting the timestamp failed, don't bail --- only bail on
861 // formatting errors.
862 if self.timer.format_time(writer).is_err() {
863 writer.write_str("<unknown time>")?;
864 }
865
866 write!(writer, "{} ", style.suffix())?;
867 return Ok(());
868 }
869 }
870
871 // Otherwise, just format the timestamp without ANSI formatting.
872 // If getting the timestamp failed, don't bail --- only bail on
873 // formatting errors.
874 if self.timer.format_time(writer).is_err() {
875 writer.write_str("<unknown time>")?;
876 }
877 writer.write_char(' ')
878 }
879}
880
881#[cfg(feature = "json")]
882#[cfg_attr(docsrs, doc(cfg(feature = "json")))]
883impl<T> Format<Json, T> {
884 /// Use the full JSON format with the event's event fields flattened.
885 ///
886 /// # Example Output
887 ///
888 /// ```ignore,json
889 /// {"timestamp":"Feb 20 11:28:15.096","level":"INFO","target":"mycrate", "message":"some message", "key": "value"}
890 /// ```
891 /// See [`Json`].
892 #[cfg(feature = "json")]
893 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
894 pub fn flatten_event(mut self, flatten_event: bool) -> Format<Json, T> {
895 self.format.flatten_event(flatten_event);
896 self
897 }
898
899 /// Sets whether or not the formatter will include the current span in
900 /// formatted events.
901 ///
902 /// See [`format::Json`][Json]
903 #[cfg(feature = "json")]
904 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
905 pub fn with_current_span(mut self, display_current_span: bool) -> Format<Json, T> {
906 self.format.with_current_span(display_current_span);
907 self
908 }
909
910 /// Sets whether or not the formatter will include a list (from root to
911 /// leaf) of all currently entered spans in formatted events.
912 ///
913 /// See [`format::Json`][Json]
914 #[cfg(feature = "json")]
915 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
916 pub fn with_span_list(mut self, display_span_list: bool) -> Format<Json, T> {
917 self.format.with_span_list(display_span_list);
918 self
919 }
920}
921
922impl<S, N, T> FormatEvent<S, N> for Format<Full, T>
923where
924 S: Subscriber + for<'a> LookupSpan<'a>,
925 N: for<'a> FormatFields<'a> + 'static,
926 T: FormatTime,
927{
928 fn format_event(
929 &self,
930 ctx: &FmtContext<'_, S, N>,
931 mut writer: Writer<'_>,
932 event: &Event<'_>,
933 ) -> fmt::Result {
934 #[cfg(feature = "tracing-log")]
935 let normalized_meta = event.normalized_metadata();
936 #[cfg(feature = "tracing-log")]
937 let meta = normalized_meta.as_ref().unwrap_or_else(|| event.metadata());
938 #[cfg(not(feature = "tracing-log"))]
939 let meta = event.metadata();
940
941 // if the `Format` struct *also* has an ANSI color configuration,
942 // override the writer...the API for configuring ANSI color codes on the
943 // `Format` struct is deprecated, but we still need to honor those
944 // configurations.
945 if let Some(ansi) = self.ansi {
946 writer = writer.with_ansi(ansi);
947 }
948
949 self.format_timestamp(&mut writer)?;
950
951 if self.display_level {
952 let fmt_level = {
953 #[cfg(feature = "ansi")]
954 {
955 FmtLevel::new(meta.level(), writer.has_ansi_escapes())
956 }
957 #[cfg(not(feature = "ansi"))]
958 {
959 FmtLevel::new(meta.level())
960 }
961 };
962 write!(writer, "{} ", fmt_level)?;
963 }
964
965 if self.display_thread_name {
966 let current_thread = std::thread::current();
967 match current_thread.name() {
968 Some(name) => {
969 write!(writer, "{} ", FmtThreadName::new(name))?;
970 }
971 // fall-back to thread id when name is absent and ids are not enabled
972 None if !self.display_thread_id => {
973 write!(writer, "{:0>2?} ", current_thread.id())?;
974 }
975 _ => {}
976 }
977 }
978
979 if self.display_thread_id {
980 write!(writer, "{:0>2?} ", std::thread::current().id())?;
981 }
982
983 let dimmed = writer.dimmed();
984
985 if let Some(scope) = ctx.event_scope() {
986 let bold = writer.bold();
987
988 let mut seen = false;
989
990 for span in scope.from_root() {
991 write!(writer, "{}", bold.paint(span.metadata().name()))?;
992 seen = true;
993
994 let ext = span.extensions();
995 if let Some(fields) = &ext.get::<FormattedFields<N>>() {
996 if !fields.is_empty() {
997 write!(writer, "{}{}{}", bold.paint("{"), fields, bold.paint("}"))?;
998 }
999 }
1000 write!(writer, "{}", dimmed.paint(":"))?;
1001 }
1002
1003 if seen {
1004 writer.write_char(' ')?;
1005 }
1006 };
1007
1008 if self.display_target {
1009 write!(
1010 writer,
1011 "{}{} ",
1012 dimmed.paint(meta.target()),
1013 dimmed.paint(":")
1014 )?;
1015 }
1016
1017 let line_number = if self.display_line_number {
1018 meta.line()
1019 } else {
1020 None
1021 };
1022
1023 if self.display_filename {
1024 if let Some(filename) = meta.file() {
1025 write!(
1026 writer,
1027 "{}{}{}",
1028 dimmed.paint(filename),
1029 dimmed.paint(":"),
1030 if line_number.is_some() { "" } else { " " }
1031 )?;
1032 }
1033 }
1034
1035 if let Some(line_number) = line_number {
1036 write!(
1037 writer,
1038 "{}{}:{} ",
1039 dimmed.prefix(),
1040 line_number,
1041 dimmed.suffix()
1042 )?;
1043 }
1044
1045 ctx.format_fields(writer.by_ref(), event)?;
1046 writeln!(writer)
1047 }
1048}
1049
1050impl<S, N, T> FormatEvent<S, N> for Format<Compact, T>
1051where
1052 S: Subscriber + for<'a> LookupSpan<'a>,
1053 N: for<'a> FormatFields<'a> + 'static,
1054 T: FormatTime,
1055{
1056 fn format_event(
1057 &self,
1058 ctx: &FmtContext<'_, S, N>,
1059 mut writer: Writer<'_>,
1060 event: &Event<'_>,
1061 ) -> fmt::Result {
1062 #[cfg(feature = "tracing-log")]
1063 let normalized_meta = event.normalized_metadata();
1064 #[cfg(feature = "tracing-log")]
1065 let meta = normalized_meta.as_ref().unwrap_or_else(|| event.metadata());
1066 #[cfg(not(feature = "tracing-log"))]
1067 let meta = event.metadata();
1068
1069 // if the `Format` struct *also* has an ANSI color configuration,
1070 // override the writer...the API for configuring ANSI color codes on the
1071 // `Format` struct is deprecated, but we still need to honor those
1072 // configurations.
1073 if let Some(ansi) = self.ansi {
1074 writer = writer.with_ansi(ansi);
1075 }
1076
1077 self.format_timestamp(&mut writer)?;
1078
1079 if self.display_level {
1080 let fmt_level = {
1081 #[cfg(feature = "ansi")]
1082 {
1083 FmtLevel::new(meta.level(), writer.has_ansi_escapes())
1084 }
1085 #[cfg(not(feature = "ansi"))]
1086 {
1087 FmtLevel::new(meta.level())
1088 }
1089 };
1090 write!(writer, "{} ", fmt_level)?;
1091 }
1092
1093 if self.display_thread_name {
1094 let current_thread = std::thread::current();
1095 match current_thread.name() {
1096 Some(name) => {
1097 write!(writer, "{} ", FmtThreadName::new(name))?;
1098 }
1099 // fall-back to thread id when name is absent and ids are not enabled
1100 None if !self.display_thread_id => {
1101 write!(writer, "{:0>2?} ", current_thread.id())?;
1102 }
1103 _ => {}
1104 }
1105 }
1106
1107 if self.display_thread_id {
1108 write!(writer, "{:0>2?} ", std::thread::current().id())?;
1109 }
1110
1111 let fmt_ctx = {
1112 #[cfg(feature = "ansi")]
1113 {
1114 FmtCtx::new(ctx, event.parent(), writer.has_ansi_escapes())
1115 }
1116 #[cfg(not(feature = "ansi"))]
1117 {
1118 FmtCtx::new(&ctx, event.parent())
1119 }
1120 };
1121 write!(writer, "{}", fmt_ctx)?;
1122
1123 let dimmed = writer.dimmed();
1124
1125 let mut needs_space = false;
1126 if self.display_target {
1127 write!(
1128 writer,
1129 "{}{}",
1130 dimmed.paint(meta.target()),
1131 dimmed.paint(":")
1132 )?;
1133 needs_space = true;
1134 }
1135
1136 if self.display_filename {
1137 if let Some(filename) = meta.file() {
1138 if self.display_target {
1139 writer.write_char(' ')?;
1140 }
1141 write!(writer, "{}{}", dimmed.paint(filename), dimmed.paint(":"))?;
1142 needs_space = true;
1143 }
1144 }
1145
1146 if self.display_line_number {
1147 if let Some(line_number) = meta.line() {
1148 write!(
1149 writer,
1150 "{}{}{}{}",
1151 dimmed.prefix(),
1152 line_number,
1153 dimmed.suffix(),
1154 dimmed.paint(":")
1155 )?;
1156 needs_space = true;
1157 }
1158 }
1159
1160 if needs_space {
1161 writer.write_char(' ')?;
1162 }
1163
1164 ctx.format_fields(writer.by_ref(), event)?;
1165
1166 for span in ctx
1167 .event_scope()
1168 .into_iter()
1169 .flat_map(crate::registry::Scope::from_root)
1170 {
1171 let exts = span.extensions();
1172 if let Some(fields) = exts.get::<FormattedFields<N>>() {
1173 if !fields.is_empty() {
1174 write!(writer, " {}", dimmed.paint(&fields.fields))?;
1175 }
1176 }
1177 }
1178 writeln!(writer)
1179 }
1180}
1181
1182// === impl FormatFields ===
1183impl<'writer, M> FormatFields<'writer> for M
1184where
1185 M: MakeOutput<Writer<'writer>, fmt::Result>,
1186 M::Visitor: VisitFmt + VisitOutput<fmt::Result>,
1187{
1188 fn format_fields<R: RecordFields>(&self, writer: Writer<'writer>, fields: R) -> fmt::Result {
1189 let mut v = self.make_visitor(writer);
1190 fields.record(&mut v);
1191 v.finish()
1192 }
1193}
1194
1195/// The default [`FormatFields`] implementation.
1196///
1197#[derive(Debug)]
1198pub struct DefaultFields {
1199 // reserve the ability to add fields to this without causing a breaking
1200 // change in the future.
1201 _private: (),
1202}
1203
1204/// The [visitor] produced by [`DefaultFields`]'s [`MakeVisitor`] implementation.
1205///
1206/// [visitor]: super::super::field::Visit
1207/// [`MakeVisitor`]: super::super::field::MakeVisitor
1208#[derive(Debug)]
1209pub struct DefaultVisitor<'a> {
1210 writer: Writer<'a>,
1211 is_empty: bool,
1212 result: fmt::Result,
1213}
1214
1215impl DefaultFields {
1216 /// Returns a new default [`FormatFields`] implementation.
1217 pub fn new() -> Self {
1218 Self { _private: () }
1219 }
1220}
1221
1222impl Default for DefaultFields {
1223 fn default() -> Self {
1224 Self::new()
1225 }
1226}
1227
1228impl<'a> MakeVisitor<Writer<'a>> for DefaultFields {
1229 type Visitor = DefaultVisitor<'a>;
1230
1231 #[inline]
1232 fn make_visitor(&self, target: Writer<'a>) -> Self::Visitor {
1233 DefaultVisitor::new(target, true)
1234 }
1235}
1236
1237// === impl DefaultVisitor ===
1238
1239impl<'a> DefaultVisitor<'a> {
1240 /// Returns a new default visitor that formats to the provided `writer`.
1241 ///
1242 /// # Arguments
1243 /// - `writer`: the writer to format to.
1244 /// - `is_empty`: whether or not any fields have been previously written to
1245 /// that writer.
1246 pub fn new(writer: Writer<'a>, is_empty: bool) -> Self {
1247 Self {
1248 writer,
1249 is_empty,
1250 result: Ok(()),
1251 }
1252 }
1253
1254 fn maybe_pad(&mut self) {
1255 if self.is_empty {
1256 self.is_empty = false;
1257 } else {
1258 self.result = write!(self.writer, " ");
1259 }
1260 }
1261}
1262
1263impl field::Visit for DefaultVisitor<'_> {
1264 fn record_str(&mut self, field: &Field, value: &str) {
1265 if self.result.is_err() {
1266 return;
1267 }
1268
1269 if field.name() == "message" {
1270 self.record_debug(field, &format_args!("{}", value))
1271 } else {
1272 self.record_debug(field, &value)
1273 }
1274 }
1275
1276 fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) {
1277 let sanitize = self.writer.sanitizes_ansi_escapes();
1278 if let Some(source) = value.source() {
1279 let italic = self.writer.italic();
1280 self.record_debug(
1281 field,
1282 &format_args!(
1283 "{} {}{}{}{}",
1284 EscapeGuard::new(format_args!("{}", value), sanitize),
1285 italic.paint(field.name()),
1286 italic.paint(".sources"),
1287 self.writer.dimmed().paint("="),
1288 ErrorSourceList::new(source, sanitize)
1289 ),
1290 )
1291 } else {
1292 self.record_debug(
1293 field,
1294 &format_args!("{}", EscapeGuard::new(format_args!("{}", value), sanitize)),
1295 )
1296 }
1297 }
1298
1299 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
1300 if self.result.is_err() {
1301 return;
1302 }
1303
1304 let name = field.name();
1305
1306 // Skip fields that are actually log metadata that have already been handled
1307 #[cfg(feature = "tracing-log")]
1308 if name.starts_with("log.") {
1309 debug_assert_eq!(self.result, Ok(())); // no need to update self.result
1310 return;
1311 }
1312
1313 // emit separating spaces if needed
1314 self.maybe_pad();
1315
1316 self.result = match name {
1317 "message" => {
1318 // Escape ANSI characters to prevent malicious patterns (e.g., terminal injection attacks)
1319 write!(
1320 self.writer,
1321 "{:?}",
1322 EscapeGuard::new(value, self.writer.sanitizes_ansi_escapes())
1323 )
1324 }
1325 name if name.starts_with("r#") => write!(
1326 self.writer,
1327 "{}{}{:?}",
1328 self.writer.italic().paint(&name[2..]),
1329 self.writer.dimmed().paint("="),
1330 value
1331 ),
1332 name => write!(
1333 self.writer,
1334 "{}{}{:?}",
1335 self.writer.italic().paint(name),
1336 self.writer.dimmed().paint("="),
1337 value
1338 ),
1339 };
1340 }
1341}
1342
1343impl crate::field::VisitOutput<fmt::Result> for DefaultVisitor<'_> {
1344 fn finish(self) -> fmt::Result {
1345 self.result
1346 }
1347}
1348
1349impl crate::field::VisitFmt for DefaultVisitor<'_> {
1350 fn writer(&mut self) -> &mut dyn fmt::Write {
1351 &mut self.writer
1352 }
1353}
1354
1355/// Renders an error into a list of sources, *including* the error.
1356struct ErrorSourceList<'a> {
1357 error: &'a (dyn std::error::Error + 'static),
1358 ansi_sanitization: bool,
1359}
1360
1361impl<'a> ErrorSourceList<'a> {
1362 fn new(error: &'a (dyn std::error::Error + 'static), ansi_sanitization: bool) -> Self {
1363 Self {
1364 error,
1365 ansi_sanitization,
1366 }
1367 }
1368}
1369
1370impl Display for ErrorSourceList<'_> {
1371 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1372 let mut list = f.debug_list();
1373 let mut curr = Some(self.error);
1374 while let Some(curr_err) = curr {
1375 list.entry(&EscapeGuard::new(
1376 format_args!("{}", curr_err),
1377 self.ansi_sanitization,
1378 ));
1379 curr = curr_err.source();
1380 }
1381 list.finish()
1382 }
1383}
1384
1385struct FmtCtx<'a, S, N> {
1386 ctx: &'a FmtContext<'a, S, N>,
1387 span: Option<&'a span::Id>,
1388 #[cfg(feature = "ansi")]
1389 ansi: bool,
1390}
1391
1392impl<'a, S, N: 'a> FmtCtx<'a, S, N>
1393where
1394 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1395 N: for<'writer> FormatFields<'writer> + 'static,
1396{
1397 #[cfg(feature = "ansi")]
1398 pub(crate) fn new(
1399 ctx: &'a FmtContext<'_, S, N>,
1400 span: Option<&'a span::Id>,
1401 ansi: bool,
1402 ) -> Self {
1403 Self { ctx, span, ansi }
1404 }
1405
1406 #[cfg(not(feature = "ansi"))]
1407 pub(crate) fn new(ctx: &'a FmtContext<'_, S, N>, span: Option<&'a span::Id>) -> Self {
1408 Self { ctx, span }
1409 }
1410
1411 fn bold(&self) -> Style {
1412 #[cfg(feature = "ansi")]
1413 {
1414 if self.ansi {
1415 return Style::new().bold();
1416 }
1417 }
1418
1419 Style::new()
1420 }
1421}
1422
1423impl<'a, S, N: 'a> fmt::Display for FmtCtx<'a, S, N>
1424where
1425 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1426 N: for<'writer> FormatFields<'writer> + 'static,
1427{
1428 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1429 let bold = self.bold();
1430 let mut seen = false;
1431
1432 let span = self
1433 .span
1434 .and_then(|id| self.ctx.ctx.span(id))
1435 .or_else(|| self.ctx.ctx.lookup_current());
1436
1437 let scope = span.into_iter().flat_map(|span| span.scope().from_root());
1438
1439 for span in scope {
1440 seen = true;
1441 write!(f, "{}:", bold.paint(span.metadata().name()))?;
1442 }
1443
1444 if seen {
1445 f.write_char(' ')?;
1446 }
1447 Ok(())
1448 }
1449}
1450
1451#[cfg(not(feature = "ansi"))]
1452struct Style;
1453
1454#[cfg(not(feature = "ansi"))]
1455impl Style {
1456 fn new() -> Self {
1457 Style
1458 }
1459
1460 fn bold(self) -> Self {
1461 self
1462 }
1463
1464 fn paint(&self, d: impl fmt::Display) -> impl fmt::Display {
1465 d
1466 }
1467
1468 fn prefix(&self) -> impl fmt::Display {
1469 ""
1470 }
1471
1472 fn suffix(&self) -> impl fmt::Display {
1473 ""
1474 }
1475}
1476
1477struct FmtThreadName<'a> {
1478 name: &'a str,
1479}
1480
1481impl<'a> FmtThreadName<'a> {
1482 pub(crate) fn new(name: &'a str) -> Self {
1483 Self { name }
1484 }
1485}
1486
1487impl fmt::Display for FmtThreadName<'_> {
1488 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1489 use std::sync::atomic::{
1490 AtomicUsize,
1491 Ordering::{AcqRel, Acquire, Relaxed},
1492 };
1493
1494 // Track the longest thread name length we've seen so far in an atomic,
1495 // so that it can be updated by any thread.
1496 static MAX_LEN: AtomicUsize = AtomicUsize::new(0);
1497 let len = self.name.len();
1498 // Snapshot the current max thread name length.
1499 let mut max_len = MAX_LEN.load(Relaxed);
1500
1501 while len > max_len {
1502 // Try to set a new max length, if it is still the value we took a
1503 // snapshot of.
1504 match MAX_LEN.compare_exchange(max_len, len, AcqRel, Acquire) {
1505 // We successfully set the new max value
1506 Ok(_) => break,
1507 // Another thread set a new max value since we last observed
1508 // it! It's possible that the new length is actually longer than
1509 // ours, so we'll loop again and check whether our length is
1510 // still the longest. If not, we'll just use the newer value.
1511 Err(actual) => max_len = actual,
1512 }
1513 }
1514
1515 // pad thread name using `max_len`
1516 write!(f, "{:>width$}", self.name, width = max_len)
1517 }
1518}
1519
1520struct FmtLevel<'a> {
1521 level: &'a Level,
1522 #[cfg(feature = "ansi")]
1523 ansi: bool,
1524}
1525
1526impl<'a> FmtLevel<'a> {
1527 #[cfg(feature = "ansi")]
1528 pub(crate) fn new(level: &'a Level, ansi: bool) -> Self {
1529 Self { level, ansi }
1530 }
1531
1532 #[cfg(not(feature = "ansi"))]
1533 pub(crate) fn new(level: &'a Level) -> Self {
1534 Self { level }
1535 }
1536}
1537
1538const TRACE_STR: &str = "TRACE";
1539const DEBUG_STR: &str = "DEBUG";
1540const INFO_STR: &str = " INFO";
1541const WARN_STR: &str = " WARN";
1542const ERROR_STR: &str = "ERROR";
1543
1544#[cfg(not(feature = "ansi"))]
1545impl<'a> fmt::Display for FmtLevel<'a> {
1546 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1547 match *self.level {
1548 Level::TRACE => f.pad(TRACE_STR),
1549 Level::DEBUG => f.pad(DEBUG_STR),
1550 Level::INFO => f.pad(INFO_STR),
1551 Level::WARN => f.pad(WARN_STR),
1552 Level::ERROR => f.pad(ERROR_STR),
1553 }
1554 }
1555}
1556
1557#[cfg(feature = "ansi")]
1558impl fmt::Display for FmtLevel<'_> {
1559 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1560 if self.ansi {
1561 match *self.level {
1562 Level::TRACE => write!(f, "{}", Color::Purple.paint(TRACE_STR)),
1563 Level::DEBUG => write!(f, "{}", Color::Blue.paint(DEBUG_STR)),
1564 Level::INFO => write!(f, "{}", Color::Green.paint(INFO_STR)),
1565 Level::WARN => write!(f, "{}", Color::Yellow.paint(WARN_STR)),
1566 Level::ERROR => write!(f, "{}", Color::Red.paint(ERROR_STR)),
1567 }
1568 } else {
1569 match *self.level {
1570 Level::TRACE => f.pad(TRACE_STR),
1571 Level::DEBUG => f.pad(DEBUG_STR),
1572 Level::INFO => f.pad(INFO_STR),
1573 Level::WARN => f.pad(WARN_STR),
1574 Level::ERROR => f.pad(ERROR_STR),
1575 }
1576 }
1577 }
1578}
1579
1580// === impl FieldFn ===
1581
1582impl<'a, F> MakeVisitor<Writer<'a>> for FieldFn<F>
1583where
1584 F: Fn(&mut Writer<'a>, &Field, &dyn fmt::Debug) -> fmt::Result + Clone,
1585{
1586 type Visitor = FieldFnVisitor<'a, F>;
1587
1588 fn make_visitor(&self, writer: Writer<'a>) -> Self::Visitor {
1589 FieldFnVisitor {
1590 writer,
1591 f: self.0.clone(),
1592 result: Ok(()),
1593 }
1594 }
1595}
1596
1597impl<'a, F> Visit for FieldFnVisitor<'a, F>
1598where
1599 F: Fn(&mut Writer<'a>, &Field, &dyn fmt::Debug) -> fmt::Result,
1600{
1601 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
1602 if self.result.is_ok() {
1603 self.result = (self.f)(&mut self.writer, field, value)
1604 }
1605 }
1606}
1607
1608impl<'a, F> VisitOutput<fmt::Result> for FieldFnVisitor<'a, F>
1609where
1610 F: Fn(&mut Writer<'a>, &Field, &dyn fmt::Debug) -> fmt::Result,
1611{
1612 fn finish(self) -> fmt::Result {
1613 self.result
1614 }
1615}
1616
1617impl<'a, F> VisitFmt for FieldFnVisitor<'a, F>
1618where
1619 F: Fn(&mut Writer<'a>, &Field, &dyn fmt::Debug) -> fmt::Result,
1620{
1621 fn writer(&mut self) -> &mut dyn fmt::Write {
1622 &mut self.writer
1623 }
1624}
1625
1626impl<F> fmt::Debug for FieldFnVisitor<'_, F> {
1627 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1628 f.debug_struct("FieldFnVisitor")
1629 .field("f", &format_args!("{}", std::any::type_name::<F>()))
1630 .field("writer", &self.writer)
1631 .field("result", &self.result)
1632 .finish()
1633 }
1634}
1635
1636// === printing synthetic Span events ===
1637
1638/// Configures what points in the span lifecycle are logged as events.
1639///
1640/// See also [`with_span_events`].
1641///
1642/// [`with_span_events`]: super::SubscriberBuilder::with_span_events
1643#[derive(Clone, Eq, PartialEq, Ord, PartialOrd)]
1644pub struct FmtSpan(u8);
1645
1646impl FmtSpan {
1647 /// one event when span is created
1648 pub const NEW: FmtSpan = FmtSpan(1 << 0);
1649 /// one event per enter of a span
1650 pub const ENTER: FmtSpan = FmtSpan(1 << 1);
1651 /// one event per exit of a span
1652 pub const EXIT: FmtSpan = FmtSpan(1 << 2);
1653 /// one event when the span is dropped
1654 pub const CLOSE: FmtSpan = FmtSpan(1 << 3);
1655
1656 /// spans are ignored (this is the default)
1657 pub const NONE: FmtSpan = FmtSpan(0);
1658 /// one event per enter/exit of a span
1659 pub const ACTIVE: FmtSpan = FmtSpan(FmtSpan::ENTER.0 | FmtSpan::EXIT.0);
1660 /// events at all points (new, enter, exit, drop)
1661 pub const FULL: FmtSpan =
1662 FmtSpan(FmtSpan::NEW.0 | FmtSpan::ENTER.0 | FmtSpan::EXIT.0 | FmtSpan::CLOSE.0);
1663
1664 /// Check whether or not a certain flag is set for this [`FmtSpan`]
1665 fn contains(&self, other: FmtSpan) -> bool {
1666 self.clone() & other.clone() == other
1667 }
1668}
1669
1670macro_rules! impl_fmt_span_bit_op {
1671 ($trait:ident, $func:ident, $op:tt) => {
1672 impl std::ops::$trait for FmtSpan {
1673 type Output = FmtSpan;
1674
1675 fn $func(self, rhs: Self) -> Self::Output {
1676 FmtSpan(self.0 $op rhs.0)
1677 }
1678 }
1679 };
1680}
1681
1682macro_rules! impl_fmt_span_bit_assign_op {
1683 ($trait:ident, $func:ident, $op:tt) => {
1684 impl std::ops::$trait for FmtSpan {
1685 fn $func(&mut self, rhs: Self) {
1686 *self = FmtSpan(self.0 $op rhs.0)
1687 }
1688 }
1689 };
1690}
1691
1692impl_fmt_span_bit_op!(BitAnd, bitand, &);
1693impl_fmt_span_bit_op!(BitOr, bitor, |);
1694impl_fmt_span_bit_op!(BitXor, bitxor, ^);
1695
1696impl_fmt_span_bit_assign_op!(BitAndAssign, bitand_assign, &);
1697impl_fmt_span_bit_assign_op!(BitOrAssign, bitor_assign, |);
1698impl_fmt_span_bit_assign_op!(BitXorAssign, bitxor_assign, ^);
1699
1700impl Debug for FmtSpan {
1701 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1702 let mut wrote_flag = false;
1703 let mut write_flags = |flag, flag_str| -> fmt::Result {
1704 if self.contains(flag) {
1705 if wrote_flag {
1706 f.write_str(" | ")?;
1707 }
1708
1709 f.write_str(flag_str)?;
1710 wrote_flag = true;
1711 }
1712
1713 Ok(())
1714 };
1715
1716 if FmtSpan::NONE | self.clone() == FmtSpan::NONE {
1717 f.write_str("FmtSpan::NONE")?;
1718 } else {
1719 write_flags(FmtSpan::NEW, "FmtSpan::NEW")?;
1720 write_flags(FmtSpan::ENTER, "FmtSpan::ENTER")?;
1721 write_flags(FmtSpan::EXIT, "FmtSpan::EXIT")?;
1722 write_flags(FmtSpan::CLOSE, "FmtSpan::CLOSE")?;
1723 }
1724
1725 Ok(())
1726 }
1727}
1728
1729pub(super) struct FmtSpanConfig {
1730 pub(super) kind: FmtSpan,
1731 pub(super) fmt_timing: bool,
1732}
1733
1734impl FmtSpanConfig {
1735 pub(super) fn without_time(self) -> Self {
1736 Self {
1737 kind: self.kind,
1738 fmt_timing: false,
1739 }
1740 }
1741 pub(super) fn with_kind(self, kind: FmtSpan) -> Self {
1742 Self {
1743 kind,
1744 fmt_timing: self.fmt_timing,
1745 }
1746 }
1747 pub(super) fn trace_new(&self) -> bool {
1748 self.kind.contains(FmtSpan::NEW)
1749 }
1750 pub(super) fn trace_enter(&self) -> bool {
1751 self.kind.contains(FmtSpan::ENTER)
1752 }
1753 pub(super) fn trace_exit(&self) -> bool {
1754 self.kind.contains(FmtSpan::EXIT)
1755 }
1756 pub(super) fn trace_close(&self) -> bool {
1757 self.kind.contains(FmtSpan::CLOSE)
1758 }
1759}
1760
1761impl Debug for FmtSpanConfig {
1762 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1763 self.kind.fmt(f)
1764 }
1765}
1766
1767impl Default for FmtSpanConfig {
1768 fn default() -> Self {
1769 Self {
1770 kind: FmtSpan::NONE,
1771 fmt_timing: true,
1772 }
1773 }
1774}
1775
1776pub(super) struct TimingDisplay(pub(super) u64);
1777impl Display for TimingDisplay {
1778 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1779 let mut t = self.0 as f64;
1780 for unit in ["ns", "µs", "ms", "s"].iter() {
1781 if t < 10.0 {
1782 return write!(f, "{:.2}{}", t, unit);
1783 } else if t < 100.0 {
1784 return write!(f, "{:.1}{}", t, unit);
1785 } else if t < 1000.0 {
1786 return write!(f, "{:.0}{}", t, unit);
1787 }
1788 t /= 1000.0;
1789 }
1790 write!(f, "{:.0}s", t * 1000.0)
1791 }
1792}
1793
1794#[cfg(test)]
1795pub(super) mod test {
1796 use crate::fmt::{test::MockMakeWriter, time::FormatTime};
1797 use alloc::{
1798 borrow::ToOwned,
1799 format,
1800 string::{String, ToString},
1801 };
1802 use tracing::{
1803 self,
1804 dispatcher::{set_default, Dispatch},
1805 subscriber::with_default,
1806 };
1807
1808 use super::*;
1809
1810 use regex::Regex;
1811 use std::{fmt, path::Path};
1812
1813 pub(crate) struct MockTime;
1814 impl FormatTime for MockTime {
1815 fn format_time(&self, w: &mut Writer<'_>) -> fmt::Result {
1816 write!(w, "fake time")
1817 }
1818 }
1819
1820 #[test]
1821 fn disable_everything() {
1822 // This test reproduces https://github.com/tokio-rs/tracing/issues/1354
1823 let make_writer = MockMakeWriter::default();
1824 let subscriber = crate::fmt::Subscriber::builder()
1825 .with_writer(make_writer.clone())
1826 .without_time()
1827 .with_level(false)
1828 .with_target(false)
1829 .with_thread_ids(false)
1830 .with_thread_names(false);
1831 #[cfg(feature = "ansi")]
1832 let subscriber = subscriber.with_ansi(false);
1833 assert_info_hello(subscriber, make_writer, "hello\n")
1834 }
1835
1836 fn test_ansi<T>(
1837 is_ansi: bool,
1838 expected: &str,
1839 builder: crate::fmt::SubscriberBuilder<DefaultFields, Format<T>>,
1840 ) where
1841 Format<T, MockTime>: FormatEvent<crate::Registry, DefaultFields>,
1842 T: Send + Sync + 'static,
1843 {
1844 let make_writer = MockMakeWriter::default();
1845 let subscriber = builder
1846 .with_writer(make_writer.clone())
1847 .with_ansi(is_ansi)
1848 .with_timer(MockTime);
1849 run_test(subscriber, make_writer, expected)
1850 }
1851
1852 #[cfg(not(feature = "ansi"))]
1853 fn test_without_ansi<T>(
1854 expected: &str,
1855 builder: crate::fmt::SubscriberBuilder<DefaultFields, Format<T>>,
1856 ) where
1857 Format<T, MockTime>: FormatEvent<crate::Registry, DefaultFields>,
1858 T: Send + Sync,
1859 {
1860 let make_writer = MockMakeWriter::default();
1861 let subscriber = builder.with_writer(make_writer).with_timer(MockTime);
1862 run_test(subscriber, make_writer, expected)
1863 }
1864
1865 fn test_without_level<T>(
1866 expected: &str,
1867 builder: crate::fmt::SubscriberBuilder<DefaultFields, Format<T>>,
1868 ) where
1869 Format<T, MockTime>: FormatEvent<crate::Registry, DefaultFields>,
1870 T: Send + Sync + 'static,
1871 {
1872 let make_writer = MockMakeWriter::default();
1873 let subscriber = builder
1874 .with_writer(make_writer.clone())
1875 .with_level(false)
1876 .with_ansi(false)
1877 .with_timer(MockTime);
1878 run_test(subscriber, make_writer, expected);
1879 }
1880
1881 #[test]
1882 fn with_line_number_and_file_name() {
1883 let make_writer = MockMakeWriter::default();
1884 let subscriber = crate::fmt::Subscriber::builder()
1885 .with_writer(make_writer.clone())
1886 .with_file(true)
1887 .with_line_number(true)
1888 .with_level(false)
1889 .with_ansi(false)
1890 .with_timer(MockTime);
1891
1892 let expected = Regex::new(&format!(
1893 "^fake time tracing_subscriber::fmt::format::test: {}:[0-9]+: hello\n$",
1894 current_path()
1895 // if we're on Windows, the path might contain backslashes, which
1896 // have to be escaped before compiling the regex.
1897 .replace('\\', "\\\\")
1898 ))
1899 .unwrap();
1900 let _default = set_default(&subscriber.into());
1901 tracing::info!("hello");
1902 let res = make_writer.get_string();
1903 assert!(expected.is_match(&res));
1904 }
1905
1906 #[test]
1907 fn with_line_number() {
1908 let make_writer = MockMakeWriter::default();
1909 let subscriber = crate::fmt::Subscriber::builder()
1910 .with_writer(make_writer.clone())
1911 .with_line_number(true)
1912 .with_level(false)
1913 .with_ansi(false)
1914 .with_timer(MockTime);
1915
1916 let expected =
1917 Regex::new("^fake time tracing_subscriber::fmt::format::test: [0-9]+: hello\n$")
1918 .unwrap();
1919 let _default = set_default(&subscriber.into());
1920 tracing::info!("hello");
1921 let res = make_writer.get_string();
1922 assert!(expected.is_match(&res));
1923 }
1924
1925 #[test]
1926 fn with_filename() {
1927 let make_writer = MockMakeWriter::default();
1928 let subscriber = crate::fmt::Subscriber::builder()
1929 .with_writer(make_writer.clone())
1930 .with_file(true)
1931 .with_level(false)
1932 .with_ansi(false)
1933 .with_timer(MockTime);
1934 let expected = &format!(
1935 "fake time tracing_subscriber::fmt::format::test: {}: hello\n",
1936 current_path(),
1937 );
1938 assert_info_hello(subscriber, make_writer, expected);
1939 }
1940
1941 #[test]
1942 fn with_thread_ids() {
1943 let make_writer = MockMakeWriter::default();
1944 let subscriber = crate::fmt::Subscriber::builder()
1945 .with_writer(make_writer.clone())
1946 .with_thread_ids(true)
1947 .with_ansi(false)
1948 .with_timer(MockTime);
1949 let expected =
1950 "fake time INFO ThreadId(NUMERIC) tracing_subscriber::fmt::format::test: hello\n";
1951
1952 assert_info_hello_ignore_numeric(subscriber, make_writer, expected);
1953 }
1954
1955 #[test]
1956 fn pretty_default() {
1957 let make_writer = MockMakeWriter::default();
1958 let subscriber = crate::fmt::Subscriber::builder()
1959 .pretty()
1960 .with_writer(make_writer.clone())
1961 .with_ansi(false)
1962 .with_timer(MockTime);
1963 let expected = format!(
1964 r#" fake time INFO tracing_subscriber::fmt::format::test: hello
1965 at {}:NUMERIC
1966
1967"#,
1968 file!()
1969 );
1970
1971 assert_info_hello_ignore_numeric(subscriber, make_writer, &expected)
1972 }
1973
1974 fn assert_info_hello(subscriber: impl Into<Dispatch>, buf: MockMakeWriter, expected: &str) {
1975 let _default = set_default(&subscriber.into());
1976 tracing::info!("hello");
1977 let result = buf.get_string();
1978
1979 assert_eq!(expected, result)
1980 }
1981
1982 // When numeric characters are used they often form a non-deterministic value as they usually represent things like a thread id or line number.
1983 // This assert method should be used when non-deterministic numeric characters are present.
1984 fn assert_info_hello_ignore_numeric(
1985 subscriber: impl Into<Dispatch>,
1986 buf: MockMakeWriter,
1987 expected: &str,
1988 ) {
1989 let _default = set_default(&subscriber.into());
1990 tracing::info!("hello");
1991
1992 let regex = Regex::new("[0-9]+").unwrap();
1993 let result = buf.get_string();
1994 let result_cleaned = regex.replace_all(&result, "NUMERIC");
1995
1996 assert_eq!(expected, result_cleaned)
1997 }
1998
1999 fn test_overridden_parents<T>(
2000 expected: &str,
2001 builder: crate::fmt::SubscriberBuilder<DefaultFields, Format<T>>,
2002 ) where
2003 Format<T, MockTime>: FormatEvent<crate::Registry, DefaultFields>,
2004 T: Send + Sync + 'static,
2005 {
2006 let make_writer = MockMakeWriter::default();
2007 let subscriber = builder
2008 .with_writer(make_writer.clone())
2009 .with_level(false)
2010 .with_ansi(false)
2011 .with_timer(MockTime)
2012 .finish();
2013
2014 with_default(subscriber, || {
2015 let span1 = tracing::info_span!("span1", span = 1);
2016 let span2 = tracing::info_span!(parent: &span1, "span2", span = 2);
2017 tracing::info!(parent: &span2, "hello");
2018 });
2019 assert_eq!(expected, make_writer.get_string());
2020 }
2021
2022 fn test_overridden_parents_in_scope<T>(
2023 expected1: &str,
2024 expected2: &str,
2025 builder: crate::fmt::SubscriberBuilder<DefaultFields, Format<T>>,
2026 ) where
2027 Format<T, MockTime>: FormatEvent<crate::Registry, DefaultFields>,
2028 T: Send + Sync + 'static,
2029 {
2030 let make_writer = MockMakeWriter::default();
2031 let subscriber = builder
2032 .with_writer(make_writer.clone())
2033 .with_level(false)
2034 .with_ansi(false)
2035 .with_timer(MockTime)
2036 .finish();
2037
2038 with_default(subscriber, || {
2039 let span1 = tracing::info_span!("span1", span = 1);
2040 let span2 = tracing::info_span!(parent: &span1, "span2", span = 2);
2041 let span3 = tracing::info_span!("span3", span = 3);
2042 let _e3 = span3.enter();
2043
2044 tracing::info!("hello");
2045 assert_eq!(expected1, make_writer.get_string().as_str());
2046
2047 tracing::info!(parent: &span2, "hello");
2048 assert_eq!(expected2, make_writer.get_string().as_str());
2049 });
2050 }
2051
2052 fn run_test(subscriber: impl Into<Dispatch>, buf: MockMakeWriter, expected: &str) {
2053 let _default = set_default(&subscriber.into());
2054 tracing::info!("hello");
2055 assert_eq!(expected, buf.get_string())
2056 }
2057
2058 mod default {
2059 use super::*;
2060
2061 #[test]
2062 fn with_thread_ids() {
2063 let make_writer = MockMakeWriter::default();
2064 let subscriber = crate::fmt::Subscriber::builder()
2065 .with_writer(make_writer.clone())
2066 .with_thread_ids(true)
2067 .with_ansi(false)
2068 .with_timer(MockTime);
2069 let expected =
2070 "fake time INFO ThreadId(NUMERIC) tracing_subscriber::fmt::format::test: hello\n";
2071
2072 assert_info_hello_ignore_numeric(subscriber, make_writer, expected);
2073 }
2074
2075 #[cfg(feature = "ansi")]
2076 #[test]
2077 fn with_ansi_true() {
2078 let expected = "\u{1b}[2mfake time\u{1b}[0m \u{1b}[32m INFO\u{1b}[0m \u{1b}[2mtracing_subscriber::fmt::format::test\u{1b}[0m\u{1b}[2m:\u{1b}[0m hello\n";
2079 test_ansi(true, expected, crate::fmt::Subscriber::builder());
2080 }
2081
2082 #[cfg(feature = "ansi")]
2083 #[test]
2084 fn with_ansi_false() {
2085 let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n";
2086 test_ansi(false, expected, crate::fmt::Subscriber::builder());
2087 }
2088
2089 #[cfg(not(feature = "ansi"))]
2090 #[test]
2091 fn without_ansi() {
2092 let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n";
2093 test_without_ansi(expected, crate::fmt::Subscriber::builder())
2094 }
2095
2096 #[test]
2097 fn without_level() {
2098 let expected = "fake time tracing_subscriber::fmt::format::test: hello\n";
2099 test_without_level(expected, crate::fmt::Subscriber::builder())
2100 }
2101
2102 #[test]
2103 fn overridden_parents() {
2104 let expected = "fake time span1{span=1}:span2{span=2}: tracing_subscriber::fmt::format::test: hello\n";
2105 test_overridden_parents(expected, crate::fmt::Subscriber::builder())
2106 }
2107
2108 #[test]
2109 fn overridden_parents_in_scope() {
2110 test_overridden_parents_in_scope(
2111 "fake time span3{span=3}: tracing_subscriber::fmt::format::test: hello\n",
2112 "fake time span1{span=1}:span2{span=2}: tracing_subscriber::fmt::format::test: hello\n",
2113 crate::fmt::Subscriber::builder(),
2114 )
2115 }
2116 }
2117
2118 mod compact {
2119 use super::*;
2120
2121 #[cfg(feature = "ansi")]
2122 #[test]
2123 fn with_ansi_true() {
2124 let expected = "\u{1b}[2mfake time\u{1b}[0m \u{1b}[32m INFO\u{1b}[0m \u{1b}[2mtracing_subscriber::fmt::format::test\u{1b}[0m\u{1b}[2m:\u{1b}[0m hello\n";
2125 test_ansi(true, expected, crate::fmt::Subscriber::builder().compact())
2126 }
2127
2128 #[cfg(feature = "ansi")]
2129 #[test]
2130 fn with_ansi_false() {
2131 let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n";
2132 test_ansi(false, expected, crate::fmt::Subscriber::builder().compact());
2133 }
2134
2135 #[cfg(not(feature = "ansi"))]
2136 #[test]
2137 fn without_ansi() {
2138 let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n";
2139 test_without_ansi(expected, crate::fmt::Subscriber::builder().compact())
2140 }
2141
2142 #[test]
2143 fn without_level() {
2144 let expected = "fake time tracing_subscriber::fmt::format::test: hello\n";
2145 test_without_level(expected, crate::fmt::Subscriber::builder().compact());
2146 }
2147
2148 #[test]
2149 fn overridden_parents() {
2150 let expected = "fake time span1:span2: tracing_subscriber::fmt::format::test: hello span=1 span=2\n";
2151 test_overridden_parents(expected, crate::fmt::Subscriber::builder().compact())
2152 }
2153
2154 #[test]
2155 fn overridden_parents_in_scope() {
2156 test_overridden_parents_in_scope(
2157 "fake time span3: tracing_subscriber::fmt::format::test: hello span=3\n",
2158 "fake time span1:span2: tracing_subscriber::fmt::format::test: hello span=1 span=2\n",
2159 crate::fmt::Subscriber::builder().compact(),
2160 )
2161 }
2162 }
2163
2164 mod pretty {
2165 use super::*;
2166
2167 #[test]
2168 fn pretty_default() {
2169 let make_writer = MockMakeWriter::default();
2170 let subscriber = crate::fmt::Subscriber::builder()
2171 .pretty()
2172 .with_writer(make_writer.clone())
2173 .with_ansi(false)
2174 .with_timer(MockTime);
2175 let expected = format!(
2176 " fake time INFO tracing_subscriber::fmt::format::test: hello\n at {}:NUMERIC\n\n",
2177 file!()
2178 );
2179
2180 assert_info_hello_ignore_numeric(subscriber, make_writer, &expected)
2181 }
2182 }
2183
2184 #[test]
2185 fn format_nanos() {
2186 fn fmt(t: u64) -> String {
2187 TimingDisplay(t).to_string()
2188 }
2189
2190 assert_eq!(fmt(1), "1.00ns");
2191 assert_eq!(fmt(12), "12.0ns");
2192 assert_eq!(fmt(123), "123ns");
2193 assert_eq!(fmt(1234), "1.23µs");
2194 assert_eq!(fmt(12345), "12.3µs");
2195 assert_eq!(fmt(123456), "123µs");
2196 assert_eq!(fmt(1234567), "1.23ms");
2197 assert_eq!(fmt(12345678), "12.3ms");
2198 assert_eq!(fmt(123456789), "123ms");
2199 assert_eq!(fmt(1234567890), "1.23s");
2200 assert_eq!(fmt(12345678901), "12.3s");
2201 assert_eq!(fmt(123456789012), "123s");
2202 assert_eq!(fmt(1234567890123), "1235s");
2203 }
2204
2205 #[test]
2206 fn fmt_span_combinations() {
2207 let f = FmtSpan::NONE;
2208 assert!(!f.contains(FmtSpan::NEW));
2209 assert!(!f.contains(FmtSpan::ENTER));
2210 assert!(!f.contains(FmtSpan::EXIT));
2211 assert!(!f.contains(FmtSpan::CLOSE));
2212
2213 let f = FmtSpan::ACTIVE;
2214 assert!(!f.contains(FmtSpan::NEW));
2215 assert!(f.contains(FmtSpan::ENTER));
2216 assert!(f.contains(FmtSpan::EXIT));
2217 assert!(!f.contains(FmtSpan::CLOSE));
2218
2219 let f = FmtSpan::FULL;
2220 assert!(f.contains(FmtSpan::NEW));
2221 assert!(f.contains(FmtSpan::ENTER));
2222 assert!(f.contains(FmtSpan::EXIT));
2223 assert!(f.contains(FmtSpan::CLOSE));
2224
2225 let f = FmtSpan::NEW | FmtSpan::CLOSE;
2226 assert!(f.contains(FmtSpan::NEW));
2227 assert!(!f.contains(FmtSpan::ENTER));
2228 assert!(!f.contains(FmtSpan::EXIT));
2229 assert!(f.contains(FmtSpan::CLOSE));
2230 }
2231
2232 /// Returns the test's module path.
2233 fn current_path() -> String {
2234 Path::new("tracing-subscriber")
2235 .join("src")
2236 .join("fmt")
2237 .join("format")
2238 .join("mod.rs")
2239 .to_str()
2240 .expect("path must not contain invalid unicode")
2241 .to_owned()
2242 }
2243}