Internals: diagnostics

How runtime:diagnostics records a span, what it costs, and the things it refuses to report.

For signatures see the API reference; for the patterns, the guide.

The gate is an integer compare

The recorder holds the union of every live subscription's wanted kinds as a bitmask. A recording site tests it before it reads a clock, allocates a name, or takes an id:

  op dispatched
    └▶ recorder.wants(Op)?  ──no──▶ nothing. no clock, no allocation, no JS.
         └yes─▶ open span ─▶ run the op ─▶ close span ─▶ ring buffer

With nothing subscribed the mask is zero. This is the whole difference from node:async_hooks, which calls into JS for every async resource and cannot stop doing so once enabled.

Delivery is once per subscription per turn, never once per record. The test for that is a counter on the delivery binding rather than a timing measurement, because the claim is categorical rather than statistical.

What it costs, measured

One op in a loop — performance.now(), which does no I/O, so what is measured is the recording path rather than a syscall. The first row is the claim above: with nothing subscribed there is a mask test and then nothing at all.

--otel sits alongside a subscription rather than above it, because the encode and the hand-off are on the loop and the delivery is not.

No resource, ever

A record carries an id, a name, a kind and four numbers. It never carries the object. Exposing the raw handle is what pinned objects, perturbed GC, and froze an internal representation into public API — the reason async_hooks could not be fixed afterwards. There is no destroy event and no finalizer dependency either; a span has a deterministic end or it is not recorded.

inventory() is the one place handles are named, and it names ids, from the registries the per-agent ownership check already maintains.

How a record knows its parent

parentId names the span a record ran inside, in the same id space as id. It used to name a task, from runtime:context's separate counter — so a record could claim a parent that did not exist, and a set of records was a flat list no backend could nest.

The enclosing span rides in the async capture, beside the mapping and the trace. That is the whole mechanism, and it needed no new propagation: a capture already follows work across every await, timer and op callback, so an op issued six continuations deep inside a request still nests under it.

  request span opened ──▶ capture.span = 12
      handler yields   ──▶ promise stamped with capture (span 12)
      continuation     ──▶ capture restored, span 12 current
        fs_write       ──▶ parentId = 12

Two consequences worth stating:

• Nesting is not filtering. A span id is allocated whenever anything is recording, not when its own kind is wanted — otherwise { kinds: ["op"] } produced a flat list, because the request span it should have nested under was never given an id.

• A handle is not active. Only a scoped span(name, options, fn) makes itself current. The first implementation made the handle active and a test caught it nesting the caller's next op under a callee's span: calling an async function runs its body on the caller's stack up to the first await, so a span made active there is still active when control returns. That is the enterWith failure in a different costume.

Exporting, and who is allowed to

--otel makes the runtime export. The alternative — a package in userland calling subscribe() and POSTing — would have required granting application code net to reach the collector and diagnostics to read the program's own traces: exactly the two powers the capability model exists to withhold, granted in order to observe it.

  recorder ─▶ host subscription ─▶ OTLP encoder ─▶ TelemetrySink ─▶ collector
             (never reaches JS)     (in runtime)    (a provider)

The sink is transport only. What a span means is runtime knowledge; where the bytes go is deployment knowledge, which is why that seam is one method and not a telemetry SDK.

Three things only measurement found: fetch's span carried url.full: "GET" (the generic "first string argument" rule picks the method there, so ops can now name the right one); the root trace was erased by the per-turn context reset, so every record outside a request was unexportable; and Unix nanoseconds computed in f64 rounded every timestamp to ~128ns, because 1.7e18 is well past the 2^53 an f64 holds exactly.

What replaced worker

The module was designed around a field this runtime cannot fill. The premise was a bounded pool with a CPU offload tier, so a record could say worker: "cpu:3" and a reader could tell "slow" from "waited behind a CPU-bound task".

None of that exists here. TaskSpawner is defined in the provider traits and called nowhere in the runtime; the only real offload is spawn_blocking inside two providers; and there is a standing decision against routing CPU work through TaskSpawn, because it is a capability and gating it would break deny-by-default.

The conclusion survives anyway, because this is a driven loop: the embedder owns tick(), so there is an exact turn boundary. Every record names its turn, and a tick record gives the turn its own timings. A 40ms span in a 45ms turn was slow; the same span in a 400ms turn was waiting. No other runtime can report this, because no other runtime hands the turn boundary to the embedder.

If a CPU tier ever lands, worker slots in beside tick without changing the record shape.

One meaning for three timestamps

So startedAt - scheduledAt is always queue delay.

For a timer, "became runnable" is its deadline. Using the arming time would fold the delay you asked for into the field and make it read as lag when it is mostly sleep. The deadline is reconstructed from the engine's clock while the scheduler anchors it at the reading taken when the turn began, so a firing can look a fraction of a millisecond early; queue delay is a duration, so that artefact is clamped rather than reported as negative.

For an op there is no boundary. The future is polled eagerly at dispatch and the provider's internals are behind a trait boundary, so the host cannot point at a moment and call it "started". The two timestamps are equal, which says "no queue is visible here". The alternative — instrumenting the provider traits so spawn_blocking queueing became visible — would change a public interface every embedder implements, to observe queueing in two providers.

Sampling without state

Per trace, never per record: half a trace is worse than none. The decision is computed by hashing the trace id rather than cached, so there is no table to evict — and evicting one mid-trace is exactly the half-trace the rule exists to prevent. A record belonging to no trace is always kept.

Two rules the implementation argued with

Both were specified, and both changed under a failing test.

A tick record is never dropped, though everything else is drop-newest. The first overflow test burned a turn by busy-waiting on performance.now() — which is an op — and produced 18,190 records in one turn, 14,094 of them dropped. The casualty was the turn's own record, because it is emitted last. Drop-newest was chosen so a span's end is never delivered without its start; completed spans have no such pairs to break, and in an overloaded turn the tick record is the one that explains the overload. Reserving it makes the loss self-describing.

close() delivers what is buffered, then stops. Delivery is per turn, so a subscriber closing inside one silently lost everything recorded in it — usually the work it had subscribed to watch.

Where it lives

The recorder is in engine, because the things worth recording — op dispatch, timer firing, the turn boundary — happen there. The ops are in runtime, because that is where every capability check in this runtime lives; a builtin would reach the recorder with no gate at all. The engine hands out the recorder rather than wrapping it in a method per operation, since an op handler is a closure with no way back to the engine that registered it.

Whether a subscription sees payloads is decided host-side: two ops do the same work behind different gates and the module tries the wider one first. A boolean argument would let JavaScript claim what it was not granted.

The dependency on runtime:context

One-directional, and it is one field: a record carries the trace the work belongs to. Nothing goes the other way — no context value lives on a record, passes through the ring, or is reachable from any export here. A test greps a full record dump for a context value to keep it that way.

The trace id moved out of the context mapping and into the capture beside it, for this module's sake: a record is attributed on the recording path, and reaching into an opaque JS value per span is the JS-on-the-hot-path the design refuses. runtime:context still mints it and pushes it down, so there is one source of truth rather than a host copy that drifts.

Not done

Source positions. There is no origin field and no resolveOrigin, by decision. A record says what ran and on what (name, plus file.path / db.query.text / url.full under detail); it does not say which line of your code issued it.

The only way to know a line is a JS stack frame, and measurement put that at ~1.5µs per span even for a single unformatted frame — an order of magnitude more than the rest of a span costs. No other runtime provides it either: Deno's auto-instrumented spans carry no code.filepath, and OpenTelemetry's own convention for auto-instrumentation is a good name plus attributes. If it comes back it will be a per-subscription flag, so the cost lands on whoever asked.

Microtask spans. The highest-volume and lowest-value kind; tick already attributes a continuation to its turn.

worker, pool saturation, and link.traceparent — all waiting on a scheduler that may never exist.

OTLP metrics and logs. Only traces are exported; metrics() is readable in-process but is not shipped. Protobuf, for the same reason as above.

Memory, CPU and GC. The runtime reports nothing about its own heap, its CPU time or its collections — see the gap named on the loop metrics above, which covers the loop and nothing else. Notably, this runtime enforces a heap ceiling and gives no way to observe approaching it.

See D89 for the decision record.