vendor/tracing-subscriber/src/fmt/fmt_layer.rs

   1 use crate::{
   2     field::RecordFields,
   3     fmt::{format, FormatEvent, FormatFields, MakeWriter, TestWriter},
   4     layer::{self, Context, Scope},
   5     registry::{LookupSpan, SpanRef},
   6 };
   7 use format::{FmtSpan, TimingDisplay};
   8 use std::{any::TypeId, cell::RefCell, fmt, io, marker::PhantomData, ops::Deref, time::Instant};
   9 use tracing_core::{
  10     field,
  11     span::{Attributes, Id, Record},
  12     Event, Metadata, Subscriber,
  13 };
  14
  15 /// A [`Layer`] that logs formatted representations of `tracing` events.
  16 ///
  17 /// ## Examples
  18 ///
  19 /// Constructing a layer with the default configuration:
  20 ///
  21 /// ```rust
  22 /// use tracing_subscriber::{fmt, Registry};
  23 /// use tracing_subscriber::prelude::*;
  24 ///
  25 /// let subscriber = Registry::default()
  26 ///     .with(fmt::Layer::default());
  27 ///
  28 /// tracing::subscriber::set_global_default(subscriber).unwrap();
  29 /// ```
  30 ///
  31 /// Overriding the layer's behavior:
  32 ///
  33 /// ```rust
  34 /// use tracing_subscriber::{fmt, Registry};
  35 /// use tracing_subscriber::prelude::*;
  36 ///
  37 /// let fmt_layer = fmt::layer()
  38 ///    .with_target(false) // don't include event targets when logging
  39 ///    .with_level(false); // don't include event levels when logging
  40 ///
  41 /// let subscriber = Registry::default().with(fmt_layer);
  42 /// # tracing::subscriber::set_global_default(subscriber).unwrap();
  43 /// ```
  44 ///
  45 /// Setting a custom event formatter:
  46 ///
  47 /// ```rust
  48 /// use tracing_subscriber::fmt::{self, format, time};
  49 /// use tracing_subscriber::prelude::*;
  50 ///
  51 /// let fmt = format().with_timer(time::Uptime::default());
  52 /// let fmt_layer = fmt::layer()
  53 ///     .event_format(fmt)
  54 ///     .with_target(false);
  55 /// # let subscriber = fmt_layer.with_subscriber(tracing_subscriber::registry::Registry::default());
  56 /// # tracing::subscriber::set_global_default(subscriber).unwrap();
  57 /// ```
  58 ///
  59 /// [`Layer`]: ../layer/trait.Layer.html
  60 #[derive(Debug)]
  61 pub struct Layer<
  62     S,
  63     N = format::DefaultFields,
  64     E = format::Format<format::Full>,
  65     W = fn() -> io::Stdout,
  66 > {
  67     make_writer: W,
  68     fmt_fields: N,
  69     fmt_event: E,
  70     fmt_span: format::FmtSpanConfig,
  71     _inner: PhantomData<S>,
  72 }
  73
  74 /// A builder for [`Layer`](struct.Layer.html) that logs formatted representations of `tracing`
  75 /// events and spans.
  76 ///
  77 /// **Note**: As of `tracing-subscriber` 0.2.4, the separate builder type is now
  78 /// deprecated, as the `Layer` type itself supports all the builder's
  79 /// configuration methods. This is now an alias for `Layer`.
  80 #[deprecated(
  81     since = "0.2.4",
  82     note = "a separate layer builder type is not necessary, `Layer`s now support configuration"
  83 )]
  84 pub type LayerBuilder<
  85     S,
  86     N = format::DefaultFields,
  87     E = format::Format<format::Full>,
  88     W = fn() -> io::Stdout,
  89 > = Layer<S, N, E, W>;
  90
  91 impl<S> Layer<S> {
  92     /// Returns a new [`LayerBuilder`](type.LayerBuilder.html) for configuring a `Layer`.
  93     #[deprecated(
  94         since = "0.2.4",
  95         note = "a separate layer builder is not necessary, use `Layer::new`/`Layer::default` instead"
  96     )]
  97     #[allow(deprecated)]
  98     pub fn builder() -> LayerBuilder<S> {
  99         Layer::default()
 100     }
 101
 102     /// Returns a new [`Layer`](struct.Layer.html) with the default configuration.
 103     pub fn new() -> Self {
 104         Self::default()
 105     }
 106 }
 107
 108 // This needs to be a seperate impl block because they place different bounds on the type parameters.
 109 impl<S, N, E, W> Layer<S, N, E, W>
 110 where
 111     S: Subscriber + for<'a> LookupSpan<'a>,
 112     N: for<'writer> FormatFields<'writer> + 'static,
 113     W: MakeWriter + 'static,
 114 {
 115     /// Sets the [event formatter][`FormatEvent`] that the layer will use to
 116     /// format events.
 117     ///
 118     /// The event formatter may be any type implementing the [`FormatEvent`]
 119     /// trait, which is implemented for all functions taking a [`FmtContext`], a
 120     /// `&mut dyn Write`, and an [`Event`].
 121     ///
 122     /// # Examples
 123     ///
 124     /// Setting a type implementing [`FormatEvent`] as the formatter:
 125     /// ```rust
 126     /// use tracing_subscriber::fmt::{self, format};
 127     ///
 128     /// let layer = fmt::layer()
 129     ///     .event_format(format().compact());
 130     /// # // this is necessary for type inference.
 131     /// # use tracing_subscriber::Layer as _;
 132     /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
 133     /// ```
 134     /// [`FormatEvent`]: ./format/trait.FormatEvent.html
 135     /// [`FmtContext`]: ./struct.FmtContext.html
 136     /// [`Event`]: https://docs.rs/tracing/latest/tracing/struct.Event.html
 137     pub fn event_format<E2>(self, e: E2) -> Layer<S, N, E2, W>
 138     where
 139         E2: FormatEvent<S, N> + 'static,
 140     {
 141         Layer {
 142             fmt_fields: self.fmt_fields,
 143             fmt_event: e,
 144             fmt_span: self.fmt_span,
 145             make_writer: self.make_writer,
 146             _inner: self._inner,
 147         }
 148     }
 149 }
 150
 151 // This needs to be a seperate impl block because they place different bounds on the type parameters.
 152 impl<S, N, E, W> Layer<S, N, E, W> {
 153     /// Sets the [`MakeWriter`] that the [`Layer`] being built will use to write events.
 154     ///
 155     /// # Examples
 156     ///
 157     /// Using `stderr` rather than `stdout`:
 158     ///
 159     /// ```rust
 160     /// use std::io;
 161     /// use tracing_subscriber::fmt;
 162     ///
 163     /// let layer = fmt::layer()
 164     ///     .with_writer(io::stderr);
 165     /// # // this is necessary for type inference.
 166     /// # use tracing_subscriber::Layer as _;
 167     /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
 168     /// ```
 169     ///
 170     /// [`MakeWriter`]: ../fmt/trait.MakeWriter.html
 171     /// [`Layer`]: ../layer/trait.Layer.html
 172     pub fn with_writer<W2>(self, make_writer: W2) -> Layer<S, N, E, W2>
 173     where
 174         W2: MakeWriter + 'static,
 175     {
 176         Layer {
 177             fmt_fields: self.fmt_fields,
 178             fmt_event: self.fmt_event,
 179             fmt_span: self.fmt_span,
 180             make_writer,
 181             _inner: self._inner,
 182         }
 183     }
 184
 185     /// Configures the subscriber to support [`libtest`'s output capturing][capturing] when used in
 186     /// unit tests.
 187     ///
 188     /// See [`TestWriter`] for additional details.
 189     ///
 190     /// # Examples
 191     ///
 192     /// Using [`TestWriter`] to let `cargo test` capture test output:
 193     ///
 194     /// ```rust
 195     /// use std::io;
 196     /// use tracing_subscriber::fmt;
 197     ///
 198     /// let layer = fmt::layer()
 199     ///     .with_test_writer();
 200     /// # // this is necessary for type inference.
 201     /// # use tracing_subscriber::Layer as _;
 202     /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default());
 203     /// ```
 204     /// [capturing]:
 205     /// https://doc.rust-lang.org/book/ch11-02-running-tests.html#showing-function-output
 206     /// [`TestWriter`]: writer/struct.TestWriter.html
 207     pub fn with_test_writer(self) -> Layer<S, N, E, TestWriter> {
 208         Layer {
 209             fmt_fields: self.fmt_fields,
 210             fmt_event: self.fmt_event,
 211             fmt_span: self.fmt_span,
 212             make_writer: TestWriter::default(),
 213             _inner: self._inner,
 214         }
 215     }
 216 }
 217
 218 impl<S, N, L, T, W> Layer<S, N, format::Format<L, T>, W>
 219 where
 220     N: for<'writer> FormatFields<'writer> + 'static,
 221 {
 222     /// Use the given [`timer`] for span and event timestamps.
 223     ///
 224     /// See [`time`] for the provided timer implementations.
 225     ///
 226     /// Note that using the `chrono` feature flag enables the
 227     /// additional time formatters [`ChronoUtc`] and [`ChronoLocal`].
 228     ///
 229     /// [`time`]: ./time/index.html
 230     /// [`timer`]: ./time/trait.FormatTime.html
 231     /// [`ChronoUtc`]: ./time/struct.ChronoUtc.html
 232     /// [`ChronoLocal`]: ./time/struct.ChronoLocal.html
 233     pub fn with_timer<T2>(self, timer: T2) -> Layer<S, N, format::Format<L, T2>, W> {
 234         Layer {
 235             fmt_event: self.fmt_event.with_timer(timer),
 236             fmt_fields: self.fmt_fields,
 237             fmt_span: self.fmt_span,
 238             make_writer: self.make_writer,
 239             _inner: self._inner,
 240         }
 241     }
 242
 243     /// Do not emit timestamps with spans and event.
 244     pub fn without_time(self) -> Layer<S, N, format::Format<L, ()>, W> {
 245         Layer {
 246             fmt_event: self.fmt_event.without_time(),
 247             fmt_fields: self.fmt_fields,
 248             fmt_span: self.fmt_span.without_time(),
 249             make_writer: self.make_writer,
 250             _inner: self._inner,
 251         }
 252     }
 253
 254     /// Configures how synthesized events are emitted at points in the [span
 255     /// lifecycle][lifecycle].
 256     ///
 257     /// The following options are available:
 258     ///
 259     /// - `FmtSpan::NONE`: No events will be synthesized when spans are
 260     ///    created, entered, exited, or closed. Data from spans will still be
 261     ///    included as the context for formatted events. This is the default.
 262     /// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered
 263     ///    or exited.
 264     /// - `FmtSpan::CLOSE`: An event will be synthesized when a span closes. If
 265     ///    [timestamps are enabled][time] for this formatter, the generated
 266     ///    event will contain fields with the span's _busy time_ (the total
 267     ///    time for which it was entered) and _idle time_ (the total time that
 268     ///    the span existed but was not entered).
 269     /// - `FmtSpan::FULL`: Events will be synthesized whenever a span is
 270     ///    created, entered, exited, or closed. If timestamps are enabled, the
 271     ///    close event will contain the span's busy and idle time, as
 272     ///    described above.
 273     ///
 274     /// Note that the generated events will only be part of the log output by
 275     /// this formatter; they will not be recorded by other `Subscriber`s or by
 276     /// `Layer`s added to this subscriber.
 277     ///
 278     /// [lifecycle]: https://docs.rs/tracing/latest/tracing/span/index.html#the-span-lifecycle
 279     /// [time]: #method.without_time
 280     pub fn with_span_events(self, kind: FmtSpan) -> Self {
 281         Layer {
 282             fmt_event: self.fmt_event,
 283             fmt_fields: self.fmt_fields,
 284             fmt_span: self.fmt_span.with_kind(kind),
 285             make_writer: self.make_writer,
 286             _inner: self._inner,
 287         }
 288     }
 289
 290     /// Enable ANSI encoding for formatted events.
 291     #[cfg(feature = "ansi")]
 292     #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
 293     pub fn with_ansi(self, ansi: bool) -> Layer<S, N, format::Format<L, T>, W> {
 294         Layer {
 295             fmt_event: self.fmt_event.with_ansi(ansi),
 296             fmt_fields: self.fmt_fields,
 297             fmt_span: self.fmt_span,
 298             make_writer: self.make_writer,
 299             _inner: self._inner,
 300         }
 301     }
 302
 303     /// Sets whether or not an event's target is displayed.
 304     pub fn with_target(self, display_target: bool) -> Layer<S, N, format::Format<L, T>, W> {
 305         Layer {
 306             fmt_event: self.fmt_event.with_target(display_target),
 307             fmt_fields: self.fmt_fields,
 308             fmt_span: self.fmt_span,
 309             make_writer: self.make_writer,
 310             _inner: self._inner,
 311         }
 312     }
 313
 314     /// Sets whether or not an event's level is displayed.
 315     pub fn with_level(self, display_level: bool) -> Layer<S, N, format::Format<L, T>, W> {
 316         Layer {
 317             fmt_event: self.fmt_event.with_level(display_level),
 318             fmt_fields: self.fmt_fields,
 319             fmt_span: self.fmt_span,
 320             make_writer: self.make_writer,
 321             _inner: self._inner,
 322         }
 323     }
 324
 325     /// Sets whether or not the [thread ID] of the current thread is displayed
 326     /// when formatting events
 327     ///
 328     /// [thread ID]: https://doc.rust-lang.org/stable/std/thread/struct.ThreadId.html
 329     pub fn with_thread_ids(self, display_thread_ids: bool) -> Layer<S, N, format::Format<L, T>, W> {
 330         Layer {
 331             fmt_event: self.fmt_event.with_thread_ids(display_thread_ids),
 332             fmt_fields: self.fmt_fields,
 333             fmt_span: self.fmt_span,
 334             make_writer: self.make_writer,
 335             _inner: self._inner,
 336         }
 337     }
 338
 339     /// Sets whether or not the [name] of the current thread is displayed
 340     /// when formatting events
 341     ///
 342     /// [name]: https://doc.rust-lang.org/stable/std/thread/index.html#naming-threads
 343     pub fn with_thread_names(
 344         self,
 345         display_thread_names: bool,
 346     ) -> Layer<S, N, format::Format<L, T>, W> {
 347         Layer {
 348             fmt_event: self.fmt_event.with_thread_names(display_thread_names),
 349             fmt_fields: self.fmt_fields,
 350             fmt_span: self.fmt_span,
 351             make_writer: self.make_writer,
 352             _inner: self._inner,
 353         }
 354     }
 355
 356     /// Sets the layer being built to use a [less verbose formatter](../fmt/format/struct.Compact.html).
 357     pub fn compact(self) -> Layer<S, N, format::Format<format::Compact, T>, W>
 358     where
 359         N: for<'writer> FormatFields<'writer> + 'static,
 360     {
 361         Layer {
 362             fmt_event: self.fmt_event.compact(),
 363             fmt_fields: self.fmt_fields,
 364             fmt_span: self.fmt_span,
 365             make_writer: self.make_writer,
 366             _inner: self._inner,
 367         }
 368     }
 369
 370     /// Sets the layer being built to use a [JSON formatter](../fmt/format/struct.Json.html).
 371     ///
 372     /// The full format includes fields from all entered spans.
 373     ///
 374     /// # Example Output
 375     ///
 376     /// ```ignore,json
 377     /// {"timestamp":"Feb 20 11:28:15.096","level":"INFO","target":"mycrate","fields":{"message":"some message", "key": "value"}}
 378     /// ```
 379     ///
 380     /// # Options
 381     ///
 382     /// - [`Layer::flatten_event`] can be used to enable flattening event fields into the root
 383     /// object.
 384     ///
 385     /// [`Layer::flatten_event`]: #method.flatten_event
 386     #[cfg(feature = "json")]
 387     #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
 388     pub fn json(self) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
 389         Layer {
 390             fmt_event: self.fmt_event.json(),
 391             fmt_fields: format::JsonFields::new(),
 392             fmt_span: self.fmt_span,
 393             make_writer: self.make_writer,
 394             _inner: self._inner,
 395         }
 396     }
 397 }
 398
 399 #[cfg(feature = "json")]
 400 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
 401 impl<S, T, W> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
 402     /// Sets the JSON layer being built to flatten event metadata.
 403     ///
 404     /// See [`format::Json`](../fmt/format/struct.Json.html)
 405     pub fn flatten_event(
 406         self,
 407         flatten_event: bool,
 408     ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
 409         Layer {
 410             fmt_event: self.fmt_event.flatten_event(flatten_event),
 411             fmt_fields: format::JsonFields::new(),
 412             fmt_span: self.fmt_span,
 413             make_writer: self.make_writer,
 414             _inner: self._inner,
 415         }
 416     }
 417
 418     /// Sets whether or not the formatter will include the current span in
 419     /// formatted events.
 420     ///
 421     /// See [`format::Json`](../fmt/format/struct.Json.html)
 422     pub fn with_current_span(
 423         self,
 424         display_current_span: bool,
 425     ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
 426         Layer {
 427             fmt_event: self.fmt_event.with_current_span(display_current_span),
 428             fmt_fields: format::JsonFields::new(),
 429             fmt_span: self.fmt_span,
 430             make_writer: self.make_writer,
 431             _inner: self._inner,
 432         }
 433     }
 434
 435     /// Sets whether or not the formatter will include a list (from root to leaf)
 436     /// of all currently entered spans in formatted events.
 437     ///
 438     /// See [`format::Json`](../fmt/format/struct.Json.html)
 439     pub fn with_span_list(
 440         self,
 441         display_span_list: bool,
 442     ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
 443         Layer {
 444             fmt_event: self.fmt_event.with_span_list(display_span_list),
 445             fmt_fields: format::JsonFields::new(),
 446             fmt_span: self.fmt_span,
 447             make_writer: self.make_writer,
 448             _inner: self._inner,
 449         }
 450     }
 451 }
 452
 453 impl<S, N, E, W> Layer<S, N, E, W> {
 454     /// Sets the field formatter that the layer being built will use to record
 455     /// fields.
 456     pub fn fmt_fields<N2>(self, fmt_fields: N2) -> Layer<S, N2, E, W>
 457     where
 458         N2: for<'writer> FormatFields<'writer> + 'static,
 459     {
 460         Layer {
 461             fmt_event: self.fmt_event,
 462             fmt_fields,
 463             fmt_span: self.fmt_span,
 464             make_writer: self.make_writer,
 465             _inner: self._inner,
 466         }
 467     }
 468 }
 469
 470 #[allow(deprecated)]
 471 impl<S, N, E, W> LayerBuilder<S, N, E, W>
 472 where
 473     S: Subscriber + for<'a> LookupSpan<'a>,
 474     N: for<'writer> FormatFields<'writer> + 'static,
 475     E: FormatEvent<S, N> + 'static,
 476     W: MakeWriter + 'static,
 477 {
 478     /// Builds a [`Layer`] with the provided configuration.
 479     ///
 480     /// [`Layer`]: struct.Layer.html
 481     #[deprecated(
 482         since = "0.2.4",
 483         note = "`LayerBuilder` is no longer a separate type; this method is not necessary"
 484     )]
 485     pub fn finish(self) -> Layer<S, N, E, W> {
 486         self
 487     }
 488 }
 489
 490 impl<S> Default for Layer<S> {
 491     fn default() -> Self {
 492         Layer {
 493             fmt_fields: format::DefaultFields::default(),
 494             fmt_event: format::Format::default(),
 495             fmt_span: format::FmtSpanConfig::default(),
 496             make_writer: io::stdout,
 497             _inner: PhantomData,
 498         }
 499     }
 500 }
 501
 502 impl<S, N, E, W> Layer<S, N, E, W>
 503 where
 504     S: Subscriber + for<'a> LookupSpan<'a>,
 505     N: for<'writer> FormatFields<'writer> + 'static,
 506     E: FormatEvent<S, N> + 'static,
 507     W: MakeWriter + 'static,
 508 {
 509     #[inline]
 510     fn make_ctx<'a>(&'a self, ctx: Context<'a, S>) -> FmtContext<'a, S, N> {
 511         FmtContext {
 512             ctx,
 513             fmt_fields: &self.fmt_fields,
 514         }
 515     }
 516 }
 517
 518 /// A formatted representation of a span's fields stored in its [extensions].
 519 ///
 520 /// Because `FormattedFields` is generic over the type of the formatter that
 521 /// produced it, multiple versions of a span's formatted fields can be stored in
 522 /// the [`Extensions`][extensions] type-map. This means that when multiple
 523 /// formatters are in use, each can store its own formatted representation
 524 /// without conflicting.
 525 ///
 526 /// [extensions]: ../registry/struct.Extensions.html
 527 #[derive(Default)]
 528 pub struct FormattedFields<E> {
 529     _format_event: PhantomData<fn(E)>,
 530     /// The formatted fields of a span.
 531     pub fields: String,
 532 }
 533
 534 impl<E> FormattedFields<E> {
 535     /// Returns a new `FormattedFields`.
 536     pub fn new(fields: String) -> Self {
 537         Self {
 538             fields,
 539             _format_event: PhantomData,
 540         }
 541     }
 542 }
 543
 544 impl<E> fmt::Debug for FormattedFields<E> {
 545     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
 546         f.debug_struct("FormattedFields")
 547             .field("fields", &self.fields)
 548             .finish()
 549     }
 550 }
 551
 552 impl<E> fmt::Display for FormattedFields<E> {
 553     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
 554         write!(f, "{}", self.fields)
 555     }
 556 }
 557
 558 impl<E> Deref for FormattedFields<E> {
 559     type Target = String;
 560     fn deref(&self) -> &Self::Target {
 561         &self.fields
 562     }
 563 }
 564
 565 // === impl FmtLayer ===
 566
 567 macro_rules! with_event_from_span {
 568     ($id:ident, $span:ident, $($field:literal = $value:expr),*, |$event:ident| $code:block) => {
 569         let meta = $span.metadata();
 570         let cs = meta.callsite();
 571         let fs = field::FieldSet::new(&[$($field),*], cs);
 572         #[allow(unused)]
 573         let mut iter = fs.iter();
 574         let v = [$(
 575             (&iter.next().unwrap(), Some(&$value as &dyn field::Value)),
 576         )*];
 577         let vs = fs.value_set(&v);
 578         let $event = Event::new_child_of($id, meta, &vs);
 579         $code
 580     };
 581 }
 582
 583 impl<S, N, E, W> layer::Layer<S> for Layer<S, N, E, W>
 584 where
 585     S: Subscriber + for<'a> LookupSpan<'a>,
 586     N: for<'writer> FormatFields<'writer> + 'static,
 587     E: FormatEvent<S, N> + 'static,
 588     W: MakeWriter + 'static,
 589 {
 590     fn new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
 591         let span = ctx.span(id).expect("Span not found, this is a bug");
 592         let mut extensions = span.extensions_mut();
 593
 594         if extensions.get_mut::<FormattedFields<N>>().is_none() {
 595             let mut buf = String::new();
 596             if self.fmt_fields.format_fields(&mut buf, attrs).is_ok() {
 597                 let fmt_fields = FormattedFields {
 598                     fields: buf,
 599                     _format_event: PhantomData::<fn(N)>,
 600                 };
 601                 extensions.insert(fmt_fields);
 602             }
 603         }
 604
 605         if self.fmt_span.fmt_timing
 606             && self.fmt_span.trace_close()
 607             && extensions.get_mut::<Timings>().is_none()
 608         {
 609             extensions.insert(Timings::new());
 610         }
 611
 612         if self.fmt_span.trace_new() {
 613             with_event_from_span!(id, span, "message" = "new", |event| {
 614                 drop(extensions);
 615                 drop(span);
 616                 self.on_event(&event, ctx);
 617             });
 618         }
 619     }
 620
 621     fn on_record(&self, id: &Id, values: &Record<'_>, ctx: Context<'_, S>) {
 622         let span = ctx.span(id).expect("Span not found, this is a bug");
 623         let mut extensions = span.extensions_mut();
 624         if let Some(FormattedFields { ref mut fields, .. }) =
 625             extensions.get_mut::<FormattedFields<N>>()
 626         {
 627             let _ = self.fmt_fields.add_fields(fields, values);
 628         } else {
 629             let mut buf = String::new();
 630             if self.fmt_fields.format_fields(&mut buf, values).is_ok() {
 631                 let fmt_fields = FormattedFields {
 632                     fields: buf,
 633                     _format_event: PhantomData::<fn(N)>,
 634                 };
 635                 extensions.insert(fmt_fields);
 636             }
 637         }
 638     }
 639
 640     fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
 641         if self.fmt_span.trace_active() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
 642             let span = ctx.span(id).expect("Span not found, this is a bug");
 643             let mut extensions = span.extensions_mut();
 644             if let Some(timings) = extensions.get_mut::<Timings>() {
 645                 let now = Instant::now();
 646                 timings.idle += (now - timings.last).as_nanos() as u64;
 647                 timings.last = now;
 648             }
 649
 650             if self.fmt_span.trace_active() {
 651                 with_event_from_span!(id, span, "message" = "enter", |event| {
 652                     drop(extensions);
 653                     drop(span);
 654                     self.on_event(&event, ctx);
 655                 });
 656             }
 657         }
 658     }
 659
 660     fn on_exit(&self, id: &Id, ctx: Context<'_, S>) {
 661         if self.fmt_span.trace_active() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
 662             let span = ctx.span(id).expect("Span not found, this is a bug");
 663             let mut extensions = span.extensions_mut();
 664             if let Some(timings) = extensions.get_mut::<Timings>() {
 665                 let now = Instant::now();
 666                 timings.busy += (now - timings.last).as_nanos() as u64;
 667                 timings.last = now;
 668             }
 669
 670             if self.fmt_span.trace_active() {
 671                 with_event_from_span!(id, span, "message" = "exit", |event| {
 672                     drop(extensions);
 673                     drop(span);
 674                     self.on_event(&event, ctx);
 675                 });
 676             }
 677         }
 678     }
 679
 680     fn on_close(&self, id: Id, ctx: Context<'_, S>) {
 681         if self.fmt_span.trace_close() {
 682             let span = ctx.span(&id).expect("Span not found, this is a bug");
 683             let extensions = span.extensions();
 684             if let Some(timing) = extensions.get::<Timings>() {
 685                 let Timings {
 686                     busy,
 687                     mut idle,
 688                     last,
 689                 } = *timing;
 690                 idle += (Instant::now() - last).as_nanos() as u64;
 691
 692                 let t_idle = field::display(TimingDisplay(idle));
 693                 let t_busy = field::display(TimingDisplay(busy));
 694
 695                 with_event_from_span!(
 696                     id,
 697                     span,
 698                     "message" = "close",
 699                     "time.busy" = t_busy,
 700                     "time.idle" = t_idle,
 701                     |event| {
 702                         drop(extensions);
 703                         drop(span);
 704                         self.on_event(&event, ctx);
 705                     }
 706                 );
 707             } else {
 708                 with_event_from_span!(id, span, "message" = "close", |event| {
 709                     drop(extensions);
 710                     drop(span);
 711                     self.on_event(&event, ctx);
 712                 });
 713             }
 714         }
 715     }
 716
 717     fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
 718         thread_local! {
 719             static BUF: RefCell<String> = RefCell::new(String::new());
 720         }
 721
 722         BUF.with(|buf| {
 723             let borrow = buf.try_borrow_mut();
 724             let mut a;
 725             let mut b;
 726             let mut buf = match borrow {
 727                 Ok(buf) => {
 728                     a = buf;
 729                     &mut *a
 730                 }
 731                 _ => {
 732                     b = String::new();
 733                     &mut b
 734                 }
 735             };
 736
 737             let ctx = self.make_ctx(ctx);
 738             if self.fmt_event.format_event(&ctx, &mut buf, event).is_ok() {
 739                 let mut writer = self.make_writer.make_writer();
 740                 let _ = io::Write::write_all(&mut writer, buf.as_bytes());
 741             }
 742
 743             buf.clear();
 744         });
 745     }
 746
 747     unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> {
 748         // This `downcast_raw` impl allows downcasting a `fmt` layer to any of
 749         // its components (event formatter, field formatter, and `MakeWriter`)
 750         // as well as to the layer's type itself. The potential use-cases for
 751         // this *may* be somewhat niche, though...
 752         match () {
 753             _ if id == TypeId::of::<Self>() => Some(self as *const Self as *const ()),
 754             _ if id == TypeId::of::<E>() => Some(&self.fmt_event as *const E as *const ()),
 755             _ if id == TypeId::of::<N>() => Some(&self.fmt_fields as *const N as *const ()),
 756             _ if id == TypeId::of::<W>() => Some(&self.make_writer as *const W as *const ()),
 757             _ => None,
 758         }
 759     }
 760 }
 761
 762 /// Provides the current span context to a formatter.
 763 pub struct FmtContext<'a, S, N> {
 764     pub(crate) ctx: Context<'a, S>,
 765     pub(crate) fmt_fields: &'a N,
 766 }
 767
 768 impl<'a, S, N> fmt::Debug for FmtContext<'a, S, N> {
 769     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
 770         f.debug_struct("FmtContext").finish()
 771     }
 772 }
 773
 774 impl<'a, S, N> FormatFields<'a> for FmtContext<'a, S, N>
 775 where
 776     S: Subscriber + for<'lookup> LookupSpan<'lookup>,
 777     N: for<'writer> FormatFields<'writer> + 'static,
 778 {
 779     fn format_fields<R: RecordFields>(
 780         &self,
 781         writer: &'a mut dyn fmt::Write,
 782         fields: R,
 783     ) -> fmt::Result {
 784         self.fmt_fields.format_fields(writer, fields)
 785     }
 786 }
 787
 788 impl<'a, S, N> FmtContext<'a, S, N>
 789 where
 790     S: Subscriber + for<'lookup> LookupSpan<'lookup>,
 791     N: for<'writer> FormatFields<'writer> + 'static,
 792 {
 793     /// Visits every span in the current context with a closure.
 794     ///
 795     /// The provided closure will be called first with the current span,
 796     /// and then with that span's parent, and then that span's parent,
 797     /// and so on until a root span is reached.
 798     pub fn visit_spans<E, F>(&self, mut f: F) -> Result<(), E>
 799     where
 800         F: FnMut(&SpanRef<'_, S>) -> Result<(), E>,
 801     {
 802         // visit all the current spans
 803         for span in self.ctx.scope() {
 804             f(&span)?;
 805         }
 806         Ok(())
 807     }
 808
 809     /// Returns metadata for the span with the given `id`, if it exists.
 810     ///
 811     /// If this returns `None`, then no span exists for that ID (either it has
 812     /// closed or the ID is invalid).
 813     #[inline]
 814     pub fn metadata(&self, id: &Id) -> Option<&'static Metadata<'static>>
 815     where
 816         S: for<'lookup> LookupSpan<'lookup>,
 817     {
 818         self.ctx.metadata(id)
 819     }
 820
 821     /// Returns [stored data] for the span with the given `id`, if it exists.
 822     ///
 823     /// If this returns `None`, then no span exists for that ID (either it has
 824     /// closed or the ID is invalid).
 825     ///
 826     /// [stored data]: ../registry/struct.SpanRef.html
 827     #[inline]
 828     pub fn span(&self, id: &Id) -> Option<SpanRef<'_, S>>
 829     where
 830         S: for<'lookup> LookupSpan<'lookup>,
 831     {
 832         self.ctx.span(id)
 833     }
 834
 835     /// Returns `true` if an active span exists for the given `Id`.
 836     #[inline]
 837     pub fn exists(&self, id: &Id) -> bool
 838     where
 839         S: for<'lookup> LookupSpan<'lookup>,
 840     {
 841         self.ctx.exists(id)
 842     }
 843
 844     /// Returns [stored data] for the span that the wrapped subscriber considers
 845     /// to be the current.
 846     ///
 847     /// If this returns `None`, then we are not currently within a span.
 848     ///
 849     /// [stored data]: ../registry/struct.SpanRef.html
 850     #[inline]
 851     pub fn lookup_current(&self) -> Option<SpanRef<'_, S>>
 852     where
 853         S: for<'lookup> LookupSpan<'lookup>,
 854     {
 855         self.ctx.lookup_current()
 856     }
 857
 858     /// Returns an iterator over the [stored data] for all the spans in the
 859     /// current context, starting the root of the trace tree and ending with
 860     /// the current span.
 861     ///
 862     /// [stored data]: ../registry/struct.SpanRef.html
 863     pub fn scope(&self) -> Scope<'_, S>
 864     where
 865         S: for<'lookup> LookupSpan<'lookup>,
 866     {
 867         self.ctx.scope()
 868     }
 869 }
 870
 871 struct Timings {
 872     idle: u64,
 873     busy: u64,
 874     last: Instant,
 875 }
 876
 877 impl Timings {
 878     fn new() -> Self {
 879         Self {
 880             idle: 0,
 881             busy: 0,
 882             last: Instant::now(),
 883         }
 884     }
 885 }
 886
 887 #[cfg(test)]
 888 mod test {
 889     use crate::fmt::{
 890         self,
 891         format::{self, test::MockTime, Format},
 892         layer::Layer as _,
 893         test::MockWriter,
 894         time,
 895     };
 896     use crate::Registry;
 897     use format::FmtSpan;
 898     use lazy_static::lazy_static;
 899     use regex::Regex;
 900     use std::sync::Mutex;
 901     use tracing::subscriber::with_default;
 902     use tracing_core::dispatcher::Dispatch;
 903
 904     #[test]
 905     fn impls() {
 906         let f = Format::default().with_timer(time::Uptime::default());
 907         let fmt = fmt::Layer::default().event_format(f);
 908         let subscriber = fmt.with_subscriber(Registry::default());
 909         let _dispatch = Dispatch::new(subscriber);
 910
 911         let f = format::Format::default();
 912         let fmt = fmt::Layer::default().event_format(f);
 913         let subscriber = fmt.with_subscriber(Registry::default());
 914         let _dispatch = Dispatch::new(subscriber);
 915
 916         let f = format::Format::default().compact();
 917         let fmt = fmt::Layer::default().event_format(f);
 918         let subscriber = fmt.with_subscriber(Registry::default());
 919         let _dispatch = Dispatch::new(subscriber);
 920     }
 921
 922     #[test]
 923     fn fmt_layer_downcasts() {
 924         let f = format::Format::default();
 925         let fmt = fmt::Layer::default().event_format(f);
 926         let subscriber = fmt.with_subscriber(Registry::default());
 927
 928         let dispatch = Dispatch::new(subscriber);
 929         assert!(dispatch.downcast_ref::<fmt::Layer<Registry>>().is_some());
 930     }
 931
 932     #[test]
 933     fn fmt_layer_downcasts_to_parts() {
 934         let f = format::Format::default();
 935         let fmt = fmt::Layer::default().event_format(f);
 936         let subscriber = fmt.with_subscriber(Registry::default());
 937         let dispatch = Dispatch::new(subscriber);
 938         assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some());
 939         assert!(dispatch.downcast_ref::<format::Format>().is_some())
 940     }
 941
 942     #[test]
 943     fn is_lookup_span() {
 944         fn assert_lookup_span<T: for<'a> crate::registry::LookupSpan<'a>>(_: T) {}
 945         let fmt = fmt::Layer::default();
 946         let subscriber = fmt.with_subscriber(Registry::default());
 947         assert_lookup_span(subscriber)
 948     }
 949
 950     fn sanitize_timings(s: String) -> String {
 951         let re = Regex::new("time\\.(idle|busy)=([0-9.]+)[mµn]s").unwrap();
 952         re.replace_all(s.as_str(), "timing").to_string()
 953     }
 954
 955     #[test]
 956     fn synthesize_span_none() {
 957         lazy_static! {
 958             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
 959         }
 960
 961         let make_writer = || MockWriter::new(&BUF);
 962         let subscriber = crate::fmt::Subscriber::builder()
 963             .with_writer(make_writer)
 964             .with_level(false)
 965             .with_ansi(false)
 966             .with_timer(MockTime)
 967             // check that FmtSpan::NONE is the default
 968             .finish();
 969
 970         with_default(subscriber, || {
 971             let span1 = tracing::info_span!("span1", x = 42);
 972             let _e = span1.enter();
 973         });
 974         let actual = sanitize_timings(String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap());
 975         assert_eq!("", actual.as_str());
 976     }
 977
 978     #[test]
 979     fn synthesize_span_active() {
 980         lazy_static! {
 981             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
 982         }
 983
 984         let make_writer = || MockWriter::new(&BUF);
 985         let subscriber = crate::fmt::Subscriber::builder()
 986             .with_writer(make_writer)
 987             .with_level(false)
 988             .with_ansi(false)
 989             .with_timer(MockTime)
 990             .with_span_events(FmtSpan::ACTIVE)
 991             .finish();
 992
 993         with_default(subscriber, || {
 994             let span1 = tracing::info_span!("span1", x = 42);
 995             let _e = span1.enter();
 996         });
 997         let actual = sanitize_timings(String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap());
 998         assert_eq!(
 999             "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1000              fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n",
1001             actual.as_str()
1002         );
1003     }
1004
1005     #[test]
1006     fn synthesize_span_close() {
1007         lazy_static! {
1008             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1009         }
1010
1011         let make_writer = || MockWriter::new(&BUF);
1012         let subscriber = crate::fmt::Subscriber::builder()
1013             .with_writer(make_writer)
1014             .with_level(false)
1015             .with_ansi(false)
1016             .with_timer(MockTime)
1017             .with_span_events(FmtSpan::CLOSE)
1018             .finish();
1019
1020         with_default(subscriber, || {
1021             let span1 = tracing::info_span!("span1", x = 42);
1022             let _e = span1.enter();
1023         });
1024         let actual = sanitize_timings(String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap());
1025         assert_eq!(
1026             "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n",
1027             actual.as_str()
1028         );
1029     }
1030
1031     #[test]
1032     fn synthesize_span_close_no_timing() {
1033         lazy_static! {
1034             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1035         }
1036
1037         let make_writer = || MockWriter::new(&BUF);
1038         let subscriber = crate::fmt::Subscriber::builder()
1039             .with_writer(make_writer)
1040             .with_level(false)
1041             .with_ansi(false)
1042             .with_timer(MockTime)
1043             .without_time()
1044             .with_span_events(FmtSpan::CLOSE)
1045             .finish();
1046
1047         with_default(subscriber, || {
1048             let span1 = tracing::info_span!("span1", x = 42);
1049             let _e = span1.enter();
1050         });
1051         let actual = sanitize_timings(String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap());
1052         assert_eq!(
1053             " span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close\n",
1054             actual.as_str()
1055         );
1056     }
1057
1058     #[test]
1059     fn synthesize_span_full() {
1060         lazy_static! {
1061             static ref BUF: Mutex<Vec<u8>> = Mutex::new(vec![]);
1062         }
1063
1064         let make_writer = || MockWriter::new(&BUF);
1065         let subscriber = crate::fmt::Subscriber::builder()
1066             .with_writer(make_writer)
1067             .with_level(false)
1068             .with_ansi(false)
1069             .with_timer(MockTime)
1070             .with_span_events(FmtSpan::FULL)
1071             .finish();
1072
1073         with_default(subscriber, || {
1074             let span1 = tracing::info_span!("span1", x = 42);
1075             let _e = span1.enter();
1076         });
1077         let actual = sanitize_timings(String::from_utf8(BUF.try_lock().unwrap().to_vec()).unwrap());
1078         assert_eq!(
1079             "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: new\n\
1080              fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1081              fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\
1082              fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n",
1083             actual.as_str()
1084         );
1085     }
1086 }