Debug a page in production

You'll read a request back as one tree: which loader waited on which service, what ran at the same time as what, which cache answered. First from the dev server with no Rust at all, then from the binary you actually deploy, where the endpoint you just used doesn't exist.

cargo install snapfire_compiler
cargo install snapfire_fsr_cli
fsr --version

Turn it on by starting the server

Nothing to install. fsr dev and fsr serve install the trace collector themselves for a development host and say so in the banner:

$ fsr dev shop/app
fsr server on http://127.0.0.1:3000/
fsr traces on http://127.0.0.1:3000/__fsr/traces

No second line means no collector, which happens when the host isn't a development one. That's server.dev in your configuration, which defaults to whether RELEASE_ENV is development.

Read one request

The endpoint answers a JSON array, one entry per trace, each with id, ms and a flat spans list. Every span carries its own depth, so laying it out as a tree is the reader's job:

$ curl -s localhost:3000/__fsr/traces | jq '.[-1].spans[] | {name, ms, outcome, fields}'
request 19.92ms ok {"method": "GET", "path": "/product/9", "status": "200"}
  source 16.25ms ok {"id": "layout", "memo": "miss", "node": "1"}
  source 16.60ms ok {"id": "product.$id", "node": "2"}
    call 15.99ms ok {"service": "catalog", "method": "getProduct"}
    call 15.54ms ok {"service": "pricing", "method": "quote"}
  render 1.37ms {"module": "shell#document"}
    render 1.16ms {"module": "routes/layout.tsx#default"}
      render 0.10ms {"module": "routes/product/[id]/page.tsx#default", "cache": "miss"}

Four things are in there that no set of log lines gives you.

The two service calls sit under the loader that made them, so you know which loader is waiting on which backend rather than guessing from timing.

Both loaders took about sixteen milliseconds inside a request that took twenty, so they ran together. Had they run one after the other the request would have been thirty-three.

Rendering the whole tree cost 1.37ms against sixteen spent waiting, which says the page is slow because of a backend and not because of the render.

Two different caches report themselves in two different fields. A source span carries memo: hit or memo: miss when that loader is memoizable; a render span carries cache: hit or cache: miss when the render cache was consulted for that node. A node you expected to be cached that says miss on every request is the bug; it's invisible from the outside because the page is correct, just expensive.

Request the page a second time and the render subtree gets shorter rather than faster. A cache: hit high in the tree means the nodes beneath it were never rendered, so they have no spans at all. A subtree that disappears between two traces is the cache working.

The four spans

Only request, source and call set an outcome. A render span has none, so read its cache field rather than looking for ok on it.

Anything you open yourself with tracing joins whichever request it's inside, so a span around your own slow function appears nested in the tree with no extra wiring.

Now do it in production

Two things change at once. The endpoint isn't registered on a production host, because what a source cost is nothing a client should be able to read. And the process isn't the fsr binary: 410 copies target/release/shop into the tree, so the thing serving is yours and it installs nothing on its own.

That binary is small. This is the whole of it, with the collector wired:

[package]
name = "shop"
version = "0.1.0"
edition = "2024"

[dependencies]
snapfire_fsr_host = "0"
tokio = { version = "1", features = ["macros", "rt-multi-thread"] }

use std::path::Path;
use std::sync::Arc;

use snapfire_fsr_host::Host;

#[tokio::main]
async fn main() -> std::io::Result<()> {
  let logging = Path::new(env!("CARGO_MANIFEST_DIR")).join("fibre_logging.yaml");
  let (traces, _logging, why) = snapfire_fsr_host::trace::observe(&logging);
  if let Some(why) = why {
    eprintln!("logging: {why}");
  }

  let host = Host::from(env!("CARGO_MANIFEST_DIR"))
    .and_then(|builder| builder.traces(traces.clone()).build())
    .map_err(std::io::Error::other)?;

  print!("{}", host.report());
  let listen = host.listen().to_owned();
  Arc::new(host).serve(&listen).await
}

observe composes two layers on one registry: fibre_logging taking events out to its appenders and the collector keeping each request's spans. They're different jobs and neither replaces the other. Hold _logging, because its Drop flushes the appenders and binding it to _ loses the tail of your log on every exit. A missing or unreadable fibre_logging.yaml isn't fatal: the collector is installed alone and the reason comes back as the third value.

With no endpoint to read, traces leave through a listener:

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

Every finished trace is handed to each listener as its root closes, before the ring. That's also the only place tail sampling can happen, because deciding to keep the slow ones and the failed ones needs the finished trace; anything sampling when a span opens hasn't seen it yet.

traces.on_finish(|trace| {
  if trace.duration.as_millis() > 500 || trace.root().and_then(|s| s.outcome()) != Some("ok") {
    exporter.send(trace);
  }
});

A listener runs on the thread that closed the root, so a slow one delays that request's close. Send to a channel and do the work elsewhere; don't do a blocking HTTP post in there.

trace::server_timing(&trace) formats one trace as a Server-Timing header value, which puts per-step cost in browser devtools. Nothing in the host sends it, so that one is for an application that wants to attach it to its own responses.

What it costs with no collector

With no collector installed a span is a relaxed atomic load and a branch. No allocation, no field formatting. So the instrumentation stays in release builds and whether anything collects is a separate decision, made in main rather than at compile time.

The ring holds the last 256 traces in memory, about a kilobyte each; /__fsr/traces returns the last fifty of them, newest last. Nothing is written to disk and nothing leaves the process until you wire an exporter.

No collector to deploy

No collector to run, no agent beside the process, no sampling config and no second deployment. The spans are in every build already. Under fsr dev the server keeps them for you; in your own binary two lines in main decide who does.

Next up: 130. Move a loader into Rust.