Tracing

Tracing records the path of one message: every flow it entered, every block it passed through, every model call made on its behalf, and the source that admitted it, all joined by a single id that survives every boundary the message crosses.

Why it exists

Neither of the runtime's other two ways of watching itself answers "what happened to this message". Metrics are aggregates whose labels all come from the config and never from message data, so they can tell you a flow is failing but never which message failed. Spies record everything about one block, but only under octo invoke. A trace is the missing middle: per-message, on live traffic, and joined end to end.

Turning it on

octo run --config app.yaml --traces

That writes octo-trace-<time>-<pid>.jsonl into the working directory. Pick a path with --traces-file, and read it with anything that speaks JSON Lines:

octo run --config app.yaml --traces --traces-file /tmp/run.jsonl
jq -c '{seq,kind,traceId,flow,path,durationNs}' /tmp/run.jsonl

A run that did not ask for traces creates no file and logs nothing.

Tracing one flow, and a whole test suite

The same flags work on octo invoke, which runs a single flow and exits:

octo invoke --config app.yaml --flow orders --data '{"orderId":"A-1"}' \
  --traces --traces-file /tmp/orders.jsonl

And dolphin will run a whole suite that way, one file per case:

dolphin test orders_test.yaml --traces-dir ./traces

That is the cheapest way to find out what a flow's messages actually look like: the cases already say how to exercise it, and the mocks they carry mean nothing real is called. Each case's trace lands at <suite>.<n>.trace.jsonl beside the others.

What a trace looks like

One HTTP request through a flow that delegates to two others, one fire-and-forget and one synchronous, is one trace:

seq  kind               flow           path
1    flow.started       orders-api
2    block.pre-invoke   orders-api     orders-api.dump-inbound
3    block.post-invoke  orders-api     orders-api.dump-inbound
6    block.pre-invoke   orders-api     orders-api.audit-async
9    flow.started       audit                                     ← one-way flow-ref
11   flow.started       enrich-order                              ← sync flow-ref
12   block.pre-invoke   enrich-order   enrich-order.normalize-order
15   block.pre-invoke   enrich-order   enrich-order.priority-check[then].set-variable
21   flow.completed     enrich-order
23   flow.completed     audit
28   flow.completed     orders-api

Every one of those records carries the same traceId. The audit flow's records interleave with enrich-order's because it really is running concurrently.

seq totally orders the records one runtime produced. It is unique and gapless at the point of publication, but the stream is not necessarily written in seq order: a publisher stamps the number and then queues the record, so sort by it rather than assuming it is already sorted. A gap in seq means records were lost, and the stream says so in band. See Dropped records.

Record kinds

What a model call cost

Every call the runtime makes to a provider, blocking or streamed, chat or embedding, produces one record with the tokens that call was billed for and the model that served it. Summing them by traceId tells you what a single execution spent. The runtime reports tokens, not money: prices change faster than a runtime release cycle, so pricing is the reader's job, and the record carries everything that lookup needs.

usage is the same shape an ai-agent's turn_end event reports, so the two observers of one call cannot disagree about what it cost.

A record with no usage means the provider reported none. For a chat turn that is a failure, and the record carries error instead. For an embedding it is routine: Gemini's embeddings API returns no token count at all. Either way the absence is reported as absence, not as a zero that would read as "free".

# What did this run spend, per block and model? Both kinds, since a flow that
# embeds and then reasons pays for both. `out` is simply null for an
# embedding, which has no output to bill.
jq -c 'select(.kind=="llm.turn" or .kind=="llm.embed") |
  {kind, path, model: .attrs.model,
   in: .attrs.usage.inputTokens, out: .attrs.usage.outputTokens}' \
  /tmp/run.jsonl

The trace id

The id is minted once, by whoever sees the work first (a source, or the flow boundary) and everything downstream joins it rather than starting its own. It survives every boundary the runtime has. EventID is re-minted whenever work crosses into a sub-invocation, so it cannot be the thread; the trace id can:

It rides in the message's variables under a reserved, internal name, so it is stripped from anything user-facing (octo invoke output, spy dumps) and cannot collide with a variable of your own. It is not readable from CEL, because it exists only while tracing is on.

Cost, and turning it down

The defaults are tuned for "I am watching this run", not for production:

llm.turn and llm.embed are recorded per model call, not per block, and a model call is a network round trip, so their cost is not measurable next to the call they describe. With tracing off they add one atomic load and do not even read the clock.

Two ways to make it cheaper:

# Record the sequence without payloads.
octo run --config app.yaml --traces --traces-bodies=false --traces-vars=false

# Trace only the blocks you care about, in the same grammar --spies accepts.
octo run --config app.yaml --traces \
  --traces-blocks 'orders.charge,orders.fanout[audit].log-it'

Payloads are on by default because "what did the message look like here" is the question tracing exists to answer. A body over --traces-max-payload (32 KiB) is omitted whole and flagged truncated, never cut short, because a JSON document sliced at a byte boundary would break every reader after it in the stream.

Dropped records

Records are queued and drained by a goroutine of the tracer's own. If that queue fills, records are dropped rather than blocking the flow, because tracing must never put a flow worker behind a disk write.

A dropped record is never silent. The stream carries a trace.dropped marker naming how many were lost, and the gap is also visible as a jump in seq.

Raise --traces-buffer if you are losing records in bursts; narrow --traces-blocks if you are losing them steadily.

Where traces go

The destination is the runtime services module's choice, not a flag, the same way queues are in-process for one module, NATS subjects for another, and long polls against your own server for the third:

The file is flushed whenever the runtime goes idle, so you can tail -f it during a run, and synced on a graceful stop.

In a deployment

A deployed pod passes no arguments, since the image's CMD stands, so tracing is enabled through the environment instead. Every flag's default is the variable of the same meaning:

OCTO_TRACING=true
OCTO_TRACING_BODIES=false
OCTO_TRACING_BLOCKS=orders.charge

On the platform you do not set the first one by hand: Trace this deployment in the deploy and rollout dialogs is a per-deployment setting that supplies it. The other two narrow what is captured and are bound as ordinary env vars.

All of them are read from the process environment only, not from a .env file: they are resolved when octo run parses its flags, before any config is loaded. That is why the setting reaches a live deployment through a rollout, since a pod has to start with it.

What the pod publishes is then stored and queryable. See Traces for how records are kept, what a model call is priced at, how to tell an unpriced call from a free one, and the API over all of it.

octo invoke never traces, because it starts no hosted services, which is also why test suites are unaffected by any of this.