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