Advanced · for everyone

What a request did

A request is one object

A log line is one fact. Ten of them from one request are ten facts you reassemble by hand, interleaved with every other request in flight. A trace is the request itself: every step it took, nested the way it nested, each with its own cost.

tracing does not give you one back. Spans go to a subscriber and nothing returns, which is right when the destination is a file and wrong here. So the host keeps them.

The host sets it up

You do not wire tracing yourself. snapfire_fsr_host::trace owns the whole arrangement, because every application wants the same lines:

rust
let logging = Path::new(env!("CARGO_MANIFEST_DIR")).join("fibre_logging.yaml");
let (traces, _logging, why) = snapfire_fsr_host::trace::observe(&logging);

let host = Host::from(env!("CARGO_MANIFEST_DIR"))
  .and_then(|builder| builder.traces(traces).build())?;

observe composes two different jobs on one registry: fibre_logging taking the events out to its appenders, and fibre_tracing keeping the spans. Neither replaces the other.

Three things come back. traces is the handle, and it is an Option because something else may already own the global dispatcher, in which case no trace is kept and that is not an error. _logging is a guard you have to hold, since dropping it flushes the appenders. why is the reason the logging configuration could not be read, if it could not: the collector is installed alone and the application still traces.

If the host already logs through tracing's default there is install(), and if a layer already owns the events there is install_with(layer). observe is the pair you want.

Reading one

The host answers GET /__fsr/traces with the last fifty, newest last. Development only: what a source cost is nothing a production client should read.

text
request 19.92ms ok GET /agents
  source layout 16.25ms ok
  source agents.layout 16.60ms ok
    call fleet.listAlerts 15.99ms ok
    call fleet.listAgents 15.54ms ok
  render shell#document 1.37ms
    render routes/layout.tsx#default 1.16ms
      render routes/agents/layout.tsx#default 0.82ms miss
        render routes/agents/page.tsx#default 0.10ms miss

The shape of the page is in the indentation. Both loaders took about sixteen milliseconds inside a request that took twenty, so they ran together rather than one after the other. Each service call sits under the loader waiting on it, so you know which loader is blocked on which backend. Rendering the whole tree cost one and a half milliseconds against sixteen spent waiting, which tells you where to look and where not to. The miss on the last two says the render memo had nothing for them.

The four spans

SpanOne perSays
requestrequest, the rootmethod, path, status, whether it succeeded
sourceplan node with a loaderwhich source, and whether it failed
callservice method, whatever the transportservice, method, and the failure kind
renderplan nodethe module, and whether the memo hit

A failure names its kind rather than a raw status, because the kind is what your code branches on. Anything you open with tracing yourself joins whichever request it is inside.

What it costs when nobody is watching

With no collector installed a span is a relaxed atomic load and a branch: no allocation, no formatting of fields. Leave the instrumentation in production builds and decide separately whether anything collects it. The ring holds the last few hundred traces in memory at roughly a kilobyte each, which is the whole storage story until you want more.

Getting them out

Nothing leaves the process on its own. A listener runs as each request finishes:

rust
traces.on_finish(|trace| exporter.send(trace));

That is also the only place tail sampling can happen, keeping what failed or ran long and dropping the rest, because the decision needs the finished trace. Anything that samples when a span opens has not seen it yet.

The lab

Load a page, fetch /__fsr/traces and find that request. Now make one service method sleep for half a second and load the page again: the request grows by roughly that, one source span grows with it and the call span underneath names the method that did it. The other loader is unchanged, which is the parallelism showing itself. Then load the same page twice without changing anything and compare the render spans: the second says hit where the first said miss.

Built with SnapFire FSR. Pure Rust runtime, zero Node.js on the server.