Expand description
Spans represent periods of time in which a program was executing in aparticular context.
A span consists offields, user-defined key-value pairs of arbitrary datathat describe the context the span represents, and a set of fixed attributesthat describe alltracing
spans and events. Attributes describing spansinclude:
- An
Id
assigned by the subscriber that uniquely identifies it in relationto other spans. - The span’sparent in the trace tree.
- Metadata that describes static characteristics of all spansoriginating from that callsite, such as its name, source code location,verbosity level, and the names of its fields.
§Creating Spans
Spans are created using thespan!
macro. This macro is invoked with thefollowing arguments, in order:
- The
target
and/orparent
attributes, if the user wishes tooverride their default values. - The span’sverbosity level
- A string literal providing the span’s name.
- Finally, zero or more arbitrary key/value fields.
For example:
usetracing::{span, Level};/// Construct a new span at the `INFO` level named "my_span", with a single/// field named answer , with the value `42`.letmy_span =span!(Level::INFO,"my_span", answer =42);
The documentation for thespan!
macro provides additional examples ofthe various options that exist when creating spans.
Thetrace_span!
,debug_span!
,info_span!
,warn_span!
, anderror_span!
exist as shorthand for constructing spans at variousverbosity levels.
§Recording Span Creation
TheAttributes
type contains data associated with a span, and isprovided to theSubscriber
when a new span is created. It containsthe span’s metadata, the ID ofthe span’s parent if one wasexplicitly set, and any fields whose values were recorded when the span wasconstructed. The subscriber, which is responsible for recordingtracing
data, can then store or record these values.
§The Span Lifecycle
§Entering a Span
A thread of execution is said toenter a span when it begins executing,andexit the span when it switches to another context. Spans may beentered through theenter
,entered
, andin_scope
methods.
Theenter
method enters a span, returning aguard that exits the spanwhen dropped
letmy_var: u64 =5;letmy_span =span!(Level::TRACE,"my_span", my_var);// `my_span` exists but has not been entered.// Enter `my_span`...let_enter = my_span.enter();// Perform some work inside of the context of `my_span`...// Dropping the `_enter` guard will exit the span.
Warning: In asynchronous code that uses async/await syntax,Span::enter
may produce incorrect traces if the returned drop guard is held across an await point. Seethe method documentation for details.
Theentered
method is analogous toenter
, but moves the span intothe returned guard, rather than borrowing it. This allows creating andentering a span in a single expression:
// Create a span and enter it, returning a guard:letspan =span!(Level::INFO,"my_span").entered();// We are now inside the span! Like `enter()`, the guard returned by// `entered()` will exit the span when it is dropped...// ...but, it can also be exited explicitly, returning the `Span`// struct:letspan = span.exit();
Finally,in_scope
takes a closure or function pointer and executes itinside the span:
letmy_var: u64 =5;letmy_span =span!(Level::TRACE,"my_span", my_var =&my_var);my_span.in_scope(|| {// perform some work in the context of `my_span`...});// Perform some work outside of the context of `my_span`...my_span.in_scope(|| {// Perform some more work in the context of `my_span`.});
Note: Since entering a span takes&self
, andSpan
s areClone
,Send
, andSync
, it is entirely valid for multiple threads to enter the same span concurrently.
§Span Relationships
Spans form a tree structure — unless it is a root span, all spans have aparent, and may have one or morechildren. When a new span is created,the current span becomes the new span’s parent. The total execution time ofa span consists of the time spent in that span and in the entire subtreerepresented by its children. Thus, a parent span always lasts for at leastas long as the longest-executing span in its subtree.
// this span is considered the "root" of a new trace tree:span!(Level::INFO,"root").in_scope(|| {// since we are now inside "root", this span is considered a child // of "root":span!(Level::DEBUG,"outer_child").in_scope(|| {// this span is a child of "outer_child", which is in turn a // child of "root":span!(Level::TRACE,"inner_child").in_scope(|| {// and so on...}); });// another span created here would also be a child of "root".});
In addition, the parent of a span may be explicitly specified inthespan!
macro. For example:
// Create, but do not enter, a span called "foo".letfoo =span!(Level::INFO,"foo");// Create and enter a span called "bar".letbar =span!(Level::INFO,"bar");let_enter = bar.enter();// Although we have currently entered "bar", "baz"'s parent span// will be "foo".letbaz =span!(parent:&foo, Level::INFO,"baz");
A child span should typically be consideredpart of its parent. Forexample, if a subscriber is recording the length of time spent in variousspans, it should generally include the time spent in a span’s children aspart of that span’s duration.
In addition to having zero or one parent, a span may alsofollow from anynumber of other spans. This indicates a causal relationship between the spanand the spans that it follows from, but a follower isnot typicallyconsidered part of the duration of the span it follows. Unlike the parent, aspan may record that it follows from another span after it is created, usingthefollows_from
method.
As an example, consider a listener task in a server. As the listener acceptsincoming connections, it spawns new tasks that handle those connections. Wemight want to have a span representing the listener, and instrument eachspawned handler task with its own span. We would want our instrumentation torecord that the handler tasks were spawned as a result of the listener task.However, we might not consider the handler tasks to bepart of the timespent in the listener task, so we would not consider those spans children ofthe listener span. Instead, we would record that the handler tasks followfrom the listener, recording the causal relationship but treating the spansas separate durations.
§Closing Spans
Execution may enter and exit a span multiple times before that span isclosed. Consider, for example, a future which has an associatedspan and enters that span every time it is polled:
structMyFuture {// dataspan: tracing::Span,}implFutureforMyFuture {typeOutput = ();fnpoll(self: Pin<&mutSelf>, _cx:&mutContext<'_>) -> Poll<Self::Output> {let_enter =self.span.enter();// Do actual future work...}}
If this future was spawned on an executor, it might yield one or more timesbeforepoll
returnsPoll::Ready
. If the future were to yield, thenthe executor would move on to poll the next future, which mayalso enteran associated span or series of spans. Therefore, it is valid for a span tobe entered repeatedly before it completes. Only the time when that span orone of its children was the current span is considered to be time spent inthat span. A span which is not executing and has not yet been closed is saidto beidle.
Because spans may be entered and exited multiple times before they close,Subscriber
s have separate trait methods which are called to notify themof span exits and when span handles are dropped. When execution exits aspan,exit
will always be called with that span’s ID to notify thesubscriber that the span has been exited. When span handles are dropped, thedrop_span
method is called with that span’s ID. The subscriber may usethis to determine whether or not the span will be entered again.
If there is only a single handle with the capacity to exit a span, droppingthat handle “closes” the span, since the capacity to enter it no longerexists. For example:
{span!(Level::TRACE,"my_span").in_scope(|| {// perform some work in the context of `my_span`...});// --> Subscriber::exit(my_span) // The handle to `my_span` only lives inside of this block; when it is // dropped, the subscriber will be informed via `drop_span`.}// --> Subscriber::drop_span(my_span)
However, if multiple handles exist, the span can still be re-entered even ifone or more is dropped. For determining whenall handles to a span havebeen dropped,Subscriber
s have aclone_span
method, which is calledevery time a span handle is cloned. Combined withdrop_span
, this may beused to track the number of handles to a given span — ifdrop_span
hasbeen called one more time than the number of calls toclone_span
for agiven ID, then no more handles to the span with that ID exist. Thesubscriber may then treat it as closed.
§When to use spans
As a rule of thumb, spans should be used to represent discrete units of work(e.g., a given request’s lifetime in a server) or periods of time spent in agiven context (e.g., time spent interacting with an instance of an externalsystem, such as a database).
Which scopes in a program correspond to new spans depend somewhat on userintent. For example, consider the case of a loop in a program. Should weconstruct one span and perform the entire loop inside of that span, like:
letspan =span!(Level::TRACE,"my_loop");let_enter = span.enter();foriin0..n {// ...}
Or, should we create a new span for each iteration of the loop, as in:
foriin0..n {letspan =span!(Level::TRACE,"my_loop", iteration = i);let_enter = span.enter();// ...}
Depending on the circumstances, we might want to do either, or both. Forexample, if we want to know how long was spent in the loop overall, we wouldcreate a single span around the entire loop; whereas if we wanted to know howmuch time was spent in each individual iteration, we would enter a new spanon every iteration.
Structs§
- Attributes
- Attributes provided to a
Subscriber
describing a new span when it iscreated. - Entered
- A guard representing a span which has been entered and is currentlyexecuting.
- Entered
Span - An owned version of
Entered
, a guard representing a span which has beenentered and is currently executing. - Id
- Identifies a span within the context of a subscriber.
- Record
- A set of fields recorded by a span.
- Span
- A handle representing a span, with the capability to enter the span if itexists.
Traits§
- AsId
- Trait implemented by types which have a span
Id
.