1 //! Spans represent periods of time in which a program was executing in a 2 //! particular context. 3 //! 4 //! A span consists of [fields], user-defined key-value pairs of arbitrary data 5 //! that describe the context the span represents, and a set of fixed attributes 6 //! that describe all `tracing` spans and events. Attributes describing spans 7 //! include: 8 //! 9 //! - An [`Id`] assigned by the subscriber that uniquely identifies it in relation 10 //! to other spans. 11 //! - The span's [parent] in the trace tree. 12 //! - [Metadata] that describes static characteristics of all spans 13 //! originating from that callsite, such as its name, source code location, 14 //! [verbosity level], and the names of its fields. 15 //! 16 //! # Creating Spans 17 //! 18 //! Spans are created using the [`span!`] macro. This macro is invoked with the 19 //! following arguments, in order: 20 //! 21 //! - The [`target`] and/or [`parent`][parent] attributes, if the user wishes to 22 //! override their default values. 23 //! - The span's [verbosity level] 24 //! - A string literal providing the span's name. 25 //! - Finally, between zero and 32 arbitrary key/value fields. 26 //! 27 //! [`target`]: ../struct.Metadata.html#method.target 28 //! 29 //! For example: 30 //! ```rust 31 //! use tracing::{span, Level}; 32 //! 33 //! /// Construct a new span at the `INFO` level named "my_span", with a single 34 //! /// field named answer , with the value `42`. 35 //! let my_span = span!(Level::INFO, "my_span", answer = 42); 36 //! ``` 37 //! 38 //! The documentation for the [`span!`] macro provides additional examples of 39 //! the various options that exist when creating spans. 40 //! 41 //! The [`trace_span!`], [`debug_span!`], [`info_span!`], [`warn_span!`], and 42 //! [`error_span!`] exist as shorthand for constructing spans at various 43 //! verbosity levels. 44 //! 45 //! ## Recording Span Creation 46 //! 47 //! The [`Attributes`] type contains data associated with a span, and is 48 //! provided to the [`Subscriber`] when a new span is created. It contains 49 //! the span's metadata, the ID of [the span's parent][parent] if one was 50 //! explicitly set, and any fields whose values were recorded when the span was 51 //! constructed. The subscriber, which is responsible for recording `tracing` 52 //! data, can then store or record these values. 53 //! 54 //! # The Span Lifecycle 55 //! 56 //! ## Entering a Span 57 //! 58 //! A thread of execution is said to _enter_ a span when it begins executing, 59 //! and _exit_ the span when it switches to another context. Spans may be 60 //! entered through the [`enter`], [`entered`], and [`in_scope`] methods. 61 //! 62 //! The [`enter`] method enters a span, returning a [guard] that exits the span 63 //! when dropped 64 //! ``` 65 //! # use tracing::{span, Level}; 66 //! let my_var: u64 = 5; 67 //! let my_span = span!(Level::TRACE, "my_span", my_var); 68 //! 69 //! // `my_span` exists but has not been entered. 70 //! 71 //! // Enter `my_span`... 72 //! let _enter = my_span.enter(); 73 //! 74 //! // Perform some work inside of the context of `my_span`... 75 //! // Dropping the `_enter` guard will exit the span. 76 //!``` 77 //! 78 //! <div class="information"> 79 //! <div class="tooltip compile_fail" style="">⚠ ️<span class="tooltiptext">Warning</span></div> 80 //! </div><div class="example-wrap" style="display:inline-block"><pre class="compile_fail" style="white-space:normal;font:inherit;"> 81 //! <strong>Warning</strong>: In asynchronous code that uses async/await syntax, 82 //! <code>Span::enter</code> may produce incorrect traces if the returned drop 83 //! guard is held across an await point. See 84 //! <a href="struct.Span.html#in-asynchronous-code">the method documentation</a> 85 //! for details. 86 //! </pre></div> 87 //! 88 //! The [`entered`] method is analogous to [`enter`], but moves the span into 89 //! the returned guard, rather than borrowing it. This allows creating and 90 //! entering a span in a single expression: 91 //! 92 //! ``` 93 //! # use tracing::{span, Level}; 94 //! // Create a span and enter it, returning a guard: 95 //! let span = span!(Level::INFO, "my_span").entered(); 96 //! 97 //! // We are now inside the span! Like `enter()`, the guard returned by 98 //! // `entered()` will exit the span when it is dropped... 99 //! 100 //! // ...but, it can also be exited explicitly, returning the `Span` 101 //! // struct: 102 //! let span = span.exit(); 103 //! ``` 104 //! 105 //! Finally, [`in_scope`] takes a closure or function pointer and executes it 106 //! inside the span: 107 //! 108 //! ``` 109 //! # use tracing::{span, Level}; 110 //! let my_var: u64 = 5; 111 //! let my_span = span!(Level::TRACE, "my_span", my_var = &my_var); 112 //! 113 //! my_span.in_scope(|| { 114 //! // perform some work in the context of `my_span`... 115 //! }); 116 //! 117 //! // Perform some work outside of the context of `my_span`... 118 //! 119 //! my_span.in_scope(|| { 120 //! // Perform some more work in the context of `my_span`. 121 //! }); 122 //! ``` 123 //! 124 //! <div class="information"> 125 //! <div class="tooltip ignore" style="">ⓘ<span class="tooltiptext">Note</span></div> 126 //! </div> 127 //! <div class="example-wrap" style="display:inline-block"> 128 //! <pre class="ignore" style="white-space:normal;font:inherit;"> 129 //! <strong>Note</strong>: Since entering a span takes <code>&self</code<, and 130 //! <code>Span</code>s are <code>Clone</code>, <code>Send</code>, and 131 //! <code>Sync</code>, it is entirely valid for multiple threads to enter the 132 //! same span concurrently. 133 //! </pre></div> 134 //! 135 //! ## Span Relationships 136 //! 137 //! Spans form a tree structure — unless it is a root span, all spans have a 138 //! _parent_, and may have one or more _children_. When a new span is created, 139 //! the current span becomes the new span's parent. The total execution time of 140 //! a span consists of the time spent in that span and in the entire subtree 141 //! represented by its children. Thus, a parent span always lasts for at least 142 //! as long as the longest-executing span in its subtree. 143 //! 144 //! ``` 145 //! # #[macro_use] extern crate tracing; 146 //! # use tracing::Level; 147 //! // this span is considered the "root" of a new trace tree: 148 //! span!(Level::INFO, "root").in_scope(|| { 149 //! // since we are now inside "root", this span is considered a child 150 //! // of "root": 151 //! span!(Level::DEBUG, "outer_child").in_scope(|| { 152 //! // this span is a child of "outer_child", which is in turn a 153 //! // child of "root": 154 //! span!(Level::TRACE, "inner_child").in_scope(|| { 155 //! // and so on... 156 //! }); 157 //! }); 158 //! // another span created here would also be a child of "root". 159 //! }); 160 //!``` 161 //! 162 //! In addition, the parent of a span may be explicitly specified in 163 //! the `span!` macro. For example: 164 //! 165 //! ```rust 166 //! # #[macro_use] extern crate tracing; 167 //! # use tracing::Level; 168 //! // Create, but do not enter, a span called "foo". 169 //! let foo = span!(Level::INFO, "foo"); 170 //! 171 //! // Create and enter a span called "bar". 172 //! let bar = span!(Level::INFO, "bar"); 173 //! let _enter = bar.enter(); 174 //! 175 //! // Although we have currently entered "bar", "baz"'s parent span 176 //! // will be "foo". 177 //! let baz = span!(parent: &foo, Level::INFO, "baz"); 178 //! ``` 179 //! 180 //! A child span should typically be considered _part_ of its parent. For 181 //! example, if a subscriber is recording the length of time spent in various 182 //! spans, it should generally include the time spent in a span's children as 183 //! part of that span's duration. 184 //! 185 //! In addition to having zero or one parent, a span may also _follow from_ any 186 //! number of other spans. This indicates a causal relationship between the span 187 //! and the spans that it follows from, but a follower is *not* typically 188 //! considered part of the duration of the span it follows. Unlike the parent, a 189 //! span may record that it follows from another span after it is created, using 190 //! the [`follows_from`] method. 191 //! 192 //! As an example, consider a listener task in a server. As the listener accepts 193 //! incoming connections, it spawns new tasks that handle those connections. We 194 //! might want to have a span representing the listener, and instrument each 195 //! spawned handler task with its own span. We would want our instrumentation to 196 //! record that the handler tasks were spawned as a result of the listener task. 197 //! However, we might not consider the handler tasks to be _part_ of the time 198 //! spent in the listener task, so we would not consider those spans children of 199 //! the listener span. Instead, we would record that the handler tasks follow 200 //! from the listener, recording the causal relationship but treating the spans 201 //! as separate durations. 202 //! 203 //! ## Closing Spans 204 //! 205 //! Execution may enter and exit a span multiple times before that span is 206 //! _closed_. Consider, for example, a future which has an associated 207 //! span and enters that span every time it is polled: 208 //! ```rust 209 //! # extern crate tracing; 210 //! # extern crate futures; 211 //! # use futures::{Future, Poll, Async}; 212 //! struct MyFuture { 213 //! // data 214 //! span: tracing::Span, 215 //! } 216 //! 217 //! impl Future for MyFuture { 218 //! type Item = (); 219 //! type Error = (); 220 //! 221 //! fn poll(&mut self) -> Poll<Self::Item, Self::Error> { 222 //! let _enter = self.span.enter(); 223 //! // Do actual future work... 224 //! # Ok(Async::Ready(())) 225 //! } 226 //! } 227 //! ``` 228 //! 229 //! If this future was spawned on an executor, it might yield one or more times 230 //! before `poll` returns `Ok(Async::Ready)`. If the future were to yield, then 231 //! the executor would move on to poll the next future, which may _also_ enter 232 //! an associated span or series of spans. Therefore, it is valid for a span to 233 //! be entered repeatedly before it completes. Only the time when that span or 234 //! one of its children was the current span is considered to be time spent in 235 //! that span. A span which is not executing and has not yet been closed is said 236 //! to be _idle_. 237 //! 238 //! Because spans may be entered and exited multiple times before they close, 239 //! [`Subscriber`]s have separate trait methods which are called to notify them 240 //! of span exits and when span handles are dropped. When execution exits a 241 //! span, [`exit`] will always be called with that span's ID to notify the 242 //! subscriber that the span has been exited. When span handles are dropped, the 243 //! [`drop_span`] method is called with that span's ID. The subscriber may use 244 //! this to determine whether or not the span will be entered again. 245 //! 246 //! If there is only a single handle with the capacity to exit a span, dropping 247 //! that handle "closes" the span, since the capacity to enter it no longer 248 //! exists. For example: 249 //! ``` 250 //! # #[macro_use] extern crate tracing; 251 //! # use tracing::Level; 252 //! { 253 //! span!(Level::TRACE, "my_span").in_scope(|| { 254 //! // perform some work in the context of `my_span`... 255 //! }); // --> Subscriber::exit(my_span) 256 //! 257 //! // The handle to `my_span` only lives inside of this block; when it is 258 //! // dropped, the subscriber will be informed via `drop_span`. 259 //! 260 //! } // --> Subscriber::drop_span(my_span) 261 //! ``` 262 //! 263 //! However, if multiple handles exist, the span can still be re-entered even if 264 //! one or more is dropped. For determining when _all_ handles to a span have 265 //! been dropped, `Subscriber`s have a [`clone_span`] method, which is called 266 //! every time a span handle is cloned. Combined with `drop_span`, this may be 267 //! used to track the number of handles to a given span — if `drop_span` has 268 //! been called one more time than the number of calls to `clone_span` for a 269 //! given ID, then no more handles to the span with that ID exist. The 270 //! subscriber may then treat it as closed. 271 //! 272 //! # When to use spans 273 //! 274 //! As a rule of thumb, spans should be used to represent discrete units of work 275 //! (e.g., a given request's lifetime in a server) or periods of time spent in a 276 //! given context (e.g., time spent interacting with an instance of an external 277 //! system, such as a database). 278 //! 279 //! Which scopes in a program correspond to new spans depend somewhat on user 280 //! intent. For example, consider the case of a loop in a program. Should we 281 //! construct one span and perform the entire loop inside of that span, like: 282 //! 283 //! ```rust 284 //! # #[macro_use] extern crate tracing; 285 //! # use tracing::Level; 286 //! # let n = 1; 287 //! let span = span!(Level::TRACE, "my_loop"); 288 //! let _enter = span.enter(); 289 //! for i in 0..n { 290 //! # let _ = i; 291 //! // ... 292 //! } 293 //! ``` 294 //! Or, should we create a new span for each iteration of the loop, as in: 295 //! ```rust 296 //! # #[macro_use] extern crate tracing; 297 //! # use tracing::Level; 298 //! # let n = 1u64; 299 //! for i in 0..n { 300 //! let span = span!(Level::TRACE, "my_loop", iteration = i); 301 //! let _enter = span.enter(); 302 //! // ... 303 //! } 304 //! ``` 305 //! 306 //! Depending on the circumstances, we might want to do either, or both. For 307 //! example, if we want to know how long was spent in the loop overall, we would 308 //! create a single span around the entire loop; whereas if we wanted to know how 309 //! much time was spent in each individual iteration, we would enter a new span 310 //! on every iteration. 311 //! 312 //! [fields]: ../field/index.html 313 //! [Metadata]: ../struct.Metadata.html 314 //! [`Id`]: struct.Id.html 315 //! [verbosity level]: ../struct.Level.html 316 //! [`span!`]: ../macro.span.html 317 //! [`trace_span!`]: ../macro.trace_span.html 318 //! [`debug_span!`]: ../macro.debug_span.html 319 //! [`info_span!`]: ../macro.info_span.html 320 //! [`warn_span!`]: ../macro.warn_span.html 321 //! [`error_span!`]: ../macro.error_span.html 322 //! [`clone_span`]: ../subscriber/trait.Subscriber.html#method.clone_span 323 //! [`drop_span`]: ../subscriber/trait.Subscriber.html#method.drop_span 324 //! [`exit`]: ../subscriber/trait.Subscriber.html#tymethod.exit 325 //! [`Subscriber`]: ../subscriber/trait.Subscriber.html 326 //! [`Attributes`]: struct.Attributes.html 327 //! [`enter`]: struct.Span.html#method.enter 328 //! [`entered`]: struct.Span.html#method.entered 329 //! [`in_scope`]: struct.Span.html#method.in_scope 330 //! [`follows_from`]: struct.Span.html#method.follows_from 331 //! [guard]: struct.Entered.html 332 //! [parent]: #span-relationships 333 pub use tracing_core::span::{Attributes, Id, Record}; 334 335 use crate::stdlib::{ 336 cmp, fmt, 337 hash::{Hash, Hasher}, 338 marker::PhantomData, 339 mem, 340 ops::Deref, 341 }; 342 use crate::{ 343 dispatcher::{self, Dispatch}, 344 field, Metadata, 345 }; 346 347 /// Trait implemented by types which have a span `Id`. 348 pub trait AsId: crate::sealed::Sealed { 349 /// Returns the `Id` of the span that `self` corresponds to, or `None` if 350 /// this corresponds to a disabled span. as_id(&self) -> Option<&Id>351 fn as_id(&self) -> Option<&Id>; 352 } 353 354 /// A handle representing a span, with the capability to enter the span if it 355 /// exists. 356 /// 357 /// If the span was rejected by the current `Subscriber`'s filter, entering the 358 /// span will silently do nothing. Thus, the handle can be used in the same 359 /// manner regardless of whether or not the trace is currently being collected. 360 #[derive(Clone)] 361 pub struct Span { 362 /// A handle used to enter the span when it is not executing. 363 /// 364 /// If this is `None`, then the span has either closed or was never enabled. 365 inner: Option<Inner>, 366 /// Metadata describing the span. 367 /// 368 /// This might be `Some` even if `inner` is `None`, in the case that the 369 /// span is disabled but the metadata is needed for `log` support. 370 meta: Option<&'static Metadata<'static>>, 371 } 372 373 /// A handle representing the capacity to enter a span which is known to exist. 374 /// 375 /// Unlike `Span`, this type is only constructed for spans which _have_ been 376 /// enabled by the current filter. This type is primarily used for implementing 377 /// span handles; users should typically not need to interact with it directly. 378 #[derive(Debug)] 379 pub(crate) struct Inner { 380 /// The span's ID, as provided by `subscriber`. 381 id: Id, 382 383 /// The subscriber that will receive events relating to this span. 384 /// 385 /// This should be the same subscriber that provided this span with its 386 /// `id`. 387 subscriber: Dispatch, 388 } 389 390 /// A guard representing a span which has been entered and is currently 391 /// executing. 392 /// 393 /// When the guard is dropped, the span will be exited. 394 /// 395 /// This is returned by the [`Span::enter`] function. 396 /// 397 /// [`Span::enter`]: ../struct.Span.html#method.enter 398 #[derive(Debug)] 399 #[must_use = "once a span has been entered, it should be exited"] 400 pub struct Entered<'a> { 401 span: &'a Span, 402 } 403 404 /// An owned version of [`Entered`], a guard representing a span which has been 405 /// entered and is currently executing. 406 /// 407 /// When the guard is dropped, the span will be exited. 408 /// 409 /// This is returned by the [`Span::entered`] function. 410 /// 411 /// [`Span::entered`]: super::Span::entered() 412 #[derive(Debug)] 413 #[must_use = "once a span has been entered, it should be exited"] 414 pub struct EnteredSpan { 415 span: Span, 416 417 /// ```compile_fail 418 /// use tracing::span::*; 419 /// trait AssertSend: Send {} 420 /// 421 /// impl AssertSend for EnteredSpan {} 422 /// ``` 423 _not_send: PhantomNotSend, 424 } 425 426 /// `log` target for all span lifecycle (creation/enter/exit/close) records. 427 #[cfg(feature = "log")] 428 const LIFECYCLE_LOG_TARGET: &str = "tracing::span"; 429 /// `log` target for span activity (enter/exit) records. 430 #[cfg(feature = "log")] 431 const ACTIVITY_LOG_TARGET: &str = "tracing::span::active"; 432 433 // ===== impl Span ===== 434 435 impl Span { 436 /// Constructs a new `Span` with the given [metadata] and set of 437 /// [field values]. 438 /// 439 /// The new span will be constructed by the currently-active [`Subscriber`], 440 /// with the current span as its parent (if one exists). 441 /// 442 /// After the span is constructed, [field values] and/or [`follows_from`] 443 /// annotations may be added to it. 444 /// 445 /// [metadata]: ../metadata 446 /// [`Subscriber`]: ../subscriber/trait.Subscriber.html 447 /// [field values]: ../field/struct.ValueSet.html 448 /// [`follows_from`]: ../struct.Span.html#method.follows_from new(meta: &'static Metadata<'static>, values: &field::ValueSet<'_>) -> Span449 pub fn new(meta: &'static Metadata<'static>, values: &field::ValueSet<'_>) -> Span { 450 dispatcher::get_default(|dispatch| Self::new_with(meta, values, dispatch)) 451 } 452 453 #[inline] 454 #[doc(hidden)] new_with( meta: &'static Metadata<'static>, values: &field::ValueSet<'_>, dispatch: &Dispatch, ) -> Span455 pub fn new_with( 456 meta: &'static Metadata<'static>, 457 values: &field::ValueSet<'_>, 458 dispatch: &Dispatch, 459 ) -> Span { 460 let new_span = Attributes::new(meta, values); 461 Self::make_with(meta, new_span, dispatch) 462 } 463 464 /// Constructs a new `Span` as the root of its own trace tree, with the 465 /// given [metadata] and set of [field values]. 466 /// 467 /// After the span is constructed, [field values] and/or [`follows_from`] 468 /// annotations may be added to it. 469 /// 470 /// [metadata]: ../metadata 471 /// [field values]: ../field/struct.ValueSet.html 472 /// [`follows_from`]: ../struct.Span.html#method.follows_from new_root(meta: &'static Metadata<'static>, values: &field::ValueSet<'_>) -> Span473 pub fn new_root(meta: &'static Metadata<'static>, values: &field::ValueSet<'_>) -> Span { 474 dispatcher::get_default(|dispatch| Self::new_root_with(meta, values, dispatch)) 475 } 476 477 #[inline] 478 #[doc(hidden)] new_root_with( meta: &'static Metadata<'static>, values: &field::ValueSet<'_>, dispatch: &Dispatch, ) -> Span479 pub fn new_root_with( 480 meta: &'static Metadata<'static>, 481 values: &field::ValueSet<'_>, 482 dispatch: &Dispatch, 483 ) -> Span { 484 let new_span = Attributes::new_root(meta, values); 485 Self::make_with(meta, new_span, dispatch) 486 } 487 488 /// Constructs a new `Span` as child of the given parent span, with the 489 /// given [metadata] and set of [field values]. 490 /// 491 /// After the span is constructed, [field values] and/or [`follows_from`] 492 /// annotations may be added to it. 493 /// 494 /// [metadata]: ../metadata 495 /// [field values]: ../field/struct.ValueSet.html 496 /// [`follows_from`]: ../struct.Span.html#method.follows_from child_of( parent: impl Into<Option<Id>>, meta: &'static Metadata<'static>, values: &field::ValueSet<'_>, ) -> Span497 pub fn child_of( 498 parent: impl Into<Option<Id>>, 499 meta: &'static Metadata<'static>, 500 values: &field::ValueSet<'_>, 501 ) -> Span { 502 let mut parent = parent.into(); 503 dispatcher::get_default(move |dispatch| { 504 Self::child_of_with(Option::take(&mut parent), meta, values, dispatch) 505 }) 506 } 507 508 #[inline] 509 #[doc(hidden)] child_of_with( parent: impl Into<Option<Id>>, meta: &'static Metadata<'static>, values: &field::ValueSet<'_>, dispatch: &Dispatch, ) -> Span510 pub fn child_of_with( 511 parent: impl Into<Option<Id>>, 512 meta: &'static Metadata<'static>, 513 values: &field::ValueSet<'_>, 514 dispatch: &Dispatch, 515 ) -> Span { 516 let new_span = match parent.into() { 517 Some(parent) => Attributes::child_of(parent, meta, values), 518 None => Attributes::new_root(meta, values), 519 }; 520 Self::make_with(meta, new_span, dispatch) 521 } 522 523 /// Constructs a new disabled span with the given `Metadata`. 524 /// 525 /// This should be used when a span is constructed from a known callsite, 526 /// but the subscriber indicates that it is disabled. 527 /// 528 /// Entering, exiting, and recording values on this span will not notify the 529 /// `Subscriber` but _may_ record log messages if the `log` feature flag is 530 /// enabled. 531 #[inline(always)] new_disabled(meta: &'static Metadata<'static>) -> Span532 pub fn new_disabled(meta: &'static Metadata<'static>) -> Span { 533 Self { 534 inner: None, 535 meta: Some(meta), 536 } 537 } 538 539 /// Constructs a new span that is *completely disabled*. 540 /// 541 /// This can be used rather than `Option<Span>` to represent cases where a 542 /// span is not present. 543 /// 544 /// Entering, exiting, and recording values on this span will do nothing. 545 #[inline(always)] none() -> Span546 pub const fn none() -> Span { 547 Self { 548 inner: None, 549 meta: None, 550 } 551 } 552 553 /// Returns a handle to the span [considered by the `Subscriber`] to be the 554 /// current span. 555 /// 556 /// If the subscriber indicates that it does not track the current span, or 557 /// that the thread from which this function is called is not currently 558 /// inside a span, the returned span will be disabled. 559 /// 560 /// [considered by the `Subscriber`]: ../subscriber/trait.Subscriber.html#method.current current() -> Span561 pub fn current() -> Span { 562 dispatcher::get_default(|dispatch| { 563 if let Some((id, meta)) = dispatch.current_span().into_inner() { 564 let id = dispatch.clone_span(&id); 565 Self { 566 inner: Some(Inner::new(id, dispatch)), 567 meta: Some(meta), 568 } 569 } else { 570 Self::none() 571 } 572 }) 573 } 574 make_with( meta: &'static Metadata<'static>, new_span: Attributes<'_>, dispatch: &Dispatch, ) -> Span575 fn make_with( 576 meta: &'static Metadata<'static>, 577 new_span: Attributes<'_>, 578 dispatch: &Dispatch, 579 ) -> Span { 580 let attrs = &new_span; 581 let id = dispatch.new_span(attrs); 582 let inner = Some(Inner::new(id, dispatch)); 583 584 let span = Self { 585 inner, 586 meta: Some(meta), 587 }; 588 589 if_log_enabled! { *meta.level(), { 590 let target = if attrs.is_empty() { 591 LIFECYCLE_LOG_TARGET 592 } else { 593 meta.target() 594 }; 595 span.log(target, level_to_log!(*meta.level()), format_args!("++ {}{}", meta.name(), FmtAttrs(attrs))); 596 }} 597 598 span 599 } 600 601 /// Enters this span, returning a guard that will exit the span when dropped. 602 /// 603 /// If this span is enabled by the current subscriber, then this function will 604 /// call [`Subscriber::enter`] with the span's [`Id`], and dropping the guard 605 /// will call [`Subscriber::exit`]. If the span is disabled, this does 606 /// nothing. 607 /// 608 /// # In Asynchronous Code 609 /// 610 /// **Warning**: in asynchronous code that uses [async/await syntax][syntax], 611 /// `Span::enter` should be used very carefully or avoided entirely. Holding 612 /// the drop guard returned by `Span::enter` across `.await` points will 613 /// result in incorrect traces. 614 /// 615 /// For example, 616 /// 617 /// ``` 618 /// # use tracing::info_span; 619 /// # async fn some_other_async_function() {} 620 /// async fn my_async_function() { 621 /// let span = info_span!("my_async_function"); 622 /// 623 /// // THIS WILL RESULT IN INCORRECT TRACES 624 /// let _enter = span.enter(); 625 /// some_other_async_function().await; 626 /// 627 /// // ... 628 /// } 629 /// ``` 630 /// 631 /// The drop guard returned by `Span::enter` exits the span when it is 632 /// dropped. When an async function or async block yields at an `.await` 633 /// point, the current scope is _exited_, but values in that scope are 634 /// **not** dropped (because the async block will eventually resume 635 /// execution from that await point). This means that _another_ task will 636 /// begin executing while _remaining_ in the entered span. This results in 637 /// an incorrect trace. 638 /// 639 /// Instead of using `Span::enter` in asynchronous code, prefer the 640 /// following: 641 /// 642 /// * To enter a span for a synchronous section of code within an async 643 /// block or function, prefer [`Span::in_scope`]. Since `in_scope` takes a 644 /// synchronous closure and exits the span when the closure returns, the 645 /// span will always be exited before the next await point. For example: 646 /// ``` 647 /// # use tracing::info_span; 648 /// # async fn some_other_async_function(_: ()) {} 649 /// async fn my_async_function() { 650 /// let span = info_span!("my_async_function"); 651 /// 652 /// let some_value = span.in_scope(|| { 653 /// // run some synchronous code inside the span... 654 /// }); 655 /// 656 /// // This is okay! The span has already been exited before we reach 657 /// // the await point. 658 /// some_other_async_function(some_value).await; 659 /// 660 /// // ... 661 /// } 662 /// ``` 663 /// * For instrumenting asynchronous code, `tracing` provides the 664 /// [`Future::instrument` combinator][instrument] for 665 /// attaching a span to a future (async function or block). This will 666 /// enter the span _every_ time the future is polled, and exit it whenever 667 /// the future yields. 668 /// 669 /// `Instrument` can be used with an async block inside an async function: 670 /// ```ignore 671 /// # use tracing::info_span; 672 /// use tracing::Instrument; 673 /// 674 /// # async fn some_other_async_function() {} 675 /// async fn my_async_function() { 676 /// let span = info_span!("my_async_function"); 677 /// async move { 678 /// // This is correct! If we yield here, the span will be exited, 679 /// // and re-entered when we resume. 680 /// some_other_async_function().await; 681 /// 682 /// //more asynchronous code inside the span... 683 /// 684 /// } 685 /// // instrument the async block with the span... 686 /// .instrument(span) 687 /// // ...and await it. 688 /// .await 689 /// } 690 /// ``` 691 /// 692 /// It can also be used to instrument calls to async functions at the 693 /// callsite: 694 /// ```ignore 695 /// # use tracing::debug_span; 696 /// use tracing::Instrument; 697 /// 698 /// # async fn some_other_async_function() {} 699 /// async fn my_async_function() { 700 /// let some_value = some_other_async_function() 701 /// .instrument(debug_span!("some_other_async_function")) 702 /// .await; 703 /// 704 /// // ... 705 /// } 706 /// ``` 707 /// 708 /// * The [`#[instrument]` attribute macro][attr] can automatically generate 709 /// correct code when used on an async function: 710 /// 711 /// ```ignore 712 /// # async fn some_other_async_function() {} 713 /// #[tracing::instrument(level = "info")] 714 /// async fn my_async_function() { 715 /// 716 /// // This is correct! If we yield here, the span will be exited, 717 /// // and re-entered when we resume. 718 /// some_other_async_function().await; 719 /// 720 /// // ... 721 /// 722 /// } 723 /// ``` 724 /// 725 /// [syntax]: https://rust-lang.github.io/async-book/01_getting_started/04_async_await_primer.html 726 /// [`Span::in_scope`]: #method.in_scope 727 /// [instrument]: https://docs.rs/tracing/latest/tracing/trait.Instrument.html 728 /// [attr]: ../../attr.instrument.html 729 /// 730 /// # Examples 731 /// 732 /// ``` 733 /// #[macro_use] extern crate tracing; 734 /// # use tracing::Level; 735 /// let span = span!(Level::INFO, "my_span"); 736 /// let guard = span.enter(); 737 /// 738 /// // code here is within the span 739 /// 740 /// drop(guard); 741 /// 742 /// // code here is no longer within the span 743 /// 744 /// ``` 745 /// 746 /// Guards need not be explicitly dropped: 747 /// 748 /// ``` 749 /// #[macro_use] extern crate tracing; 750 /// fn my_function() -> String { 751 /// // enter a span for the duration of this function. 752 /// let span = trace_span!("my_function"); 753 /// let _enter = span.enter(); 754 /// 755 /// // anything happening in functions we call is still inside the span... 756 /// my_other_function(); 757 /// 758 /// // returning from the function drops the guard, exiting the span. 759 /// return "Hello world".to_owned(); 760 /// } 761 /// 762 /// fn my_other_function() { 763 /// // ... 764 /// } 765 /// ``` 766 /// 767 /// Sub-scopes may be created to limit the duration for which the span is 768 /// entered: 769 /// 770 /// ``` 771 /// #[macro_use] extern crate tracing; 772 /// let span = info_span!("my_great_span"); 773 /// 774 /// { 775 /// let _enter = span.enter(); 776 /// 777 /// // this event occurs inside the span. 778 /// info!("i'm in the span!"); 779 /// 780 /// // exiting the scope drops the guard, exiting the span. 781 /// } 782 /// 783 /// // this event is not inside the span. 784 /// info!("i'm outside the span!") 785 /// ``` 786 /// 787 /// [`Subscriber::enter`]: ../subscriber/trait.Subscriber.html#method.enter 788 /// [`Subscriber::exit`]: ../subscriber/trait.Subscriber.html#method.exit 789 /// [`Id`]: ../struct.Id.html 790 #[inline] enter(&self) -> Entered<'_>791 pub fn enter(&self) -> Entered<'_> { 792 self.do_enter(); 793 Entered { span: self } 794 } 795 796 /// Enters this span, consuming it and returning a [guard][`EnteredSpan`] 797 /// that will exit the span when dropped. 798 /// 799 /// If this span is enabled by the current subscriber, then this function will 800 /// call [`Subscriber::enter`] with the span's [`Id`], and dropping the guard 801 /// will call [`Subscriber::exit`]. If the span is disabled, this does 802 /// nothing. 803 /// 804 /// This is similar to the [`Span::enter`] method, except that it moves the 805 /// span by value into the returned guard, rather than borrowing it. 806 /// Therefore, this method can be used to create and enter a span in a 807 /// single expression, without requiring a `let`-binding. For example: 808 /// 809 /// ``` 810 /// # use tracing::info_span; 811 /// let _span = info_span!("something_interesting").entered(); 812 /// ``` 813 /// rather than: 814 /// ``` 815 /// # use tracing::info_span; 816 /// let span = info_span!("something_interesting"); 817 /// let _e = span.enter(); 818 /// ``` 819 /// 820 /// Furthermore, `entered` may be used when the span must be stored in some 821 /// other struct or be passed to a function while remaining entered. 822 /// 823 /// <div class="information"> 824 /// <div class="tooltip ignore" style="">ⓘ<span class="tooltiptext">Note</span></div> 825 /// </div> 826 /// <div class="example-wrap" style="display:inline-block"> 827 /// <pre class="ignore" style="white-space:normal;font:inherit;"> 828 /// 829 /// **Note**: The returned [`EnteredSpan`] guard does not 830 /// implement `Send`. Dropping the guard will exit *this* span, 831 /// and if the guard is sent to another thread and dropped there, that thread may 832 /// never have entered this span. Thus, `EnteredSpan`s should not be sent 833 /// between threads. 834 /// 835 /// </pre></div> 836 /// 837 /// **Warning**: in asynchronous code that uses [async/await syntax][syntax], 838 /// [`Span::entered`] should be used very carefully or avoided entirely. Holding 839 /// the drop guard returned by `Span::entered` across `.await` points will 840 /// result in incorrect traces. See the documentation for the 841 /// [`Span::enter`] method for details. 842 /// 843 /// [syntax]: https://rust-lang.github.io/async-book/01_getting_started/04_async_await_primer.html 844 /// 845 /// # Examples 846 /// 847 /// The returned guard can be [explicitly exited][EnteredSpan::exit], 848 /// returning the un-entered span: 849 /// 850 /// ``` 851 /// # use tracing::{Level, span}; 852 /// let span = span!(Level::INFO, "doing_something").entered(); 853 /// 854 /// // code here is within the span 855 /// 856 /// // explicitly exit the span, returning it 857 /// let span = span.exit(); 858 /// 859 /// // code here is no longer within the span 860 /// 861 /// // enter the span again 862 /// let span = span.entered(); 863 /// 864 /// // now we are inside the span once again 865 /// ``` 866 /// 867 /// Guards need not be explicitly dropped: 868 /// 869 /// ``` 870 /// # use tracing::trace_span; 871 /// fn my_function() -> String { 872 /// // enter a span for the duration of this function. 873 /// let span = trace_span!("my_function").entered(); 874 /// 875 /// // anything happening in functions we call is still inside the span... 876 /// my_other_function(); 877 /// 878 /// // returning from the function drops the guard, exiting the span. 879 /// return "Hello world".to_owned(); 880 /// } 881 /// 882 /// fn my_other_function() { 883 /// // ... 884 /// } 885 /// ``` 886 /// 887 /// Since the [`EnteredSpan`] guard can dereference to the [`Span`] itself, 888 /// the span may still be accessed while entered. For example: 889 /// 890 /// ```rust 891 /// # use tracing::info_span; 892 /// use tracing::field; 893 /// 894 /// // create the span with an empty field, and enter it. 895 /// let span = info_span!("my_span", some_field = field::Empty).entered(); 896 /// 897 /// // we can still record a value for the field while the span is entered. 898 /// span.record("some_field", &"hello world!"); 899 /// ``` 900 /// 901 /// [`Subscriber::enter`]: ../subscriber/trait.Subscriber.html#method.enter 902 /// [`Subscriber::exit`]: ../subscriber/trait.Subscriber.html#method.exit 903 /// [`Id`]: ../struct.Id.html 904 #[inline] entered(self) -> EnteredSpan905 pub fn entered(self) -> EnteredSpan { 906 self.do_enter(); 907 EnteredSpan { 908 span: self, 909 _not_send: PhantomNotSend, 910 } 911 } 912 913 #[inline] do_enter(&self)914 fn do_enter(&self) { 915 if let Some(inner) = self.inner.as_ref() { 916 inner.subscriber.enter(&inner.id); 917 } 918 919 if_log_enabled! { crate::Level::TRACE, { 920 if let Some(ref meta) = self.meta { 921 self.log(ACTIVITY_LOG_TARGET, log::Level::Trace, format_args!("-> {}", meta.name())); 922 } 923 }} 924 } 925 926 // Called from [`Entered`] and [`EnteredSpan`] drops. 927 // 928 // Running this behaviour on drop rather than with an explicit function 929 // call means that spans may still be exited when unwinding. 930 #[inline] do_exit(&self)931 fn do_exit(&self) { 932 if let Some(inner) = self.inner.as_ref() { 933 inner.subscriber.exit(&inner.id); 934 } 935 936 if_log_enabled! { crate::Level::TRACE, { 937 if let Some(ref _meta) = self.meta { 938 self.log(ACTIVITY_LOG_TARGET, log::Level::Trace, format_args!("<- {}", _meta.name())); 939 } 940 }} 941 } 942 943 /// Executes the given function in the context of this span. 944 /// 945 /// If this span is enabled, then this function enters the span, invokes `f` 946 /// and then exits the span. If the span is disabled, `f` will still be 947 /// invoked, but in the context of the currently-executing span (if there is 948 /// one). 949 /// 950 /// Returns the result of evaluating `f`. 951 /// 952 /// # Examples 953 /// 954 /// ``` 955 /// # #[macro_use] extern crate tracing; 956 /// # use tracing::Level; 957 /// let my_span = span!(Level::TRACE, "my_span"); 958 /// 959 /// my_span.in_scope(|| { 960 /// // this event occurs within the span. 961 /// trace!("i'm in the span!"); 962 /// }); 963 /// 964 /// // this event occurs outside the span. 965 /// trace!("i'm not in the span!"); 966 /// ``` 967 /// 968 /// Calling a function and returning the result: 969 /// ``` 970 /// # use tracing::{info_span, Level}; 971 /// fn hello_world() -> String { 972 /// "Hello world!".to_owned() 973 /// } 974 /// 975 /// let span = info_span!("hello_world"); 976 /// // the span will be entered for the duration of the call to 977 /// // `hello_world`. 978 /// let a_string = span.in_scope(hello_world); 979 /// in_scope<F: FnOnce() -> T, T>(&self, f: F) -> T980 pub fn in_scope<F: FnOnce() -> T, T>(&self, f: F) -> T { 981 let _enter = self.enter(); 982 f() 983 } 984 985 /// Returns a [`Field`](../field/struct.Field.html) for the field with the 986 /// given `name`, if one exists, field<Q: ?Sized>(&self, field: &Q) -> Option<field::Field> where Q: field::AsField,987 pub fn field<Q: ?Sized>(&self, field: &Q) -> Option<field::Field> 988 where 989 Q: field::AsField, 990 { 991 self.metadata().and_then(|meta| field.as_field(meta)) 992 } 993 994 /// Returns true if this `Span` has a field for the given 995 /// [`Field`](../field/struct.Field.html) or field name. 996 #[inline] has_field<Q: ?Sized>(&self, field: &Q) -> bool where Q: field::AsField,997 pub fn has_field<Q: ?Sized>(&self, field: &Q) -> bool 998 where 999 Q: field::AsField, 1000 { 1001 self.field(field).is_some() 1002 } 1003 1004 /// Records that the field described by `field` has the value `value`. 1005 /// 1006 /// This may be used with [`field::Empty`] to declare fields whose values 1007 /// are not known when the span is created, and record them later: 1008 /// ``` 1009 /// use tracing::{trace_span, field}; 1010 /// 1011 /// // Create a span with two fields: `greeting`, with the value "hello world", and 1012 /// // `parting`, without a value. 1013 /// let span = trace_span!("my_span", greeting = "hello world", parting = field::Empty); 1014 /// 1015 /// // ... 1016 /// 1017 /// // Now, record a value for parting as well. 1018 /// // (note that the field name is passed as a string slice) 1019 /// span.record("parting", &"goodbye world!"); 1020 /// ``` 1021 /// However, it may also be used to record a _new_ value for a field whose 1022 /// value was already recorded: 1023 /// ``` 1024 /// use tracing::info_span; 1025 /// # fn do_something() -> Result<(), ()> { Err(()) } 1026 /// 1027 /// // Initially, let's assume that our attempt to do something is going okay... 1028 /// let span = info_span!("doing_something", is_okay = true); 1029 /// let _e = span.enter(); 1030 /// 1031 /// match do_something() { 1032 /// Ok(something) => { 1033 /// // ... 1034 /// } 1035 /// Err(_) => { 1036 /// // Things are no longer okay! 1037 /// span.record("is_okay", &false); 1038 /// } 1039 /// } 1040 /// ``` 1041 /// 1042 /// <div class="information"> 1043 /// <div class="tooltip ignore" style="">ⓘ<span class="tooltiptext">Note</span></div> 1044 /// </div> 1045 /// <div class="example-wrap" style="display:inline-block"> 1046 /// <pre class="ignore" style="white-space:normal;font:inherit;"> 1047 /// <strong>Note</strong>: The fields associated with a span are part of its 1048 /// <a href="../struct.Metadata.html"><code>Metadata</code></a>. 1049 /// The <a href="../struct.Metadata.html"><code>Metadata</code></a>. describing a particular 1050 /// span is constructed statically when the span is created and cannot be extended later to 1051 /// add new fields. Therefore, you cannot record a value for a field that was not specified 1052 /// when the span was created:</pre></div> 1053 /// 1054 /// ``` 1055 /// use tracing::{trace_span, field}; 1056 /// 1057 /// // Create a span with two fields: `greeting`, with the value "hello world", and 1058 /// // `parting`, without a value. 1059 /// let span = trace_span!("my_span", greeting = "hello world", parting = field::Empty); 1060 /// 1061 /// // ... 1062 /// 1063 /// // Now, you try to record a value for a new field, `new_field`, which was not 1064 /// // declared as `Empty` or populated when you created `span`. 1065 /// // You won't get any error, but the assignment will have no effect! 1066 /// span.record("new_field", &"interesting_value_you_really_need"); 1067 /// 1068 /// // Instead, all fields that may be recorded after span creation should be declared up front, 1069 /// // using field::Empty when a value is not known, as we did for `parting`. 1070 /// // This `record` call will indeed replace field::Empty with "you will be remembered". 1071 /// span.record("parting", &"you will be remembered"); 1072 /// ``` 1073 /// 1074 /// [`field::Empty`]: ../field/struct.Empty.html 1075 /// [`Metadata`]: ../struct.Metadata.html record<Q: ?Sized, V>(&self, field: &Q, value: &V) -> &Self where Q: field::AsField, V: field::Value,1076 pub fn record<Q: ?Sized, V>(&self, field: &Q, value: &V) -> &Self 1077 where 1078 Q: field::AsField, 1079 V: field::Value, 1080 { 1081 if let Some(ref meta) = self.meta { 1082 if let Some(field) = field.as_field(meta) { 1083 self.record_all( 1084 &meta 1085 .fields() 1086 .value_set(&[(&field, Some(value as &dyn field::Value))]), 1087 ); 1088 } 1089 } 1090 1091 self 1092 } 1093 1094 /// Records all the fields in the provided `ValueSet`. record_all(&self, values: &field::ValueSet<'_>) -> &Self1095 pub fn record_all(&self, values: &field::ValueSet<'_>) -> &Self { 1096 let record = Record::new(values); 1097 if let Some(ref inner) = self.inner { 1098 inner.record(&record); 1099 } 1100 1101 if let Some(ref _meta) = self.meta { 1102 if_log_enabled! { *_meta.level(), { 1103 let target = if record.is_empty() { 1104 LIFECYCLE_LOG_TARGET 1105 } else { 1106 _meta.target() 1107 }; 1108 self.log(target, level_to_log!(*_meta.level()), format_args!("{}{}", _meta.name(), FmtValues(&record))); 1109 }} 1110 } 1111 1112 self 1113 } 1114 1115 /// Returns `true` if this span was disabled by the subscriber and does not 1116 /// exist. 1117 /// 1118 /// See also [`is_none`]. 1119 /// 1120 /// [`is_none`]: #method.is_none 1121 #[inline] is_disabled(&self) -> bool1122 pub fn is_disabled(&self) -> bool { 1123 self.inner.is_none() 1124 } 1125 1126 /// Returns `true` if this span was constructed by [`Span::none`] and is 1127 /// empty. 1128 /// 1129 /// If `is_none` returns `true` for a given span, then [`is_disabled`] will 1130 /// also return `true`. However, when a span is disabled by the subscriber 1131 /// rather than constructed by `Span::none`, this method will return 1132 /// `false`, while `is_disabled` will return `true`. 1133 /// 1134 /// [`Span::none`]: #method.none 1135 /// [`is_disabled`]: #method.is_disabled 1136 #[inline] is_none(&self) -> bool1137 pub fn is_none(&self) -> bool { 1138 self.is_disabled() && self.meta.is_none() 1139 } 1140 1141 /// Indicates that the span with the given ID has an indirect causal 1142 /// relationship with this span. 1143 /// 1144 /// This relationship differs somewhat from the parent-child relationship: a 1145 /// span may have any number of prior spans, rather than a single one; and 1146 /// spans are not considered to be executing _inside_ of the spans they 1147 /// follow from. This means that a span may close even if subsequent spans 1148 /// that follow from it are still open, and time spent inside of a 1149 /// subsequent span should not be included in the time its precedents were 1150 /// executing. This is used to model causal relationships such as when a 1151 /// single future spawns several related background tasks, et cetera. 1152 /// 1153 /// If this span is disabled, or the resulting follows-from relationship 1154 /// would be invalid, this function will do nothing. 1155 /// 1156 /// # Examples 1157 /// 1158 /// Setting a `follows_from` relationship with a `Span`: 1159 /// ``` 1160 /// # use tracing::{span, Id, Level, Span}; 1161 /// let span1 = span!(Level::INFO, "span_1"); 1162 /// let span2 = span!(Level::DEBUG, "span_2"); 1163 /// span2.follows_from(span1); 1164 /// ``` 1165 /// 1166 /// Setting a `follows_from` relationship with the current span: 1167 /// ``` 1168 /// # use tracing::{span, Id, Level, Span}; 1169 /// let span = span!(Level::INFO, "hello!"); 1170 /// span.follows_from(Span::current()); 1171 /// ``` 1172 /// 1173 /// Setting a `follows_from` relationship with a `Span` reference: 1174 /// ``` 1175 /// # use tracing::{span, Id, Level, Span}; 1176 /// let span = span!(Level::INFO, "hello!"); 1177 /// let curr = Span::current(); 1178 /// span.follows_from(&curr); 1179 /// ``` 1180 /// 1181 /// Setting a `follows_from` relationship with an `Id`: 1182 /// ``` 1183 /// # use tracing::{span, Id, Level, Span}; 1184 /// let span = span!(Level::INFO, "hello!"); 1185 /// let id = span.id(); 1186 /// span.follows_from(id); 1187 /// ``` follows_from(&self, from: impl Into<Option<Id>>) -> &Self1188 pub fn follows_from(&self, from: impl Into<Option<Id>>) -> &Self { 1189 if let Some(ref inner) = self.inner { 1190 if let Some(from) = from.into() { 1191 inner.follows_from(&from); 1192 } 1193 } 1194 self 1195 } 1196 1197 /// Returns this span's `Id`, if it is enabled. id(&self) -> Option<Id>1198 pub fn id(&self) -> Option<Id> { 1199 self.inner.as_ref().map(Inner::id) 1200 } 1201 1202 /// Returns this span's `Metadata`, if it is enabled. metadata(&self) -> Option<&'static Metadata<'static>>1203 pub fn metadata(&self) -> Option<&'static Metadata<'static>> { 1204 self.meta 1205 } 1206 1207 #[cfg(feature = "log")] 1208 #[inline] log(&self, target: &str, level: log::Level, message: fmt::Arguments<'_>)1209 fn log(&self, target: &str, level: log::Level, message: fmt::Arguments<'_>) { 1210 if let Some(ref meta) = self.meta { 1211 if level_to_log!(*meta.level()) <= log::max_level() { 1212 let logger = log::logger(); 1213 let log_meta = log::Metadata::builder().level(level).target(target).build(); 1214 if logger.enabled(&log_meta) { 1215 if let Some(ref inner) = self.inner { 1216 logger.log( 1217 &log::Record::builder() 1218 .metadata(log_meta) 1219 .module_path(meta.module_path()) 1220 .file(meta.file()) 1221 .line(meta.line()) 1222 .args(format_args!("{}; span={}", message, inner.id.into_u64())) 1223 .build(), 1224 ); 1225 } else { 1226 logger.log( 1227 &log::Record::builder() 1228 .metadata(log_meta) 1229 .module_path(meta.module_path()) 1230 .file(meta.file()) 1231 .line(meta.line()) 1232 .args(message) 1233 .build(), 1234 ); 1235 } 1236 } 1237 } 1238 } 1239 } 1240 1241 /// Invokes a function with a reference to this span's ID and subscriber. 1242 /// 1243 /// if this span is enabled, the provided function is called, and the result is returned. 1244 /// If the span is disabled, the function is not called, and this method returns `None` 1245 /// instead. with_subscriber<T>(&self, f: impl FnOnce((&Id, &Dispatch)) -> T) -> Option<T>1246 pub fn with_subscriber<T>(&self, f: impl FnOnce((&Id, &Dispatch)) -> T) -> Option<T> { 1247 self.inner 1248 .as_ref() 1249 .map(|inner| f((&inner.id, &inner.subscriber))) 1250 } 1251 } 1252 1253 impl cmp::PartialEq for Span { eq(&self, other: &Self) -> bool1254 fn eq(&self, other: &Self) -> bool { 1255 match (&self.meta, &other.meta) { 1256 (Some(this), Some(that)) => { 1257 this.callsite() == that.callsite() && self.inner == other.inner 1258 } 1259 _ => false, 1260 } 1261 } 1262 } 1263 1264 impl Hash for Span { hash<H: Hasher>(&self, hasher: &mut H)1265 fn hash<H: Hasher>(&self, hasher: &mut H) { 1266 self.inner.hash(hasher); 1267 } 1268 } 1269 1270 impl fmt::Debug for Span { fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1271 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 1272 let mut span = f.debug_struct("Span"); 1273 if let Some(ref meta) = self.meta { 1274 span.field("name", &meta.name()) 1275 .field("level", &meta.level()) 1276 .field("target", &meta.target()); 1277 1278 if let Some(ref inner) = self.inner { 1279 span.field("id", &inner.id()); 1280 } else { 1281 span.field("disabled", &true); 1282 } 1283 1284 if let Some(ref path) = meta.module_path() { 1285 span.field("module_path", &path); 1286 } 1287 1288 if let Some(ref line) = meta.line() { 1289 span.field("line", &line); 1290 } 1291 1292 if let Some(ref file) = meta.file() { 1293 span.field("file", &file); 1294 } 1295 } else { 1296 span.field("none", &true); 1297 } 1298 1299 span.finish() 1300 } 1301 } 1302 1303 impl<'a> From<&'a Span> for Option<&'a Id> { from(span: &'a Span) -> Self1304 fn from(span: &'a Span) -> Self { 1305 span.inner.as_ref().map(|inner| &inner.id) 1306 } 1307 } 1308 1309 impl<'a> From<&'a Span> for Option<Id> { from(span: &'a Span) -> Self1310 fn from(span: &'a Span) -> Self { 1311 span.inner.as_ref().map(Inner::id) 1312 } 1313 } 1314 1315 impl From<Span> for Option<Id> { from(span: Span) -> Self1316 fn from(span: Span) -> Self { 1317 span.inner.as_ref().map(Inner::id) 1318 } 1319 } 1320 1321 impl<'a> From<&'a EnteredSpan> for Option<&'a Id> { from(span: &'a EnteredSpan) -> Self1322 fn from(span: &'a EnteredSpan) -> Self { 1323 span.inner.as_ref().map(|inner| &inner.id) 1324 } 1325 } 1326 1327 impl<'a> From<&'a EnteredSpan> for Option<Id> { from(span: &'a EnteredSpan) -> Self1328 fn from(span: &'a EnteredSpan) -> Self { 1329 span.inner.as_ref().map(Inner::id) 1330 } 1331 } 1332 1333 impl Drop for Span { drop(&mut self)1334 fn drop(&mut self) { 1335 if let Some(Inner { 1336 ref id, 1337 ref subscriber, 1338 }) = self.inner 1339 { 1340 subscriber.try_close(id.clone()); 1341 } 1342 1343 if let Some(ref _meta) = self.meta { 1344 if_log_enabled! { crate::Level::TRACE, { 1345 self.log( 1346 LIFECYCLE_LOG_TARGET, 1347 log::Level::Trace, 1348 format_args!("-- {}", _meta.name()), 1349 ); 1350 }} 1351 } 1352 } 1353 } 1354 1355 // ===== impl Inner ===== 1356 1357 impl Inner { 1358 /// Indicates that the span with the given ID has an indirect causal 1359 /// relationship with this span. 1360 /// 1361 /// This relationship differs somewhat from the parent-child relationship: a 1362 /// span may have any number of prior spans, rather than a single one; and 1363 /// spans are not considered to be executing _inside_ of the spans they 1364 /// follow from. This means that a span may close even if subsequent spans 1365 /// that follow from it are still open, and time spent inside of a 1366 /// subsequent span should not be included in the time its precedents were 1367 /// executing. This is used to model causal relationships such as when a 1368 /// single future spawns several related background tasks, et cetera. 1369 /// 1370 /// If this span is disabled, this function will do nothing. Otherwise, it 1371 /// returns `Ok(())` if the other span was added as a precedent of this 1372 /// span, or an error if this was not possible. follows_from(&self, from: &Id)1373 fn follows_from(&self, from: &Id) { 1374 self.subscriber.record_follows_from(&self.id, &from) 1375 } 1376 1377 /// Returns the span's ID. id(&self) -> Id1378 fn id(&self) -> Id { 1379 self.id.clone() 1380 } 1381 record(&self, values: &Record<'_>)1382 fn record(&self, values: &Record<'_>) { 1383 self.subscriber.record(&self.id, values) 1384 } 1385 new(id: Id, subscriber: &Dispatch) -> Self1386 fn new(id: Id, subscriber: &Dispatch) -> Self { 1387 Inner { 1388 id, 1389 subscriber: subscriber.clone(), 1390 } 1391 } 1392 } 1393 1394 impl cmp::PartialEq for Inner { eq(&self, other: &Self) -> bool1395 fn eq(&self, other: &Self) -> bool { 1396 self.id == other.id 1397 } 1398 } 1399 1400 impl Hash for Inner { hash<H: Hasher>(&self, state: &mut H)1401 fn hash<H: Hasher>(&self, state: &mut H) { 1402 self.id.hash(state); 1403 } 1404 } 1405 1406 impl Clone for Inner { clone(&self) -> Self1407 fn clone(&self) -> Self { 1408 Inner { 1409 id: self.subscriber.clone_span(&self.id), 1410 subscriber: self.subscriber.clone(), 1411 } 1412 } 1413 } 1414 1415 // ===== impl Entered ===== 1416 1417 impl EnteredSpan { 1418 /// Returns this span's `Id`, if it is enabled. id(&self) -> Option<Id>1419 pub fn id(&self) -> Option<Id> { 1420 self.inner.as_ref().map(Inner::id) 1421 } 1422 1423 /// Exits this span, returning the underlying [`Span`]. 1424 #[inline] exit(mut self) -> Span1425 pub fn exit(mut self) -> Span { 1426 // One does not simply move out of a struct with `Drop`. 1427 let span = mem::replace(&mut self.span, Span::none()); 1428 span.do_exit(); 1429 span 1430 } 1431 } 1432 1433 impl Deref for EnteredSpan { 1434 type Target = Span; 1435 1436 #[inline] deref(&self) -> &Span1437 fn deref(&self) -> &Span { 1438 &self.span 1439 } 1440 } 1441 1442 impl<'a> Drop for Entered<'a> { 1443 #[inline] drop(&mut self)1444 fn drop(&mut self) { 1445 self.span.do_exit() 1446 } 1447 } 1448 1449 impl Drop for EnteredSpan { 1450 #[inline] drop(&mut self)1451 fn drop(&mut self) { 1452 self.span.do_exit() 1453 } 1454 } 1455 1456 /// Technically, `EnteredSpan` _can_ implement both `Send` *and* 1457 /// `Sync` safely. It doesn't, because it has a `PhantomNotSend` field, 1458 /// specifically added in order to make it `!Send`. 1459 /// 1460 /// Sending an `EnteredSpan` guard between threads cannot cause memory unsafety. 1461 /// However, it *would* result in incorrect behavior, so we add a 1462 /// `PhantomNotSend` to prevent it from being sent between threads. This is 1463 /// because it must be *dropped* on the same thread that it was created; 1464 /// otherwise, the span will never be exited on the thread where it was entered, 1465 /// and it will attempt to exit the span on a thread that may never have entered 1466 /// it. However, we still want them to be `Sync` so that a struct holding an 1467 /// `Entered` guard can be `Sync`. 1468 /// 1469 /// Thus, this is totally safe. 1470 #[derive(Debug)] 1471 struct PhantomNotSend { 1472 ghost: PhantomData<*mut ()>, 1473 } 1474 1475 #[allow(non_upper_case_globals)] 1476 const PhantomNotSend: PhantomNotSend = PhantomNotSend { ghost: PhantomData }; 1477 1478 /// # Safety 1479 /// 1480 /// Trivially safe, as `PhantomNotSend` doesn't have any API. 1481 unsafe impl Sync for PhantomNotSend {} 1482 1483 #[cfg(feature = "log")] 1484 struct FmtValues<'a>(&'a Record<'a>); 1485 1486 #[cfg(feature = "log")] 1487 impl<'a> fmt::Display for FmtValues<'a> { fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1488 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 1489 let mut res = Ok(()); 1490 let mut is_first = true; 1491 self.0.record(&mut |k: &field::Field, v: &dyn fmt::Debug| { 1492 res = write!(f, "{} {}={:?}", if is_first { ";" } else { "" }, k, v); 1493 is_first = false; 1494 }); 1495 res 1496 } 1497 } 1498 1499 #[cfg(feature = "log")] 1500 struct FmtAttrs<'a>(&'a Attributes<'a>); 1501 1502 #[cfg(feature = "log")] 1503 impl<'a> fmt::Display for FmtAttrs<'a> { fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result1504 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { 1505 let mut res = Ok(()); 1506 let mut is_first = true; 1507 self.0.record(&mut |k: &field::Field, v: &dyn fmt::Debug| { 1508 res = write!(f, "{} {}={:?}", if is_first { ";" } else { "" }, k, v); 1509 is_first = false; 1510 }); 1511 res 1512 } 1513 } 1514 1515 #[cfg(test)] 1516 mod test { 1517 use super::*; 1518 1519 trait AssertSend: Send {} 1520 impl AssertSend for Span {} 1521 1522 trait AssertSync: Sync {} 1523 impl AssertSync for Span {} 1524 impl AssertSync for Entered<'_> {} 1525 impl AssertSync for EnteredSpan {} 1526 } 1527