Observing the runtime

The runtime records what it did and how long it took: every host op, every timer, every turn of the loop, plus spans you open yourself.

There are two ways to get at it. Pick by where you want the data to go.

Send it to a collector

esrun --otel app.js

That is the whole change. Your program does not know it is being traced.

GET                        (SERVER, trace 6341c455)
├─ fs_write   ./o.txt
├─ fs_remove  ./o.txt
└─ http_respond

fetch  http://…/api/users  (CLIENT, trace 3bf2e15b)

An inbound request becomes a SERVER span with the work it caused nested under it; an outbound fetch becomes a CLIENT span in its own trace. Attributes follow the semantic conventions, so a backend labels them without a mapping: file.path, db.query.text, url.full, http.request.method, url.path.

esrun --otel=http://collector:4318 \
      --otel-service=checkout \
      --otel-min-duration=5 \
      --otel-sample=0.01 app.js

A trivial request produces around twenty spans, most of them microsecond-long pure computation, so a production exporter usually wants the last two.

Read them in your program

import { subscribe } from "runtime:diagnostics";

const sub = subscribe({ kinds: ["op"], minDuration: 10 }, ({ records }) => {
  for (const r of records) console.log(r.name, (r.endedAt - r.startedAt).toFixed(1), "ms");
});

Two grants, two disclosures

esrun --allow-diagnostics app.js         # timings, kinds, counts
esrun --allow-diagnostics-detail app.js  # …plus paths, URLs, SQL text

Observability is gated even though it never leaves the isolate, because it is authority over the rest of your program: anything that can subscribe learns every filesystem call, query and request you make.

A profiler runs on the narrower grant and sees full timings with empty payloads. Which one a subscription gets is decided by the host, not claimed by the caller.

Was it slow, or did it wait?

The question timings alone cannot answer. Every record names the loop turn it landed in, and a tick record gives that turn its own timings:

subscribe({}, ({ records }) => {
  const turns = new Map(records.filter((r) => r.kind === "tick").map((r) => [r.tick, r]));
  for (const r of records) {
    const turn = turns.get(r.tick);
    if (!turn || r.kind === "tick") continue;
    const self = r.endedAt - r.startedAt;
    const whole = turn.endedAt - turn.startedAt;
    if (self > 20 && whole - self > 50) console.warn(`${r.name} waited: ${whole - self}ms of other work`);
    else if (self > 20) console.warn(`${r.name} was slow: ${self}ms`);
  }
});

A 40ms span in a 45ms turn was slow. The same span in a 400ms turn was sharing the turn with something else.

Queue delay means one thing

Keeping the volume down

subscribe({
  kinds: ["op"],      // only host ops
  minDuration: 5,     // only what took a while
  sample: 0.01,       // 1% of traces — whole traces, never half of one
  bufferSize: 512,    // per subscription
}, onBatch);

All four are applied in the host. A record your filter rejects is never built, so narrowing a filter genuinely costs less rather than moving the work.

Sampling is per trace, computed from the trace id: a trace is kept whole or dropped whole. Half a trace is worse than none.

subscribe({}, ({ records, dropped }) => {
  if (dropped) console.warn(`lost ${dropped}`);
});

Your own spans

Two forms. The one with a callback is active, so the work inside becomes its children:

import { span } from "runtime:diagnostics";

// Nests: every query and file read inside `charge()` becomes a child.
await span("checkout", { attributes: { plan: "pro" } }, () => charge());

// Measures: times a region, nests nothing.
const s = span("checkout");
try { await charge(); s.end(); } catch (e) { s.fail(); throw e; }

User spans share the runtime's id space and timeline, so they line up with the ops underneath them. source: "user" tells them apart. attributes are recorded only under diagnostics-detail. Ending twice records once.

Following one request

Records nest, so you can read a trace as a tree rather than a list:

subscribe({}, ({ records }) => {
  const byId = new Map(records.map((r) => [r.id, r]));
  for (const r of records) {
    const depth = (function d(x, n = 0) {
      const p = byId.get(x.parentId);
      return p ? d(p, n + 1) : n;
    })(r);
    console.log(`${"  ".repeat(depth)}${r.kind}/${r.name}`);
  }
});

parentId names the span a record ran inside — the async scope, not the call stack, so an op six awaits deep inside a request still nests under it. Nesting is independent of filtering: { kinds: ["op"] } still gets ops parented to the request that caused them.

For the task that scheduled something — Node's triggerAsyncId — use currentTask().parentId from runtime:context. Two sibling ops in one request share a parent span but have different parent tasks.

Loop health

import { metrics } from "runtime:diagnostics";

const m = metrics();
if (m.tickDurationMs.p99 > 100) console.warn("turns are long — something is blocking");

metrics() is pull-only — poll it from a timer or expose it on a health endpoint.

A large loopLagMs with a small tickDurationMs is an idle process, which is fine. A large one with a large tickDurationMs is a loop that cannot keep up.

gc is in this table and not one of its own because a GC pause is lag: the isolate is stopped for the whole of one, so a collection shows up in loopLagMs with nothing else to explain it.

const m = metrics();
// Was the loop stopped, or merely idle?
const stopped = m.gc.pauseMs.p99;
const lag = m.loopLagMs.p99;

Counted per isolate, so a worker's collections are its own and do not move its parent's count.

Memory and CPU

A health endpoint usually wants both halves — what this agent is doing, and what the process around it is doing:

import { cpuTime, memoryUsage, uptime } from "runtime:process";
import { metrics } from "runtime:diagnostics";

const mine = { heap: memoryUsage().heapUsed, cpu: cpuTime(), up: uptime() };
const all = metrics().process; // { rss, cpu, uptime }

The per-agent half needs no grant because it reports only what the caller could find out about itself anyway — by allocating until it is stopped, or by counting. rss is the number a container's memory limit is compared against, so it is the one that decides whether the process is killed.

The split matters most in a worker. A worker is its own isolate and its own OS thread, so cpuTime() there answers "is it me burning the CPU?" — which the process-wide figure cannot:

// parent: idle while the worker computes
cpuTime();            // small
metrics().process.cpu; // large — the worker's time is in here

What handles are open

import { inventory } from "runtime:diagnostics";
inventory().handles;
// [{ kind: "socket", count: 12, ids: [3, 4, …] }]

The host handles this agent owns — an id and a kind, never the resource. Useful for finding a leak: a count that only grows is one.

Trace ids

Records carry the trace from runtime:context, so a span joins the request that caused it:

import { currentTask } from "runtime:context";
subscribe({}, ({ records }) => {
  for (const r of records) if (r.traceId === currentTask().traceId) console.log(r.name);
});

The dependency runs one way. No context value ever reaches a record.

See Internals: diagnostics for what it costs, and the API reference for signatures.