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