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