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