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