edlang/tracing/span/index.html

241 lines
24 KiB
HTML
Raw Normal View History

<!DOCTYPE html><html lang="en"><head><meta charset="utf-8"><meta name="viewport" content="width=device-width, initial-scale=1.0"><meta name="generator" content="rustdoc"><meta name="description" content="Spans represent periods of time in which a program was executing in a particular context."><title>tracing::span - Rust</title><link rel="preload" as="font" type="font/woff2" crossorigin href="../../static.files/SourceSerif4-Regular-46f98efaafac5295.ttf.woff2"><link rel="preload" as="font" type="font/woff2" crossorigin href="../../static.files/FiraSans-Regular-018c141bf0843ffd.woff2"><link rel="preload" as="font" type="font/woff2" crossorigin href="../../static.files/FiraSans-Medium-8f9a781e4970d388.woff2"><link rel="preload" as="font" type="font/woff2" crossorigin href="../../static.files/SourceCodePro-Regular-562dcc5011b6de7d.ttf.woff2"><link rel="preload" as="font" type="font/woff2" crossorigin href="../../static.files/SourceCodePro-Semibold-d899c5a5c4aeb14a.ttf.woff2"><link rel="stylesheet" href="../../static.files/normalize-76eba96aa4d2e634.css"><link rel="stylesheet" href="../../static.files/rustdoc-ac92e1bbe349e143.css"><meta name="rustdoc-vars" data-root-path="../../" data-static-root-path="../../static.files/" data-current-crate="tracing" data-themes="" data-resource-suffix="" data-rustdoc-version="1.76.0 (07dca489a 2024-02-04)" data-channel="1.76.0" data-search-js="search-2b6ce74ff89ae146.js" data-settings-js="settings-4313503d2e1961c2.js" ><script src="../../static.files/storage-f2adc0d6ca4d09fb.js"></script><script defer src="../sidebar-items.js"></script><script defer src="../../static.files/main-305769736d49e732.js"></script><noscript><link rel="stylesheet" href="../../static.files/noscript-feafe1bb7466e4bd.css"></noscript><link rel="alternate icon" type="image/png" href="../../static.files/favicon-16x16-8b506e7a72182f1c.png"><link rel="alternate icon" type="image/png" href="../../static.files/favicon-32x32-422f7d1d52889060.png"><link rel="icon" type="image/svg+xml" href="../../static.files/favicon-2c020d218678b618.svg"></head><body class="rustdoc mod"><!--[if lte IE 11]><div class="warning">This old browser is unsupported and will most likely display funky things.</div><![endif]--><nav class="mobile-topbar"><button class="sidebar-menu-toggle">&#9776;</button><a class="logo-container" href="../../tracing/index.html"><img src="https://raw.githubusercontent.com/tokio-rs/tracing/master/assets/logo-type.png" alt=""></a></nav><nav class="sidebar"><div class="sidebar-crate"><a class="logo-container" href="../../tracing/index.html"><img src="https://raw.githubusercontent.com/tokio-rs/tracing/master/assets/logo-type.png" alt="logo"></a><h2><a href="../../tracing/index.html">tracing</a><span class="version">0.1.40</span></h2></div><h2 class="location"><a href="#">Module span</a></h2><div class="sidebar-elems"><section><ul class="block"><li><a href="#structs">Structs</a></li><li><a href="#traits">Traits</a></li></ul></section><h2><a href="../index.html">In crate tracing</a></h2></div></nav><div class="sidebar-resizer"></div>
<main><div class="width-limiter"><nav class="sub"><form class="search-form"><span></span><div id="sidebar-button" tabindex="-1"><a href="../../tracing/all.html" title="show sidebar"></a></div><input class="search-input" name="search" aria-label="Run search in the documentation" autocomplete="off" spellcheck="false" placeholder="Click or press S to search, ? for more options…" type="search"><div id="help-button" tabindex="-1"><a href="../../help.html" title="help">?</a></div><div id="settings-menu" tabindex="-1"><a href="../../settings.html" title="settings"><img width="22" height="22" alt="Change settings" src="../../static.files/wheel-7b819b6101059cd0.svg"></a></div></form></nav><section id="main-content" class="content"><div class="main-heading"><h1>Module <a href="../index.html">tracing</a>::<wbr><a class="mod" href="#">span</a><button id="copy-path" title="Copy item path to clipboard"><img src="../../static.files/clipboard-7571035ce49a181d.svg" width="19" height="18" alt="Copy item path"></button></h1><span class="out-of-band"><a class="src" href="../../src/tracing/span.rs.html#1-1623">source</a> · <button id="toggle-all-docs" title="collapse all docs">[<span>&#x2212;</span>]</button></span></div><details class="toggle top-doc" open><summary class="hideme"><span>Expand description</span></summary><div class="docblock"><p>Spans represent periods of time in which a program was executing in a
particular context.</p>
<p>A span consists of <a href="../field/index.html" title="mod tracing::field">fields</a>, user-defined key-value pairs of arbitrary data
that describe the context the span represents, and a set of fixed attributes
that describe all <code>tracing</code> spans and events. Attributes describing spans
include:</p>
<ul>
<li>An <a href="struct.Id.html" title="struct tracing::span::Id"><code>Id</code></a> assigned by the subscriber that uniquely identifies it in relation
to other spans.</li>
<li>The spans <a href="#span-relationships">parent</a> in the trace tree.</li>
<li><a href="../struct.Metadata.html" title="struct tracing::Metadata">Metadata</a> that describes static characteristics of all spans
originating from that callsite, such as its name, source code location,
<a href="../struct.Level.html" title="struct tracing::Level">verbosity level</a>, and the names of its fields.</li>
</ul>
<h2 id="creating-spans"><a href="#creating-spans">Creating Spans</a></h2>
<p>Spans are created using the <a href="../macro.span.html" title="macro tracing::span"><code>span!</code></a> macro. This macro is invoked with the
following arguments, in order:</p>
<ul>
<li>The <a href="../struct.Metadata.html#method.target" title="method tracing::Metadata::target"><code>target</code></a> and/or <a href="#span-relationships"><code>parent</code></a> attributes, if the user wishes to
override their default values.</li>
<li>The spans <a href="../struct.Level.html" title="struct tracing::Level">verbosity level</a></li>
<li>A string literal providing the spans name.</li>
<li>Finally, zero or more arbitrary key/value fields.</li>
</ul>
<p>For example:</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="kw">use </span>tracing::{span, Level};
<span class="doccomment">/// Construct a new span at the `INFO` level named "my_span", with a single
/// field named answer , with the value `42`.
</span><span class="kw">let </span>my_span = <span class="macro">span!</span>(Level::INFO, <span class="string">"my_span"</span>, answer = <span class="number">42</span>);</code></pre></div>
<p>The documentation for the <a href="../macro.span.html" title="macro tracing::span"><code>span!</code></a> macro provides additional examples of
the various options that exist when creating spans.</p>
<p>The <a href="../macro.trace_span.html" title="macro tracing::trace_span"><code>trace_span!</code></a>, <a href="../macro.debug_span.html" title="macro tracing::debug_span"><code>debug_span!</code></a>, <a href="../macro.info_span.html" title="macro tracing::info_span"><code>info_span!</code></a>, <a href="../macro.warn_span.html" title="macro tracing::warn_span"><code>warn_span!</code></a>, and
<a href="../macro.error_span.html" title="macro tracing::error_span"><code>error_span!</code></a> exist as shorthand for constructing spans at various
verbosity levels.</p>
<h3 id="recording-span-creation"><a href="#recording-span-creation">Recording Span Creation</a></h3>
<p>The <a href="struct.Attributes.html" title="struct tracing::span::Attributes"><code>Attributes</code></a> type contains data associated with a span, and is
provided to the <a href="../trait.Subscriber.html" title="trait tracing::Subscriber"><code>Subscriber</code></a> when a new span is created. It contains
the spans metadata, the ID of <a href="#span-relationships">the spans parent</a> if one was
explicitly set, and any fields whose values were recorded when the span was
constructed. The subscriber, which is responsible for recording <code>tracing</code>
data, can then store or record these values.</p>
<h2 id="the-span-lifecycle"><a href="#the-span-lifecycle">The Span Lifecycle</a></h2><h3 id="entering-a-span"><a href="#entering-a-span">Entering a Span</a></h3>
<p>A thread of execution is said to <em>enter</em> a span when it begins executing,
and <em>exit</em> the span when it switches to another context. Spans may be
entered through the <a href="../struct.Span.html#method.enter" title="method tracing::Span::enter"><code>enter</code></a>, <a href="../struct.Span.html#method.entered" title="method tracing::Span::entered"><code>entered</code></a>, and <a href="../struct.Span.html#method.in_scope" title="method tracing::Span::in_scope"><code>in_scope</code></a> methods.</p>
<p>The <a href="../struct.Span.html#method.enter" title="method tracing::Span::enter"><code>enter</code></a> method enters a span, returning a <a href="struct.Entered.html" title="struct tracing::span::Entered">guard</a> that exits the span
when dropped</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="kw">let </span>my_var: u64 = <span class="number">5</span>;
<span class="kw">let </span>my_span = <span class="macro">span!</span>(Level::TRACE, <span class="string">"my_span"</span>, my_var);
<span class="comment">// `my_span` exists but has not been entered.
// Enter `my_span`...
</span><span class="kw">let </span>_enter = my_span.enter();
<span class="comment">// Perform some work inside of the context of `my_span`...
// Dropping the `_enter` guard will exit the span.</span></code></pre></div>
<div class="example-wrap" style="display:inline-block"><pre class="compile_fail" style="white-space:normal;font:inherit;">
<strong>Warning</strong>: In asynchronous code that uses async/await syntax,
<code>Span::enter</code> may produce incorrect traces if the returned drop
guard is held across an await point. See
<a href="struct.Span.html#in-asynchronous-code">the method documentation</a>
for details.
</pre></div>
<p>The <a href="../struct.Span.html#method.entered" title="method tracing::Span::entered"><code>entered</code></a> method is analogous to <a href="../struct.Span.html#method.enter" title="method tracing::Span::enter"><code>enter</code></a>, but moves the span into
the returned guard, rather than borrowing it. This allows creating and
entering a span in a single expression:</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="comment">// Create a span and enter it, returning a guard:
</span><span class="kw">let </span>span = <span class="macro">span!</span>(Level::INFO, <span class="string">"my_span"</span>).entered();
<span class="comment">// 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:
</span><span class="kw">let </span>span = span.exit();</code></pre></div>
<p>Finally, <a href="../struct.Span.html#method.in_scope" title="method tracing::Span::in_scope"><code>in_scope</code></a> takes a closure or function pointer and executes it
inside the span:</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="kw">let </span>my_var: u64 = <span class="number">5</span>;
<span class="kw">let </span>my_span = <span class="macro">span!</span>(Level::TRACE, <span class="string">"my_span"</span>, my_var = <span class="kw-2">&amp;</span>my_var);
my_span.in_scope(|| {
<span class="comment">// perform some work in the context of `my_span`...
</span>});
<span class="comment">// Perform some work outside of the context of `my_span`...
</span>my_span.in_scope(|| {
<span class="comment">// Perform some more work in the context of `my_span`.
</span>});</code></pre></div>
<pre class="ignore" style="white-space:normal;font:inherit;">
<strong>Note</strong>: Since entering a span takes <code>&self</code>, and
<code>Span</code>s are <code>Clone</code>, <code>Send</code>, and
<code>Sync</code>, it is entirely valid for multiple threads to enter the
same span concurrently.
</pre>
<h3 id="span-relationships"><a href="#span-relationships">Span Relationships</a></h3>
<p>Spans form a tree structure — unless it is a root span, all spans have a
<em>parent</em>, and may have one or more <em>children</em>. When a new span is created,
the current span becomes the new spans parent. The total execution time of
a span consists of the time spent in that span and in the entire subtree
represented by its children. Thus, a parent span always lasts for at least
as long as the longest-executing span in its subtree.</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="comment">// this span is considered the "root" of a new trace tree:
</span><span class="macro">span!</span>(Level::INFO, <span class="string">"root"</span>).in_scope(|| {
<span class="comment">// since we are now inside "root", this span is considered a child
// of "root":
</span><span class="macro">span!</span>(Level::DEBUG, <span class="string">"outer_child"</span>).in_scope(|| {
<span class="comment">// this span is a child of "outer_child", which is in turn a
// child of "root":
</span><span class="macro">span!</span>(Level::TRACE, <span class="string">"inner_child"</span>).in_scope(|| {
<span class="comment">// and so on...
</span>});
});
<span class="comment">// another span created here would also be a child of "root".
</span>});</code></pre></div>
<p>In addition, the parent of a span may be explicitly specified in
the <code>span!</code> macro. For example:</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="comment">// Create, but do not enter, a span called "foo".
</span><span class="kw">let </span>foo = <span class="macro">span!</span>(Level::INFO, <span class="string">"foo"</span>);
<span class="comment">// Create and enter a span called "bar".
</span><span class="kw">let </span>bar = <span class="macro">span!</span>(Level::INFO, <span class="string">"bar"</span>);
<span class="kw">let </span>_enter = bar.enter();
<span class="comment">// Although we have currently entered "bar", "baz"'s parent span
// will be "foo".
</span><span class="kw">let </span>baz = <span class="macro">span!</span>(parent: <span class="kw-2">&amp;</span>foo, Level::INFO, <span class="string">"baz"</span>);</code></pre></div>
<p>A child span should typically be considered <em>part</em> of its parent. For
example, if a subscriber is recording the length of time spent in various
spans, it should generally include the time spent in a spans children as
part of that spans duration.</p>
<p>In addition to having zero or one parent, a span may also <em>follow from</em> any
number of other spans. This indicates a causal relationship between the span
and the spans that it follows from, but a follower is <em>not</em> typically
considered part of the duration of the span it follows. Unlike the parent, a
span may record that it follows from another span after it is created, using
the <a href="../struct.Span.html#method.follows_from" title="method tracing::Span::follows_from"><code>follows_from</code></a> method.</p>
<p>As an example, consider a listener task in a server. As the listener accepts
incoming connections, it spawns new tasks that handle those connections. We
might want to have a span representing the listener, and instrument each
spawned handler task with its own span. We would want our instrumentation to
record that the handler tasks were spawned as a result of the listener task.
However, we might not consider the handler tasks to be <em>part</em> of the time
spent in the listener task, so we would not consider those spans children of
the listener span. Instead, we would record that the handler tasks follow
from the listener, recording the causal relationship but treating the spans
as separate durations.</p>
<h3 id="closing-spans"><a href="#closing-spans">Closing Spans</a></h3>
<p>Execution may enter and exit a span multiple times before that span is
<em>closed</em>. Consider, for example, a future which has an associated
span and enters that span every time it is polled:</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="kw">struct </span>MyFuture {
<span class="comment">// data
</span>span: tracing::Span,
}
<span class="kw">impl </span>Future <span class="kw">for </span>MyFuture {
<span class="kw">type </span>Output = ();
<span class="kw">fn </span>poll(<span class="self">self</span>: Pin&lt;<span class="kw-2">&amp;mut </span><span class="self">Self</span>&gt;, _cx: <span class="kw-2">&amp;mut </span>Context&lt;<span class="lifetime">'_</span>&gt;) -&gt; Poll&lt;<span class="self">Self</span>::Output&gt; {
<span class="kw">let </span>_enter = <span class="self">self</span>.span.enter();
<span class="comment">// Do actual future work...
</span>}
}</code></pre></div>
<p>If this future was spawned on an executor, it might yield one or more times
before <code>poll</code> returns <a href="https://doc.rust-lang.org/1.76.0/core/task/poll/enum.Poll.html#variant.Ready" title="variant core::task::poll::Poll::Ready"><code>Poll::Ready</code></a>. If the future were to yield, then
the executor would move on to poll the next future, which may <em>also</em> enter
an associated span or series of spans. Therefore, it is valid for a span to
be entered repeatedly before it completes. Only the time when that span or
one of its children was the current span is considered to be time spent in
that span. A span which is not executing and has not yet been closed is said
to be <em>idle</em>.</p>
<p>Because spans may be entered and exited multiple times before they close,
<a href="../trait.Subscriber.html" title="trait tracing::Subscriber"><code>Subscriber</code></a>s have separate trait methods which are called to notify them
of span exits and when span handles are dropped. When execution exits a
span, <a href="../trait.Subscriber.html#tymethod.exit" title="method tracing::Subscriber::exit"><code>exit</code></a> will always be called with that spans ID to notify the
subscriber that the span has been exited. When span handles are dropped, the
<a href="../trait.Subscriber.html#method.drop_span" title="method tracing::Subscriber::drop_span"><code>drop_span</code></a> method is called with that spans ID. The subscriber may use
this to determine whether or not the span will be entered again.</p>
<p>If there is only a single handle with the capacity to exit a span, dropping
that handle “closes” the span, since the capacity to enter it no longer
exists. For example:</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code>{
<span class="macro">span!</span>(Level::TRACE, <span class="string">"my_span"</span>).in_scope(|| {
<span class="comment">// perform some work in the context of `my_span`...
</span>}); <span class="comment">// --&gt; 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`.
</span>} <span class="comment">// --&gt; Subscriber::drop_span(my_span)</span></code></pre></div>
<p>However, if multiple handles exist, the span can still be re-entered even if
one or more is dropped. For determining when <em>all</em> handles to a span have
been dropped, <code>Subscriber</code>s have a <a href="../trait.Subscriber.html#method.clone_span" title="method tracing::Subscriber::clone_span"><code>clone_span</code></a> method, which is called
every time a span handle is cloned. Combined with <code>drop_span</code>, this may be
used to track the number of handles to a given span — if <code>drop_span</code> has
been called one more time than the number of calls to <code>clone_span</code> for a
given ID, then no more handles to the span with that ID exist. The
subscriber may then treat it as closed.</p>
<h2 id="when-to-use-spans"><a href="#when-to-use-spans">When to use spans</a></h2>
<p>As a rule of thumb, spans should be used to represent discrete units of work
(e.g., a given requests lifetime in a server) or periods of time spent in a
given context (e.g., time spent interacting with an instance of an external
system, such as a database).</p>
<p>Which scopes in a program correspond to new spans depend somewhat on user
intent. For example, consider the case of a loop in a program. Should we
construct one span and perform the entire loop inside of that span, like:</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="kw">let </span>span = <span class="macro">span!</span>(Level::TRACE, <span class="string">"my_loop"</span>);
<span class="kw">let </span>_enter = span.enter();
<span class="kw">for </span>i <span class="kw">in </span><span class="number">0</span>..n {
<span class="comment">// ...
</span>}</code></pre></div>
<p>Or, should we create a new span for each iteration of the loop, as in:</p>
<div class="example-wrap"><pre class="rust rust-example-rendered"><code><span class="kw">for </span>i <span class="kw">in </span><span class="number">0</span>..n {
<span class="kw">let </span>span = <span class="macro">span!</span>(Level::TRACE, <span class="string">"my_loop"</span>, iteration = i);
<span class="kw">let </span>_enter = span.enter();
<span class="comment">// ...
</span>}</code></pre></div>
<p>Depending on the circumstances, we might want to do either, or both. For
example, if we want to know how long was spent in the loop overall, we would
create a single span around the entire loop; whereas if we wanted to know how
much time was spent in each individual iteration, we would enter a new span
on every iteration.</p>
</div></details><h2 id="structs" class="section-header"><a href="#structs">Structs</a></h2><ul class="item-table"><li><div class="item-name"><a class="struct" href="struct.Attributes.html" title="struct tracing::span::Attributes">Attributes</a></div><div class="desc docblock-short">Attributes provided to a <code>Subscriber</code> describing a new span when it is
created.</div></li><li><div class="item-name"><a class="struct" href="struct.Entered.html" title="struct tracing::span::Entered">Entered</a></div><div class="desc docblock-short">A guard representing a span which has been entered and is currently
executing.</div></li><li><div class="item-name"><a class="struct" href="struct.EnteredSpan.html" title="struct tracing::span::EnteredSpan">EnteredSpan</a></div><div class="desc docblock-short">An owned version of <a href="struct.Entered.html" title="struct tracing::span::Entered"><code>Entered</code></a>, a guard representing a span which has been
entered and is currently executing.</div></li><li><div class="item-name"><a class="struct" href="struct.Id.html" title="struct tracing::span::Id">Id</a></div><div class="desc docblock-short">Identifies a span within the context of a subscriber.</div></li><li><div class="item-name"><a class="struct" href="struct.Record.html" title="struct tracing::span::Record">Record</a></div><div class="desc docblock-short">A set of fields recorded by a span.</div></li><li><div class="item-name"><a class="struct" href="struct.Span.html" title="struct tracing::span::Span">Span</a></div><div class="desc docblock-short">A handle representing a span, with the capability to enter the span if it
exists.</div></li></ul><h2 id="traits" class="section-header"><a href="#traits">Traits</a></h2><ul class="item-table"><li><div class="item-name"><a class="trait" href="trait.AsId.html" title="trait tracing::span::AsId">AsId</a></div><div class="desc docblock-short">Trait implemented by types which have a span <code>Id</code>.</div></li></ul></section></div></main></body></html>