1 use crate::{ 2 field::RecordFields, 3 fmt::{format, FormatEvent, FormatFields, MakeWriter, TestWriter}, 4 layer::{self, Context}, 5 registry::{self, LookupSpan, SpanRef}, 6 }; 7 use format::{FmtSpan, TimingDisplay}; 8 use std::{ 9 any::TypeId, cell::RefCell, env, fmt, io, marker::PhantomData, ops::Deref, time::Instant, 10 }; 11 use tracing_core::{ 12 field, 13 span::{Attributes, Current, Id, Record}, 14 Event, Metadata, Subscriber, 15 }; 16 17 /// A [`Layer`] that logs formatted representations of `tracing` events. 18 /// 19 /// ## Examples 20 /// 21 /// Constructing a layer with the default configuration: 22 /// 23 /// ```rust 24 /// use tracing_subscriber::{fmt, Registry}; 25 /// use tracing_subscriber::prelude::*; 26 /// 27 /// let subscriber = Registry::default() 28 /// .with(fmt::Layer::default()); 29 /// 30 /// tracing::subscriber::set_global_default(subscriber).unwrap(); 31 /// ``` 32 /// 33 /// Overriding the layer's behavior: 34 /// 35 /// ```rust 36 /// use tracing_subscriber::{fmt, Registry}; 37 /// use tracing_subscriber::prelude::*; 38 /// 39 /// let fmt_layer = fmt::layer() 40 /// .with_target(false) // don't include event targets when logging 41 /// .with_level(false); // don't include event levels when logging 42 /// 43 /// let subscriber = Registry::default().with(fmt_layer); 44 /// # tracing::subscriber::set_global_default(subscriber).unwrap(); 45 /// ``` 46 /// 47 /// Setting a custom event formatter: 48 /// 49 /// ```rust 50 /// use tracing_subscriber::fmt::{self, format, time}; 51 /// use tracing_subscriber::prelude::*; 52 /// 53 /// let fmt = format().with_timer(time::Uptime::default()); 54 /// let fmt_layer = fmt::layer() 55 /// .event_format(fmt) 56 /// .with_target(false); 57 /// # let subscriber = fmt_layer.with_subscriber(tracing_subscriber::registry::Registry::default()); 58 /// # tracing::subscriber::set_global_default(subscriber).unwrap(); 59 /// ``` 60 /// 61 /// [`Layer`]: super::layer::Layer 62 #[cfg_attr(docsrs, doc(cfg(all(feature = "fmt", feature = "std"))))] 63 #[derive(Debug)] 64 pub struct Layer< 65 S, 66 N = format::DefaultFields, 67 E = format::Format<format::Full>, 68 W = fn() -> io::Stdout, 69 > { 70 make_writer: W, 71 fmt_fields: N, 72 fmt_event: E, 73 fmt_span: format::FmtSpanConfig, 74 is_ansi: bool, 75 log_internal_errors: bool, 76 _inner: PhantomData<fn(S)>, 77 } 78 79 impl<S> Layer<S> { 80 /// Returns a new [`Layer`][self::Layer] with the default configuration. new() -> Self81 pub fn new() -> Self { 82 Self::default() 83 } 84 } 85 86 // This needs to be a seperate impl block because they place different bounds on the type parameters. 87 impl<S, N, E, W> Layer<S, N, E, W> 88 where 89 S: Subscriber + for<'a> LookupSpan<'a>, 90 N: for<'writer> FormatFields<'writer> + 'static, 91 W: for<'writer> MakeWriter<'writer> + 'static, 92 { 93 /// Sets the [event formatter][`FormatEvent`] that the layer being built will 94 /// use to format events. 95 /// 96 /// The event formatter may be any type implementing the [`FormatEvent`] 97 /// trait, which is implemented for all functions taking a [`FmtContext`], a 98 /// [`Writer`], and an [`Event`]. 99 /// 100 /// # Examples 101 /// 102 /// Setting a type implementing [`FormatEvent`] as the formatter: 103 /// ```rust 104 /// use tracing_subscriber::fmt::{self, format}; 105 /// 106 /// let layer = fmt::layer() 107 /// .event_format(format().compact()); 108 /// # // this is necessary for type inference. 109 /// # use tracing_subscriber::Layer as _; 110 /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default()); 111 /// ``` 112 /// [`FormatEvent`]: format::FormatEvent 113 /// [`Event`]: tracing::Event 114 /// [`Writer`]: format::Writer event_format<E2>(self, e: E2) -> Layer<S, N, E2, W> where E2: FormatEvent<S, N> + 'static,115 pub fn event_format<E2>(self, e: E2) -> Layer<S, N, E2, W> 116 where 117 E2: FormatEvent<S, N> + 'static, 118 { 119 Layer { 120 fmt_fields: self.fmt_fields, 121 fmt_event: e, 122 fmt_span: self.fmt_span, 123 make_writer: self.make_writer, 124 is_ansi: self.is_ansi, 125 log_internal_errors: self.log_internal_errors, 126 _inner: self._inner, 127 } 128 } 129 130 /// Updates the event formatter by applying a function to the existing event formatter. 131 /// 132 /// This sets the event formatter that the layer being built will use to record fields. 133 /// 134 /// # Examples 135 /// 136 /// Updating an event formatter: 137 /// 138 /// ```rust 139 /// let layer = tracing_subscriber::fmt::layer() 140 /// .map_event_format(|e| e.compact()); 141 /// # // this is necessary for type inference. 142 /// # use tracing_subscriber::Layer as _; 143 /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default()); 144 /// ``` map_event_format<E2>(self, f: impl FnOnce(E) -> E2) -> Layer<S, N, E2, W> where E2: FormatEvent<S, N> + 'static,145 pub fn map_event_format<E2>(self, f: impl FnOnce(E) -> E2) -> Layer<S, N, E2, W> 146 where 147 E2: FormatEvent<S, N> + 'static, 148 { 149 Layer { 150 fmt_fields: self.fmt_fields, 151 fmt_event: f(self.fmt_event), 152 fmt_span: self.fmt_span, 153 make_writer: self.make_writer, 154 is_ansi: self.is_ansi, 155 log_internal_errors: self.log_internal_errors, 156 _inner: self._inner, 157 } 158 } 159 } 160 161 // This needs to be a seperate impl block because they place different bounds on the type parameters. 162 impl<S, N, E, W> Layer<S, N, E, W> { 163 /// Sets the [`MakeWriter`] that the layer being built will use to write events. 164 /// 165 /// # Examples 166 /// 167 /// Using `stderr` rather than `stdout`: 168 /// 169 /// ```rust 170 /// use std::io; 171 /// use tracing_subscriber::fmt; 172 /// 173 /// let layer = fmt::layer() 174 /// .with_writer(io::stderr); 175 /// # // this is necessary for type inference. 176 /// # use tracing_subscriber::Layer as _; 177 /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default()); 178 /// ``` with_writer<W2>(self, make_writer: W2) -> Layer<S, N, E, W2> where W2: for<'writer> MakeWriter<'writer> + 'static,179 pub fn with_writer<W2>(self, make_writer: W2) -> Layer<S, N, E, W2> 180 where 181 W2: for<'writer> MakeWriter<'writer> + 'static, 182 { 183 Layer { 184 fmt_fields: self.fmt_fields, 185 fmt_event: self.fmt_event, 186 fmt_span: self.fmt_span, 187 is_ansi: self.is_ansi, 188 log_internal_errors: self.log_internal_errors, 189 make_writer, 190 _inner: self._inner, 191 } 192 } 193 194 /// Borrows the [writer] for this [`Layer`]. 195 /// 196 /// [writer]: MakeWriter writer(&self) -> &W197 pub fn writer(&self) -> &W { 198 &self.make_writer 199 } 200 201 /// Mutably borrows the [writer] for this [`Layer`]. 202 /// 203 /// This method is primarily expected to be used with the 204 /// [`reload::Handle::modify`](crate::reload::Handle::modify) method. 205 /// 206 /// # Examples 207 /// 208 /// ``` 209 /// # use tracing::info; 210 /// # use tracing_subscriber::{fmt,reload,Registry,prelude::*}; 211 /// # fn non_blocking<T: std::io::Write>(writer: T) -> (fn() -> std::io::Stdout) { 212 /// # std::io::stdout 213 /// # } 214 /// # fn main() { 215 /// let layer = fmt::layer().with_writer(non_blocking(std::io::stderr())); 216 /// let (layer, reload_handle) = reload::Layer::new(layer); 217 /// # 218 /// # // specifying the Registry type is required 219 /// # let _: &reload::Handle<fmt::Layer<Registry, _, _, _>, Registry> = &reload_handle; 220 /// # 221 /// info!("This will be logged to stderr"); 222 /// reload_handle.modify(|layer| *layer.writer_mut() = non_blocking(std::io::stdout())); 223 /// info!("This will be logged to stdout"); 224 /// # } 225 /// ``` 226 /// 227 /// [writer]: MakeWriter writer_mut(&mut self) -> &mut W228 pub fn writer_mut(&mut self) -> &mut W { 229 &mut self.make_writer 230 } 231 232 /// Sets whether this layer should use ANSI terminal formatting 233 /// escape codes (such as colors). 234 /// 235 /// This method is primarily expected to be used with the 236 /// [`reload::Handle::modify`](crate::reload::Handle::modify) method when changing 237 /// the writer. 238 #[cfg(feature = "ansi")] 239 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))] set_ansi(&mut self, ansi: bool)240 pub fn set_ansi(&mut self, ansi: bool) { 241 self.is_ansi = ansi; 242 } 243 244 /// Modifies how synthesized events are emitted at points in the [span 245 /// lifecycle][lifecycle]. 246 /// 247 /// See [`Self::with_span_events`] for documentation on the [`FmtSpan`] 248 /// 249 /// This method is primarily expected to be used with the 250 /// [`reload::Handle::modify`](crate::reload::Handle::modify) method 251 /// 252 /// Note that using this method modifies the span configuration instantly and does not take into 253 /// account any current spans. If the previous configuration was set to capture 254 /// `FmtSpan::ALL`, for example, using this method to change to `FmtSpan::NONE` will cause an 255 /// exit event for currently entered events not to be formatted 256 /// 257 /// [lifecycle]: mod@tracing::span#the-span-lifecycle set_span_events(&mut self, kind: FmtSpan)258 pub fn set_span_events(&mut self, kind: FmtSpan) { 259 self.fmt_span = format::FmtSpanConfig { 260 kind, 261 fmt_timing: self.fmt_span.fmt_timing, 262 } 263 } 264 265 /// Configures the layer to support [`libtest`'s output capturing][capturing] when used in 266 /// unit tests. 267 /// 268 /// See [`TestWriter`] for additional details. 269 /// 270 /// # Examples 271 /// 272 /// Using [`TestWriter`] to let `cargo test` capture test output: 273 /// 274 /// ```rust 275 /// use std::io; 276 /// use tracing_subscriber::fmt; 277 /// 278 /// let layer = fmt::layer() 279 /// .with_test_writer(); 280 /// # // this is necessary for type inference. 281 /// # use tracing_subscriber::Layer as _; 282 /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default()); 283 /// ``` 284 /// [capturing]: 285 /// https://doc.rust-lang.org/book/ch11-02-running-tests.html#showing-function-output 286 /// [`TestWriter`]: super::writer::TestWriter with_test_writer(self) -> Layer<S, N, E, TestWriter>287 pub fn with_test_writer(self) -> Layer<S, N, E, TestWriter> { 288 Layer { 289 fmt_fields: self.fmt_fields, 290 fmt_event: self.fmt_event, 291 fmt_span: self.fmt_span, 292 is_ansi: self.is_ansi, 293 log_internal_errors: self.log_internal_errors, 294 make_writer: TestWriter::default(), 295 _inner: self._inner, 296 } 297 } 298 299 /// Sets whether or not the formatter emits ANSI terminal escape codes 300 /// for colors and other text formatting. 301 /// 302 /// When the "ansi" crate feature flag is enabled, ANSI colors are enabled 303 /// by default unless the [`NO_COLOR`] environment variable is set to 304 /// a non-empty value. If the [`NO_COLOR`] environment variable is set to 305 /// any non-empty value, then ANSI colors will be suppressed by default. 306 /// The [`with_ansi`] and [`set_ansi`] methods can be used to forcibly 307 /// enable ANSI colors, overriding any [`NO_COLOR`] environment variable. 308 /// 309 /// [`NO_COLOR`]: https://no-color.org/ 310 /// 311 /// Enabling ANSI escapes (calling `with_ansi(true)`) requires the "ansi" 312 /// crate feature flag. Calling `with_ansi(true)` without the "ansi" 313 /// feature flag enabled will panic if debug assertions are enabled, or 314 /// print a warning otherwise. 315 /// 316 /// This method itself is still available without the feature flag. This 317 /// is to allow ANSI escape codes to be explicitly *disabled* without 318 /// having to opt-in to the dependencies required to emit ANSI formatting. 319 /// This way, code which constructs a formatter that should never emit 320 /// ANSI escape codes can ensure that they are not used, regardless of 321 /// whether or not other crates in the dependency graph enable the "ansi" 322 /// feature flag. 323 /// 324 /// [`with_ansi`]: Subscriber::with_ansi 325 /// [`set_ansi`]: Subscriber::set_ansi with_ansi(self, ansi: bool) -> Self326 pub fn with_ansi(self, ansi: bool) -> Self { 327 #[cfg(not(feature = "ansi"))] 328 if ansi { 329 const ERROR: &str = 330 "tracing-subscriber: the `ansi` crate feature is required to enable ANSI terminal colors"; 331 #[cfg(debug_assertions)] 332 panic!("{}", ERROR); 333 #[cfg(not(debug_assertions))] 334 eprintln!("{}", ERROR); 335 } 336 337 Self { 338 is_ansi: ansi, 339 ..self 340 } 341 } 342 343 /// Sets whether to write errors from [`FormatEvent`] to the writer. 344 /// Defaults to true. 345 /// 346 /// By default, `fmt::Layer` will write any `FormatEvent`-internal errors to 347 /// the writer. These errors are unlikely and will only occur if there is a 348 /// bug in the `FormatEvent` implementation or its dependencies. 349 /// 350 /// If writing to the writer fails, the error message is printed to stderr 351 /// as a fallback. 352 /// 353 /// [`FormatEvent`]: crate::fmt::FormatEvent log_internal_errors(self, log_internal_errors: bool) -> Self354 pub fn log_internal_errors(self, log_internal_errors: bool) -> Self { 355 Self { 356 log_internal_errors, 357 ..self 358 } 359 } 360 361 /// Updates the [`MakeWriter`] by applying a function to the existing [`MakeWriter`]. 362 /// 363 /// This sets the [`MakeWriter`] that the layer being built will use to write events. 364 /// 365 /// # Examples 366 /// 367 /// Redirect output to stderr if level is <= WARN: 368 /// 369 /// ```rust 370 /// use tracing::Level; 371 /// use tracing_subscriber::fmt::{self, writer::MakeWriterExt}; 372 /// 373 /// let stderr = std::io::stderr.with_max_level(Level::WARN); 374 /// let layer = fmt::layer() 375 /// .map_writer(move |w| stderr.or_else(w)); 376 /// # // this is necessary for type inference. 377 /// # use tracing_subscriber::Layer as _; 378 /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default()); 379 /// ``` map_writer<W2>(self, f: impl FnOnce(W) -> W2) -> Layer<S, N, E, W2> where W2: for<'writer> MakeWriter<'writer> + 'static,380 pub fn map_writer<W2>(self, f: impl FnOnce(W) -> W2) -> Layer<S, N, E, W2> 381 where 382 W2: for<'writer> MakeWriter<'writer> + 'static, 383 { 384 Layer { 385 fmt_fields: self.fmt_fields, 386 fmt_event: self.fmt_event, 387 fmt_span: self.fmt_span, 388 is_ansi: self.is_ansi, 389 log_internal_errors: self.log_internal_errors, 390 make_writer: f(self.make_writer), 391 _inner: self._inner, 392 } 393 } 394 } 395 396 impl<S, N, L, T, W> Layer<S, N, format::Format<L, T>, W> 397 where 398 N: for<'writer> FormatFields<'writer> + 'static, 399 { 400 /// Use the given [`timer`] for span and event timestamps. 401 /// 402 /// See the [`time` module] for the provided timer implementations. 403 /// 404 /// Note that using the `"time`"" feature flag enables the 405 /// additional time formatters [`UtcTime`] and [`LocalTime`], which use the 406 /// [`time` crate] to provide more sophisticated timestamp formatting 407 /// options. 408 /// 409 /// [`timer`]: super::time::FormatTime 410 /// [`time` module]: mod@super::time 411 /// [`UtcTime`]: super::time::UtcTime 412 /// [`LocalTime`]: super::time::LocalTime 413 /// [`time` crate]: https://docs.rs/time/0.3 with_timer<T2>(self, timer: T2) -> Layer<S, N, format::Format<L, T2>, W>414 pub fn with_timer<T2>(self, timer: T2) -> Layer<S, N, format::Format<L, T2>, W> { 415 Layer { 416 fmt_event: self.fmt_event.with_timer(timer), 417 fmt_fields: self.fmt_fields, 418 fmt_span: self.fmt_span, 419 make_writer: self.make_writer, 420 is_ansi: self.is_ansi, 421 log_internal_errors: self.log_internal_errors, 422 _inner: self._inner, 423 } 424 } 425 426 /// Do not emit timestamps with spans and event. without_time(self) -> Layer<S, N, format::Format<L, ()>, W>427 pub fn without_time(self) -> Layer<S, N, format::Format<L, ()>, W> { 428 Layer { 429 fmt_event: self.fmt_event.without_time(), 430 fmt_fields: self.fmt_fields, 431 fmt_span: self.fmt_span.without_time(), 432 make_writer: self.make_writer, 433 is_ansi: self.is_ansi, 434 log_internal_errors: self.log_internal_errors, 435 _inner: self._inner, 436 } 437 } 438 439 /// Configures how synthesized events are emitted at points in the [span 440 /// lifecycle][lifecycle]. 441 /// 442 /// The following options are available: 443 /// 444 /// - `FmtSpan::NONE`: No events will be synthesized when spans are 445 /// created, entered, exited, or closed. Data from spans will still be 446 /// included as the context for formatted events. This is the default. 447 /// - `FmtSpan::NEW`: An event will be synthesized when spans are created. 448 /// - `FmtSpan::ENTER`: An event will be synthesized when spans are entered. 449 /// - `FmtSpan::EXIT`: An event will be synthesized when spans are exited. 450 /// - `FmtSpan::CLOSE`: An event will be synthesized when a span closes. If 451 /// [timestamps are enabled][time] for this formatter, the generated 452 /// event will contain fields with the span's _busy time_ (the total 453 /// time for which it was entered) and _idle time_ (the total time that 454 /// the span existed but was not entered). 455 /// - `FmtSpan::ACTIVE`: Events will be synthesized when spans are entered 456 /// or exited. 457 /// - `FmtSpan::FULL`: Events will be synthesized whenever a span is 458 /// created, entered, exited, or closed. If timestamps are enabled, the 459 /// close event will contain the span's busy and idle time, as 460 /// described above. 461 /// 462 /// The options can be enabled in any combination. For instance, the following 463 /// will synthesize events whenever spans are created and closed: 464 /// 465 /// ```rust 466 /// use tracing_subscriber::fmt; 467 /// use tracing_subscriber::fmt::format::FmtSpan; 468 /// 469 /// let subscriber = fmt() 470 /// .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE) 471 /// .finish(); 472 /// ``` 473 /// 474 /// Note that the generated events will only be part of the log output by 475 /// this formatter; they will not be recorded by other `Subscriber`s or by 476 /// `Layer`s added to this subscriber. 477 /// 478 /// [lifecycle]: https://docs.rs/tracing/latest/tracing/span/index.html#the-span-lifecycle 479 /// [time]: Layer::without_time() with_span_events(self, kind: FmtSpan) -> Self480 pub fn with_span_events(self, kind: FmtSpan) -> Self { 481 Layer { 482 fmt_span: self.fmt_span.with_kind(kind), 483 ..self 484 } 485 } 486 487 /// Sets whether or not an event's target is displayed. with_target(self, display_target: bool) -> Layer<S, N, format::Format<L, T>, W>488 pub fn with_target(self, display_target: bool) -> Layer<S, N, format::Format<L, T>, W> { 489 Layer { 490 fmt_event: self.fmt_event.with_target(display_target), 491 ..self 492 } 493 } 494 /// Sets whether or not an event's [source code file path][file] is 495 /// displayed. 496 /// 497 /// [file]: tracing_core::Metadata::file with_file(self, display_filename: bool) -> Layer<S, N, format::Format<L, T>, W>498 pub fn with_file(self, display_filename: bool) -> Layer<S, N, format::Format<L, T>, W> { 499 Layer { 500 fmt_event: self.fmt_event.with_file(display_filename), 501 ..self 502 } 503 } 504 505 /// Sets whether or not an event's [source code line number][line] is 506 /// displayed. 507 /// 508 /// [line]: tracing_core::Metadata::line with_line_number( self, display_line_number: bool, ) -> Layer<S, N, format::Format<L, T>, W>509 pub fn with_line_number( 510 self, 511 display_line_number: bool, 512 ) -> Layer<S, N, format::Format<L, T>, W> { 513 Layer { 514 fmt_event: self.fmt_event.with_line_number(display_line_number), 515 ..self 516 } 517 } 518 519 /// Sets whether or not an event's level is displayed. with_level(self, display_level: bool) -> Layer<S, N, format::Format<L, T>, W>520 pub fn with_level(self, display_level: bool) -> Layer<S, N, format::Format<L, T>, W> { 521 Layer { 522 fmt_event: self.fmt_event.with_level(display_level), 523 ..self 524 } 525 } 526 527 /// Sets whether or not the [thread ID] of the current thread is displayed 528 /// when formatting events. 529 /// 530 /// [thread ID]: std::thread::ThreadId with_thread_ids(self, display_thread_ids: bool) -> Layer<S, N, format::Format<L, T>, W>531 pub fn with_thread_ids(self, display_thread_ids: bool) -> Layer<S, N, format::Format<L, T>, W> { 532 Layer { 533 fmt_event: self.fmt_event.with_thread_ids(display_thread_ids), 534 ..self 535 } 536 } 537 538 /// Sets whether or not the [name] of the current thread is displayed 539 /// when formatting events. 540 /// 541 /// [name]: std::thread#naming-threads with_thread_names( self, display_thread_names: bool, ) -> Layer<S, N, format::Format<L, T>, W>542 pub fn with_thread_names( 543 self, 544 display_thread_names: bool, 545 ) -> Layer<S, N, format::Format<L, T>, W> { 546 Layer { 547 fmt_event: self.fmt_event.with_thread_names(display_thread_names), 548 ..self 549 } 550 } 551 552 /// Sets the layer being built to use a [less verbose formatter][super::format::Compact]. compact(self) -> Layer<S, N, format::Format<format::Compact, T>, W> where N: for<'writer> FormatFields<'writer> + 'static,553 pub fn compact(self) -> Layer<S, N, format::Format<format::Compact, T>, W> 554 where 555 N: for<'writer> FormatFields<'writer> + 'static, 556 { 557 Layer { 558 fmt_event: self.fmt_event.compact(), 559 fmt_fields: self.fmt_fields, 560 fmt_span: self.fmt_span, 561 make_writer: self.make_writer, 562 is_ansi: self.is_ansi, 563 log_internal_errors: self.log_internal_errors, 564 _inner: self._inner, 565 } 566 } 567 568 /// Sets the layer being built to use an [excessively pretty, human-readable formatter](crate::fmt::format::Pretty). 569 #[cfg(feature = "ansi")] 570 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))] pretty(self) -> Layer<S, format::Pretty, format::Format<format::Pretty, T>, W>571 pub fn pretty(self) -> Layer<S, format::Pretty, format::Format<format::Pretty, T>, W> { 572 Layer { 573 fmt_event: self.fmt_event.pretty(), 574 fmt_fields: format::Pretty::default(), 575 fmt_span: self.fmt_span, 576 make_writer: self.make_writer, 577 is_ansi: self.is_ansi, 578 log_internal_errors: self.log_internal_errors, 579 _inner: self._inner, 580 } 581 } 582 583 /// Sets the layer being built to use a [JSON formatter][super::format::Json]. 584 /// 585 /// The full format includes fields from all entered spans. 586 /// 587 /// # Example Output 588 /// 589 /// ```ignore,json 590 /// {"timestamp":"Feb 20 11:28:15.096","level":"INFO","target":"mycrate","fields":{"message":"some message", "key": "value"}} 591 /// ``` 592 /// 593 /// # Options 594 /// 595 /// - [`Layer::flatten_event`] can be used to enable flattening event fields into the root 596 /// object. 597 /// 598 /// [`Layer::flatten_event`]: Layer::flatten_event() 599 #[cfg(feature = "json")] 600 #[cfg_attr(docsrs, doc(cfg(feature = "json")))] json(self) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W>601 pub fn json(self) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> { 602 Layer { 603 fmt_event: self.fmt_event.json(), 604 fmt_fields: format::JsonFields::new(), 605 fmt_span: self.fmt_span, 606 make_writer: self.make_writer, 607 // always disable ANSI escapes in JSON mode! 608 is_ansi: false, 609 log_internal_errors: self.log_internal_errors, 610 _inner: self._inner, 611 } 612 } 613 } 614 615 #[cfg(feature = "json")] 616 #[cfg_attr(docsrs, doc(cfg(feature = "json")))] 617 impl<S, T, W> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> { 618 /// Sets the JSON layer being built to flatten event metadata. 619 /// 620 /// See [`format::Json`][super::format::Json] flatten_event( self, flatten_event: bool, ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W>621 pub fn flatten_event( 622 self, 623 flatten_event: bool, 624 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> { 625 Layer { 626 fmt_event: self.fmt_event.flatten_event(flatten_event), 627 fmt_fields: format::JsonFields::new(), 628 ..self 629 } 630 } 631 632 /// Sets whether or not the formatter will include the current span in 633 /// formatted events. 634 /// 635 /// See [`format::Json`][super::format::Json] with_current_span( self, display_current_span: bool, ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W>636 pub fn with_current_span( 637 self, 638 display_current_span: bool, 639 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> { 640 Layer { 641 fmt_event: self.fmt_event.with_current_span(display_current_span), 642 fmt_fields: format::JsonFields::new(), 643 ..self 644 } 645 } 646 647 /// Sets whether or not the formatter will include a list (from root to leaf) 648 /// of all currently entered spans in formatted events. 649 /// 650 /// See [`format::Json`][super::format::Json] with_span_list( self, display_span_list: bool, ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W>651 pub fn with_span_list( 652 self, 653 display_span_list: bool, 654 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> { 655 Layer { 656 fmt_event: self.fmt_event.with_span_list(display_span_list), 657 fmt_fields: format::JsonFields::new(), 658 ..self 659 } 660 } 661 } 662 663 impl<S, N, E, W> Layer<S, N, E, W> { 664 /// Sets the field formatter that the layer being built will use to record 665 /// fields. fmt_fields<N2>(self, fmt_fields: N2) -> Layer<S, N2, E, W> where N2: for<'writer> FormatFields<'writer> + 'static,666 pub fn fmt_fields<N2>(self, fmt_fields: N2) -> Layer<S, N2, E, W> 667 where 668 N2: for<'writer> FormatFields<'writer> + 'static, 669 { 670 Layer { 671 fmt_event: self.fmt_event, 672 fmt_fields, 673 fmt_span: self.fmt_span, 674 make_writer: self.make_writer, 675 is_ansi: self.is_ansi, 676 log_internal_errors: self.log_internal_errors, 677 _inner: self._inner, 678 } 679 } 680 681 /// Updates the field formatter by applying a function to the existing field formatter. 682 /// 683 /// This sets the field formatter that the layer being built will use to record fields. 684 /// 685 /// # Examples 686 /// 687 /// Updating a field formatter: 688 /// 689 /// ```rust 690 /// use tracing_subscriber::field::MakeExt; 691 /// let layer = tracing_subscriber::fmt::layer() 692 /// .map_fmt_fields(|f| f.debug_alt()); 693 /// # // this is necessary for type inference. 694 /// # use tracing_subscriber::Layer as _; 695 /// # let _ = layer.with_subscriber(tracing_subscriber::registry::Registry::default()); 696 /// ``` map_fmt_fields<N2>(self, f: impl FnOnce(N) -> N2) -> Layer<S, N2, E, W> where N2: for<'writer> FormatFields<'writer> + 'static,697 pub fn map_fmt_fields<N2>(self, f: impl FnOnce(N) -> N2) -> Layer<S, N2, E, W> 698 where 699 N2: for<'writer> FormatFields<'writer> + 'static, 700 { 701 Layer { 702 fmt_event: self.fmt_event, 703 fmt_fields: f(self.fmt_fields), 704 fmt_span: self.fmt_span, 705 make_writer: self.make_writer, 706 is_ansi: self.is_ansi, 707 log_internal_errors: self.log_internal_errors, 708 _inner: self._inner, 709 } 710 } 711 } 712 713 impl<S> Default for Layer<S> { default() -> Self714 fn default() -> Self { 715 // only enable ANSI when the feature is enabled, and the NO_COLOR 716 // environment variable is unset or empty. 717 let ansi = cfg!(feature = "ansi") && env::var("NO_COLOR").map_or(true, |v| v.is_empty()); 718 719 Layer { 720 fmt_fields: format::DefaultFields::default(), 721 fmt_event: format::Format::default(), 722 fmt_span: format::FmtSpanConfig::default(), 723 make_writer: io::stdout, 724 is_ansi: ansi, 725 log_internal_errors: false, 726 _inner: PhantomData, 727 } 728 } 729 } 730 731 impl<S, N, E, W> Layer<S, N, E, W> 732 where 733 S: Subscriber + for<'a> LookupSpan<'a>, 734 N: for<'writer> FormatFields<'writer> + 'static, 735 E: FormatEvent<S, N> + 'static, 736 W: for<'writer> MakeWriter<'writer> + 'static, 737 { 738 #[inline] make_ctx<'a>(&'a self, ctx: Context<'a, S>, event: &'a Event<'a>) -> FmtContext<'a, S, N>739 fn make_ctx<'a>(&'a self, ctx: Context<'a, S>, event: &'a Event<'a>) -> FmtContext<'a, S, N> { 740 FmtContext { 741 ctx, 742 fmt_fields: &self.fmt_fields, 743 event, 744 } 745 } 746 } 747 748 /// A formatted representation of a span's fields stored in its [extensions]. 749 /// 750 /// Because `FormattedFields` is generic over the type of the formatter that 751 /// produced it, multiple versions of a span's formatted fields can be stored in 752 /// the [`Extensions`][extensions] type-map. This means that when multiple 753 /// formatters are in use, each can store its own formatted representation 754 /// without conflicting. 755 /// 756 /// [extensions]: crate::registry::Extensions 757 #[derive(Default)] 758 pub struct FormattedFields<E: ?Sized> { 759 _format_fields: PhantomData<fn(E)>, 760 was_ansi: bool, 761 /// The formatted fields of a span. 762 pub fields: String, 763 } 764 765 impl<E: ?Sized> FormattedFields<E> { 766 /// Returns a new `FormattedFields`. new(fields: String) -> Self767 pub fn new(fields: String) -> Self { 768 Self { 769 fields, 770 was_ansi: false, 771 _format_fields: PhantomData, 772 } 773 } 774 775 /// Returns a new [`format::Writer`] for writing to this `FormattedFields`. 776 /// 777 /// The returned [`format::Writer`] can be used with the 778 /// [`FormatFields::format_fields`] method. as_writer(&mut self) -> format::Writer<'_>779 pub fn as_writer(&mut self) -> format::Writer<'_> { 780 format::Writer::new(&mut self.fields).with_ansi(self.was_ansi) 781 } 782 } 783 784 impl<E: ?Sized> fmt::Debug for FormattedFields<E> { fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result785 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 786 f.debug_struct("FormattedFields") 787 .field("fields", &self.fields) 788 .field("formatter", &format_args!("{}", std::any::type_name::<E>())) 789 .field("was_ansi", &self.was_ansi) 790 .finish() 791 } 792 } 793 794 impl<E: ?Sized> fmt::Display for FormattedFields<E> { fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result795 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 796 fmt::Display::fmt(&self.fields, f) 797 } 798 } 799 800 impl<E: ?Sized> Deref for FormattedFields<E> { 801 type Target = String; deref(&self) -> &Self::Target802 fn deref(&self) -> &Self::Target { 803 &self.fields 804 } 805 } 806 807 // === impl FmtLayer === 808 809 macro_rules! with_event_from_span { 810 ($id:ident, $span:ident, $($field:literal = $value:expr),*, |$event:ident| $code:block) => { 811 let meta = $span.metadata(); 812 let cs = meta.callsite(); 813 let fs = field::FieldSet::new(&[$($field),*], cs); 814 #[allow(unused)] 815 let mut iter = fs.iter(); 816 let v = [$( 817 (&iter.next().unwrap(), ::core::option::Option::Some(&$value as &dyn field::Value)), 818 )*]; 819 let vs = fs.value_set(&v); 820 let $event = Event::new_child_of($id, meta, &vs); 821 $code 822 }; 823 } 824 825 impl<S, N, E, W> layer::Layer<S> for Layer<S, N, E, W> 826 where 827 S: Subscriber + for<'a> LookupSpan<'a>, 828 N: for<'writer> FormatFields<'writer> + 'static, 829 E: FormatEvent<S, N> + 'static, 830 W: for<'writer> MakeWriter<'writer> + 'static, 831 { on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>)832 fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) { 833 let span = ctx.span(id).expect("Span not found, this is a bug"); 834 let mut extensions = span.extensions_mut(); 835 836 if extensions.get_mut::<FormattedFields<N>>().is_none() { 837 let mut fields = FormattedFields::<N>::new(String::new()); 838 if self 839 .fmt_fields 840 .format_fields(fields.as_writer().with_ansi(self.is_ansi), attrs) 841 .is_ok() 842 { 843 fields.was_ansi = self.is_ansi; 844 extensions.insert(fields); 845 } else { 846 eprintln!( 847 "[tracing-subscriber] Unable to format the following event, ignoring: {:?}", 848 attrs 849 ); 850 } 851 } 852 853 if self.fmt_span.fmt_timing 854 && self.fmt_span.trace_close() 855 && extensions.get_mut::<Timings>().is_none() 856 { 857 extensions.insert(Timings::new()); 858 } 859 860 if self.fmt_span.trace_new() { 861 with_event_from_span!(id, span, "message" = "new", |event| { 862 drop(extensions); 863 drop(span); 864 self.on_event(&event, ctx); 865 }); 866 } 867 } 868 on_record(&self, id: &Id, values: &Record<'_>, ctx: Context<'_, S>)869 fn on_record(&self, id: &Id, values: &Record<'_>, ctx: Context<'_, S>) { 870 let span = ctx.span(id).expect("Span not found, this is a bug"); 871 let mut extensions = span.extensions_mut(); 872 if let Some(fields) = extensions.get_mut::<FormattedFields<N>>() { 873 let _ = self.fmt_fields.add_fields(fields, values); 874 return; 875 } 876 877 let mut fields = FormattedFields::<N>::new(String::new()); 878 if self 879 .fmt_fields 880 .format_fields(fields.as_writer().with_ansi(self.is_ansi), values) 881 .is_ok() 882 { 883 fields.was_ansi = self.is_ansi; 884 extensions.insert(fields); 885 } 886 } 887 on_enter(&self, id: &Id, ctx: Context<'_, S>)888 fn on_enter(&self, id: &Id, ctx: Context<'_, S>) { 889 if self.fmt_span.trace_enter() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing { 890 let span = ctx.span(id).expect("Span not found, this is a bug"); 891 let mut extensions = span.extensions_mut(); 892 if let Some(timings) = extensions.get_mut::<Timings>() { 893 let now = Instant::now(); 894 timings.idle += (now - timings.last).as_nanos() as u64; 895 timings.last = now; 896 } 897 898 if self.fmt_span.trace_enter() { 899 with_event_from_span!(id, span, "message" = "enter", |event| { 900 drop(extensions); 901 drop(span); 902 self.on_event(&event, ctx); 903 }); 904 } 905 } 906 } 907 on_exit(&self, id: &Id, ctx: Context<'_, S>)908 fn on_exit(&self, id: &Id, ctx: Context<'_, S>) { 909 if self.fmt_span.trace_exit() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing { 910 let span = ctx.span(id).expect("Span not found, this is a bug"); 911 let mut extensions = span.extensions_mut(); 912 if let Some(timings) = extensions.get_mut::<Timings>() { 913 let now = Instant::now(); 914 timings.busy += (now - timings.last).as_nanos() as u64; 915 timings.last = now; 916 } 917 918 if self.fmt_span.trace_exit() { 919 with_event_from_span!(id, span, "message" = "exit", |event| { 920 drop(extensions); 921 drop(span); 922 self.on_event(&event, ctx); 923 }); 924 } 925 } 926 } 927 on_close(&self, id: Id, ctx: Context<'_, S>)928 fn on_close(&self, id: Id, ctx: Context<'_, S>) { 929 if self.fmt_span.trace_close() { 930 let span = ctx.span(&id).expect("Span not found, this is a bug"); 931 let extensions = span.extensions(); 932 if let Some(timing) = extensions.get::<Timings>() { 933 let Timings { 934 busy, 935 mut idle, 936 last, 937 } = *timing; 938 idle += (Instant::now() - last).as_nanos() as u64; 939 940 let t_idle = field::display(TimingDisplay(idle)); 941 let t_busy = field::display(TimingDisplay(busy)); 942 943 with_event_from_span!( 944 id, 945 span, 946 "message" = "close", 947 "time.busy" = t_busy, 948 "time.idle" = t_idle, 949 |event| { 950 drop(extensions); 951 drop(span); 952 self.on_event(&event, ctx); 953 } 954 ); 955 } else { 956 with_event_from_span!(id, span, "message" = "close", |event| { 957 drop(extensions); 958 drop(span); 959 self.on_event(&event, ctx); 960 }); 961 } 962 } 963 } 964 on_event(&self, event: &Event<'_>, ctx: Context<'_, S>)965 fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) { 966 thread_local! { 967 static BUF: RefCell<String> = const { RefCell::new(String::new()) }; 968 } 969 970 BUF.with(|buf| { 971 let borrow = buf.try_borrow_mut(); 972 let mut a; 973 let mut b; 974 let mut buf = match borrow { 975 Ok(buf) => { 976 a = buf; 977 &mut *a 978 } 979 _ => { 980 b = String::new(); 981 &mut b 982 } 983 }; 984 985 let ctx = self.make_ctx(ctx, event); 986 if self 987 .fmt_event 988 .format_event( 989 &ctx, 990 format::Writer::new(&mut buf).with_ansi(self.is_ansi), 991 event, 992 ) 993 .is_ok() 994 { 995 let mut writer = self.make_writer.make_writer_for(event.metadata()); 996 let res = io::Write::write_all(&mut writer, buf.as_bytes()); 997 if self.log_internal_errors { 998 if let Err(e) = res { 999 eprintln!("[tracing-subscriber] Unable to write an event to the Writer for this Subscriber! Error: {}\n", e); 1000 } 1001 } 1002 } else if self.log_internal_errors { 1003 let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}\n", 1004 event.metadata().name(), event.fields()); 1005 let mut writer = self.make_writer.make_writer_for(event.metadata()); 1006 let res = io::Write::write_all(&mut writer, err_msg.as_bytes()); 1007 if let Err(e) = res { 1008 eprintln!("[tracing-subscriber] Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}\n", e); 1009 } 1010 } 1011 1012 buf.clear(); 1013 }); 1014 } 1015 downcast_raw(&self, id: TypeId) -> Option<*const ()>1016 unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> { 1017 // This `downcast_raw` impl allows downcasting a `fmt` layer to any of 1018 // its components (event formatter, field formatter, and `MakeWriter`) 1019 // as well as to the layer's type itself. The potential use-cases for 1020 // this *may* be somewhat niche, though... 1021 match () { 1022 _ if id == TypeId::of::<Self>() => Some(self as *const Self as *const ()), 1023 _ if id == TypeId::of::<E>() => Some(&self.fmt_event as *const E as *const ()), 1024 _ if id == TypeId::of::<N>() => Some(&self.fmt_fields as *const N as *const ()), 1025 _ if id == TypeId::of::<W>() => Some(&self.make_writer as *const W as *const ()), 1026 _ => None, 1027 } 1028 } 1029 } 1030 1031 /// Provides the current span context to a formatter. 1032 pub struct FmtContext<'a, S, N> { 1033 pub(crate) ctx: Context<'a, S>, 1034 pub(crate) fmt_fields: &'a N, 1035 pub(crate) event: &'a Event<'a>, 1036 } 1037 1038 impl<S, N> fmt::Debug for FmtContext<'_, S, N> { fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1039 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 1040 f.debug_struct("FmtContext").finish() 1041 } 1042 } 1043 1044 impl<'writer, S, N> FormatFields<'writer> for FmtContext<'_, S, N> 1045 where 1046 S: Subscriber + for<'lookup> LookupSpan<'lookup>, 1047 N: FormatFields<'writer> + 'static, 1048 { format_fields<R: RecordFields>( &self, writer: format::Writer<'writer>, fields: R, ) -> fmt::Result1049 fn format_fields<R: RecordFields>( 1050 &self, 1051 writer: format::Writer<'writer>, 1052 fields: R, 1053 ) -> fmt::Result { 1054 self.fmt_fields.format_fields(writer, fields) 1055 } 1056 } 1057 1058 impl<S, N> FmtContext<'_, S, N> 1059 where 1060 S: Subscriber + for<'lookup> LookupSpan<'lookup>, 1061 N: for<'writer> FormatFields<'writer> + 'static, 1062 { 1063 /// Visits every span in the current context with a closure. 1064 /// 1065 /// The provided closure will be called first with the current span, 1066 /// and then with that span's parent, and then that span's parent, 1067 /// and so on until a root span is reached. visit_spans<E, F>(&self, mut f: F) -> Result<(), E> where F: FnMut(&SpanRef<'_, S>) -> Result<(), E>,1068 pub fn visit_spans<E, F>(&self, mut f: F) -> Result<(), E> 1069 where 1070 F: FnMut(&SpanRef<'_, S>) -> Result<(), E>, 1071 { 1072 // visit all the current spans 1073 if let Some(scope) = self.event_scope() { 1074 for span in scope.from_root() { 1075 f(&span)?; 1076 } 1077 } 1078 Ok(()) 1079 } 1080 1081 /// Returns metadata for the span with the given `id`, if it exists. 1082 /// 1083 /// If this returns `None`, then no span exists for that ID (either it has 1084 /// closed or the ID is invalid). 1085 #[inline] metadata(&self, id: &Id) -> Option<&'static Metadata<'static>> where S: for<'lookup> LookupSpan<'lookup>,1086 pub fn metadata(&self, id: &Id) -> Option<&'static Metadata<'static>> 1087 where 1088 S: for<'lookup> LookupSpan<'lookup>, 1089 { 1090 self.ctx.metadata(id) 1091 } 1092 1093 /// Returns [stored data] for the span with the given `id`, if it exists. 1094 /// 1095 /// If this returns `None`, then no span exists for that ID (either it has 1096 /// closed or the ID is invalid). 1097 /// 1098 /// [stored data]: crate::registry::SpanRef 1099 #[inline] span(&self, id: &Id) -> Option<SpanRef<'_, S>> where S: for<'lookup> LookupSpan<'lookup>,1100 pub fn span(&self, id: &Id) -> Option<SpanRef<'_, S>> 1101 where 1102 S: for<'lookup> LookupSpan<'lookup>, 1103 { 1104 self.ctx.span(id) 1105 } 1106 1107 /// Returns `true` if an active span exists for the given `Id`. 1108 #[inline] exists(&self, id: &Id) -> bool where S: for<'lookup> LookupSpan<'lookup>,1109 pub fn exists(&self, id: &Id) -> bool 1110 where 1111 S: for<'lookup> LookupSpan<'lookup>, 1112 { 1113 self.ctx.exists(id) 1114 } 1115 1116 /// Returns [stored data] for the span that the wrapped subscriber considers 1117 /// to be the current. 1118 /// 1119 /// If this returns `None`, then we are not currently within a span. 1120 /// 1121 /// [stored data]: crate::registry::SpanRef 1122 #[inline] lookup_current(&self) -> Option<SpanRef<'_, S>> where S: for<'lookup> LookupSpan<'lookup>,1123 pub fn lookup_current(&self) -> Option<SpanRef<'_, S>> 1124 where 1125 S: for<'lookup> LookupSpan<'lookup>, 1126 { 1127 self.ctx.lookup_current() 1128 } 1129 1130 /// Returns the current span for this formatter. current_span(&self) -> Current1131 pub fn current_span(&self) -> Current { 1132 self.ctx.current_span() 1133 } 1134 1135 /// Returns [stored data] for the parent span of the event currently being 1136 /// formatted. 1137 /// 1138 /// If the event has a contextual parent, this will return the current span. If 1139 /// the event has an explicit parent span, this will return that span. If 1140 /// the event does not have a parent span, this will return `None`. 1141 /// 1142 /// [stored data]: SpanRef parent_span(&self) -> Option<SpanRef<'_, S>>1143 pub fn parent_span(&self) -> Option<SpanRef<'_, S>> { 1144 self.ctx.event_span(self.event) 1145 } 1146 1147 /// Returns an iterator over the [stored data] for all the spans in the 1148 /// current context, starting with the specified span and ending with the 1149 /// root of the trace tree and ending with the current span. 1150 /// 1151 /// This is equivalent to the [`Context::span_scope`] method. 1152 /// 1153 /// <div class="information"> 1154 /// <div class="tooltip ignore" style="">ⓘ<span class="tooltiptext">Note</span></div> 1155 /// </div> 1156 /// <div class="example-wrap" style="display:inline-block"> 1157 /// <pre class="ignore" style="white-space:normal;font:inherit;"> 1158 /// <strong>Note</strong>: Compared to <a href="#method.scope"><code>scope</code></a> this 1159 /// returns the spans in reverse order (from leaf to root). Use 1160 /// <a href="../registry/struct.Scope.html#method.from_root"><code>Scope::from_root</code></a> 1161 /// in case root-to-leaf ordering is desired. 1162 /// </pre></div> 1163 /// 1164 /// <div class="example-wrap" style="display:inline-block"> 1165 /// <pre class="ignore" style="white-space:normal;font:inherit;"> 1166 /// <strong>Note</strong>: This requires the wrapped subscriber to implement the 1167 /// <a href="../registry/trait.LookupSpan.html"><code>LookupSpan</code></a> trait. 1168 /// See the documentation on <a href="./struct.Context.html"><code>Context</code>'s 1169 /// declaration</a> for details. 1170 /// </pre></div> 1171 /// 1172 /// [stored data]: crate::registry::SpanRef span_scope(&self, id: &Id) -> Option<registry::Scope<'_, S>> where S: for<'lookup> LookupSpan<'lookup>,1173 pub fn span_scope(&self, id: &Id) -> Option<registry::Scope<'_, S>> 1174 where 1175 S: for<'lookup> LookupSpan<'lookup>, 1176 { 1177 self.ctx.span_scope(id) 1178 } 1179 1180 /// Returns an iterator over the [stored data] for all the spans in the 1181 /// event's span context, starting with its parent span and ending with the 1182 /// root of the trace tree. 1183 /// 1184 /// This is equivalent to calling the [`Context::event_scope`] method and 1185 /// passing the event currently being formatted. 1186 /// 1187 /// <div class="example-wrap" style="display:inline-block"> 1188 /// <pre class="ignore" style="white-space:normal;font:inherit;"> 1189 /// <strong>Note</strong>: Compared to <a href="#method.scope"><code>scope</code></a> this 1190 /// returns the spans in reverse order (from leaf to root). Use 1191 /// <a href="../registry/struct.Scope.html#method.from_root"><code>Scope::from_root</code></a> 1192 /// in case root-to-leaf ordering is desired. 1193 /// </pre></div> 1194 /// 1195 /// <div class="example-wrap" style="display:inline-block"> 1196 /// <pre class="ignore" style="white-space:normal;font:inherit;"> 1197 /// <strong>Note</strong>: This requires the wrapped subscriber to implement the 1198 /// <a href="../registry/trait.LookupSpan.html"><code>LookupSpan</code></a> trait. 1199 /// See the documentation on <a href="./struct.Context.html"><code>Context</code>'s 1200 /// declaration</a> for details. 1201 /// </pre></div> 1202 /// 1203 /// [stored data]: crate::registry::SpanRef event_scope(&self) -> Option<registry::Scope<'_, S>> where S: for<'lookup> registry::LookupSpan<'lookup>,1204 pub fn event_scope(&self) -> Option<registry::Scope<'_, S>> 1205 where 1206 S: for<'lookup> registry::LookupSpan<'lookup>, 1207 { 1208 self.ctx.event_scope(self.event) 1209 } 1210 1211 /// Returns the [field formatter] configured by the subscriber invoking 1212 /// `format_event`. 1213 /// 1214 /// The event formatter may use the returned field formatter to format the 1215 /// fields of any events it records. 1216 /// 1217 /// [field formatter]: FormatFields field_format(&self) -> &N1218 pub fn field_format(&self) -> &N { 1219 self.fmt_fields 1220 } 1221 } 1222 1223 struct Timings { 1224 idle: u64, 1225 busy: u64, 1226 last: Instant, 1227 } 1228 1229 impl Timings { new() -> Self1230 fn new() -> Self { 1231 Self { 1232 idle: 0, 1233 busy: 0, 1234 last: Instant::now(), 1235 } 1236 } 1237 } 1238 1239 #[cfg(test)] 1240 mod test { 1241 use super::*; 1242 use crate::fmt::{ 1243 self, 1244 format::{self, test::MockTime, Format}, 1245 layer::Layer as _, 1246 test::{MockMakeWriter, MockWriter}, 1247 time, 1248 }; 1249 use crate::Registry; 1250 use format::FmtSpan; 1251 use regex::Regex; 1252 use tracing::subscriber::with_default; 1253 use tracing_core::dispatcher::Dispatch; 1254 1255 #[test] impls()1256 fn impls() { 1257 let f = Format::default().with_timer(time::Uptime::default()); 1258 let fmt = fmt::Layer::default().event_format(f); 1259 let subscriber = fmt.with_subscriber(Registry::default()); 1260 let _dispatch = Dispatch::new(subscriber); 1261 1262 let f = format::Format::default(); 1263 let fmt = fmt::Layer::default().event_format(f); 1264 let subscriber = fmt.with_subscriber(Registry::default()); 1265 let _dispatch = Dispatch::new(subscriber); 1266 1267 let f = format::Format::default().compact(); 1268 let fmt = fmt::Layer::default().event_format(f); 1269 let subscriber = fmt.with_subscriber(Registry::default()); 1270 let _dispatch = Dispatch::new(subscriber); 1271 } 1272 1273 #[test] fmt_layer_downcasts()1274 fn fmt_layer_downcasts() { 1275 let f = format::Format::default(); 1276 let fmt = fmt::Layer::default().event_format(f); 1277 let subscriber = fmt.with_subscriber(Registry::default()); 1278 1279 let dispatch = Dispatch::new(subscriber); 1280 assert!(dispatch.downcast_ref::<fmt::Layer<Registry>>().is_some()); 1281 } 1282 1283 #[test] fmt_layer_downcasts_to_parts()1284 fn fmt_layer_downcasts_to_parts() { 1285 let f = format::Format::default(); 1286 let fmt = fmt::Layer::default().event_format(f); 1287 let subscriber = fmt.with_subscriber(Registry::default()); 1288 let dispatch = Dispatch::new(subscriber); 1289 assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some()); 1290 assert!(dispatch.downcast_ref::<format::Format>().is_some()) 1291 } 1292 1293 #[test] is_lookup_span()1294 fn is_lookup_span() { 1295 fn assert_lookup_span<T: for<'a> crate::registry::LookupSpan<'a>>(_: T) {} 1296 let fmt = fmt::Layer::default(); 1297 let subscriber = fmt.with_subscriber(Registry::default()); 1298 assert_lookup_span(subscriber) 1299 } 1300 sanitize_timings(s: String) -> String1301 fn sanitize_timings(s: String) -> String { 1302 let re = Regex::new("time\\.(idle|busy)=([0-9.]+)[mµn]s").unwrap(); 1303 re.replace_all(s.as_str(), "timing").to_string() 1304 } 1305 1306 #[test] format_error_print_to_stderr()1307 fn format_error_print_to_stderr() { 1308 struct AlwaysError; 1309 1310 impl std::fmt::Debug for AlwaysError { 1311 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result { 1312 Err(std::fmt::Error) 1313 } 1314 } 1315 1316 let make_writer = MockMakeWriter::default(); 1317 let subscriber = crate::fmt::Subscriber::builder() 1318 .with_writer(make_writer.clone()) 1319 .with_level(false) 1320 .with_ansi(false) 1321 .with_timer(MockTime) 1322 .finish(); 1323 1324 with_default(subscriber, || { 1325 tracing::info!(?AlwaysError); 1326 }); 1327 let actual = sanitize_timings(make_writer.get_string()); 1328 1329 // Only assert the start because the line number and callsite may change. 1330 let expected = concat!( 1331 "Unable to format the following event. Name: event ", 1332 file!(), 1333 ":" 1334 ); 1335 assert!( 1336 actual.as_str().starts_with(expected), 1337 "\nactual = {}\nshould start with expected = {}\n", 1338 actual, 1339 expected 1340 ); 1341 } 1342 1343 #[test] format_error_ignore_if_log_internal_errors_is_false()1344 fn format_error_ignore_if_log_internal_errors_is_false() { 1345 struct AlwaysError; 1346 1347 impl std::fmt::Debug for AlwaysError { 1348 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result { 1349 Err(std::fmt::Error) 1350 } 1351 } 1352 1353 let make_writer = MockMakeWriter::default(); 1354 let subscriber = crate::fmt::Subscriber::builder() 1355 .with_writer(make_writer.clone()) 1356 .with_level(false) 1357 .with_ansi(false) 1358 .with_timer(MockTime) 1359 .log_internal_errors(false) 1360 .finish(); 1361 1362 with_default(subscriber, || { 1363 tracing::info!(?AlwaysError); 1364 }); 1365 let actual = sanitize_timings(make_writer.get_string()); 1366 assert_eq!("", actual.as_str()); 1367 } 1368 1369 #[test] synthesize_span_none()1370 fn synthesize_span_none() { 1371 let make_writer = MockMakeWriter::default(); 1372 let subscriber = crate::fmt::Subscriber::builder() 1373 .with_writer(make_writer.clone()) 1374 .with_level(false) 1375 .with_ansi(false) 1376 .with_timer(MockTime) 1377 // check that FmtSpan::NONE is the default 1378 .finish(); 1379 1380 with_default(subscriber, || { 1381 let span1 = tracing::info_span!("span1", x = 42); 1382 let _e = span1.enter(); 1383 }); 1384 let actual = sanitize_timings(make_writer.get_string()); 1385 assert_eq!("", actual.as_str()); 1386 } 1387 1388 #[test] synthesize_span_active()1389 fn synthesize_span_active() { 1390 let make_writer = MockMakeWriter::default(); 1391 let subscriber = crate::fmt::Subscriber::builder() 1392 .with_writer(make_writer.clone()) 1393 .with_level(false) 1394 .with_ansi(false) 1395 .with_timer(MockTime) 1396 .with_span_events(FmtSpan::ACTIVE) 1397 .finish(); 1398 1399 with_default(subscriber, || { 1400 let span1 = tracing::info_span!("span1", x = 42); 1401 let _e = span1.enter(); 1402 }); 1403 let actual = sanitize_timings(make_writer.get_string()); 1404 assert_eq!( 1405 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\ 1406 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n", 1407 actual.as_str() 1408 ); 1409 } 1410 1411 #[test] synthesize_span_close()1412 fn synthesize_span_close() { 1413 let make_writer = MockMakeWriter::default(); 1414 let subscriber = crate::fmt::Subscriber::builder() 1415 .with_writer(make_writer.clone()) 1416 .with_level(false) 1417 .with_ansi(false) 1418 .with_timer(MockTime) 1419 .with_span_events(FmtSpan::CLOSE) 1420 .finish(); 1421 1422 with_default(subscriber, || { 1423 let span1 = tracing::info_span!("span1", x = 42); 1424 let _e = span1.enter(); 1425 }); 1426 let actual = sanitize_timings(make_writer.get_string()); 1427 assert_eq!( 1428 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n", 1429 actual.as_str() 1430 ); 1431 } 1432 1433 #[test] synthesize_span_close_no_timing()1434 fn synthesize_span_close_no_timing() { 1435 let make_writer = MockMakeWriter::default(); 1436 let subscriber = crate::fmt::Subscriber::builder() 1437 .with_writer(make_writer.clone()) 1438 .with_level(false) 1439 .with_ansi(false) 1440 .with_timer(MockTime) 1441 .without_time() 1442 .with_span_events(FmtSpan::CLOSE) 1443 .finish(); 1444 1445 with_default(subscriber, || { 1446 let span1 = tracing::info_span!("span1", x = 42); 1447 let _e = span1.enter(); 1448 }); 1449 let actual = sanitize_timings(make_writer.get_string()); 1450 assert_eq!( 1451 "span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close\n", 1452 actual.as_str() 1453 ); 1454 } 1455 1456 #[test] synthesize_span_full()1457 fn synthesize_span_full() { 1458 let make_writer = MockMakeWriter::default(); 1459 let subscriber = crate::fmt::Subscriber::builder() 1460 .with_writer(make_writer.clone()) 1461 .with_level(false) 1462 .with_ansi(false) 1463 .with_timer(MockTime) 1464 .with_span_events(FmtSpan::FULL) 1465 .finish(); 1466 1467 with_default(subscriber, || { 1468 let span1 = tracing::info_span!("span1", x = 42); 1469 let _e = span1.enter(); 1470 }); 1471 let actual = sanitize_timings(make_writer.get_string()); 1472 assert_eq!( 1473 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: new\n\ 1474 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\ 1475 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\ 1476 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n", 1477 actual.as_str() 1478 ); 1479 } 1480 1481 #[test] make_writer_based_on_meta()1482 fn make_writer_based_on_meta() { 1483 struct MakeByTarget { 1484 make_writer1: MockMakeWriter, 1485 make_writer2: MockMakeWriter, 1486 } 1487 1488 impl<'a> MakeWriter<'a> for MakeByTarget { 1489 type Writer = MockWriter; 1490 1491 fn make_writer(&'a self) -> Self::Writer { 1492 self.make_writer1.make_writer() 1493 } 1494 1495 fn make_writer_for(&'a self, meta: &Metadata<'_>) -> Self::Writer { 1496 if meta.target() == "writer2" { 1497 return self.make_writer2.make_writer(); 1498 } 1499 self.make_writer() 1500 } 1501 } 1502 1503 let make_writer1 = MockMakeWriter::default(); 1504 let make_writer2 = MockMakeWriter::default(); 1505 1506 let make_writer = MakeByTarget { 1507 make_writer1: make_writer1.clone(), 1508 make_writer2: make_writer2.clone(), 1509 }; 1510 1511 let subscriber = crate::fmt::Subscriber::builder() 1512 .with_writer(make_writer) 1513 .with_level(false) 1514 .with_target(false) 1515 .with_ansi(false) 1516 .with_timer(MockTime) 1517 .with_span_events(FmtSpan::CLOSE) 1518 .finish(); 1519 1520 with_default(subscriber, || { 1521 let span1 = tracing::info_span!("writer1_span", x = 42); 1522 let _e = span1.enter(); 1523 tracing::info!(target: "writer2", "hello writer2!"); 1524 let span2 = tracing::info_span!(target: "writer2", "writer2_span"); 1525 let _e = span2.enter(); 1526 tracing::warn!(target: "writer1", "hello writer1!"); 1527 }); 1528 1529 let actual = sanitize_timings(make_writer1.get_string()); 1530 assert_eq!( 1531 "fake time writer1_span{x=42}:writer2_span: hello writer1!\n\ 1532 fake time writer1_span{x=42}: close timing timing\n", 1533 actual.as_str() 1534 ); 1535 let actual = sanitize_timings(make_writer2.get_string()); 1536 assert_eq!( 1537 "fake time writer1_span{x=42}: hello writer2!\n\ 1538 fake time writer1_span{x=42}:writer2_span: close timing timing\n", 1539 actual.as_str() 1540 ); 1541 } 1542 1543 // Because we need to modify an environment variable for these test cases, 1544 // we do them all in a single test. 1545 #[cfg(feature = "ansi")] 1546 #[test] layer_no_color()1547 fn layer_no_color() { 1548 const NO_COLOR: &str = "NO_COLOR"; 1549 1550 // Restores the previous value of the `NO_COLOR` env variable when 1551 // dropped. 1552 // 1553 // This is done in a `Drop` implementation, rather than just resetting 1554 // the value at the end of the test, so that the previous value is 1555 // restored even if the test panics. 1556 struct RestoreEnvVar(Result<String, env::VarError>); 1557 impl Drop for RestoreEnvVar { 1558 fn drop(&mut self) { 1559 match self.0 { 1560 Ok(ref var) => env::set_var(NO_COLOR, var), 1561 Err(_) => env::remove_var(NO_COLOR), 1562 } 1563 } 1564 } 1565 1566 let _saved_no_color = RestoreEnvVar(env::var(NO_COLOR)); 1567 1568 let cases: Vec<(Option<&str>, bool)> = vec![ 1569 (Some("0"), false), // any non-empty value disables ansi 1570 (Some("off"), false), // any non-empty value disables ansi 1571 (Some("1"), false), 1572 (Some(""), true), // empty value does not disable ansi 1573 (None, true), 1574 ]; 1575 1576 for (var, ansi) in cases { 1577 if let Some(value) = var { 1578 env::set_var(NO_COLOR, value); 1579 } else { 1580 env::remove_var(NO_COLOR); 1581 } 1582 1583 let layer: Layer<()> = fmt::Layer::default(); 1584 assert_eq!( 1585 layer.is_ansi, ansi, 1586 "NO_COLOR={:?}; Layer::default().is_ansi should be {}", 1587 var, ansi 1588 ); 1589 1590 // with_ansi should override any `NO_COLOR` value 1591 let layer: Layer<()> = fmt::Layer::default().with_ansi(true); 1592 assert!( 1593 layer.is_ansi, 1594 "NO_COLOR={:?}; Layer::default().with_ansi(true).is_ansi should be true", 1595 var 1596 ); 1597 1598 // set_ansi should override any `NO_COLOR` value 1599 let mut layer: Layer<()> = fmt::Layer::default(); 1600 layer.set_ansi(true); 1601 assert!( 1602 layer.is_ansi, 1603 "NO_COLOR={:?}; layer.set_ansi(true); layer.is_ansi should be true", 1604 var 1605 ); 1606 } 1607 1608 // dropping `_saved_no_color` will restore the previous value of 1609 // `NO_COLOR`. 1610 } 1611 1612 // Validates that span event configuration can be modified with a reload handle 1613 #[test] modify_span_events()1614 fn modify_span_events() { 1615 let make_writer = MockMakeWriter::default(); 1616 1617 let inner_layer = fmt::Layer::default() 1618 .with_writer(make_writer.clone()) 1619 .with_level(false) 1620 .with_ansi(false) 1621 .with_timer(MockTime) 1622 .with_span_events(FmtSpan::ACTIVE); 1623 1624 let (reloadable_layer, reload_handle) = 1625 crate::reload::Layer::new(inner_layer); 1626 let reload = reloadable_layer.with_subscriber(Registry::default()); 1627 1628 with_default(reload, || { 1629 { 1630 let span1 = tracing::info_span!("span1", x = 42); 1631 let _e = span1.enter(); 1632 } 1633 1634 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::NONE)); 1635 1636 // this span should not be logged at all! 1637 { 1638 let span2 = tracing::info_span!("span2", x = 100); 1639 let _e = span2.enter(); 1640 } 1641 1642 { 1643 let span3 = tracing::info_span!("span3", x = 42); 1644 let _e = span3.enter(); 1645 1646 // The span config was modified after span3 was already entered. 1647 // We should only see an exit 1648 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::ACTIVE)); 1649 } 1650 }); 1651 let actual = sanitize_timings(make_writer.get_string()); 1652 assert_eq!( 1653 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\ 1654 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\ 1655 fake time span3{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n", 1656 actual.as_str() 1657 ); 1658 } 1659 } 1660