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