Timing

std/timing is the scoped-duration primitive for Harn scripts. It replaces hand-rolled let started_ms = harness.clock.now_ms() subtraction with a first-class observability span that carries trace identifiers, monotonic duration, wall-clock start/end, status, attributes, and sub-phase events.

Use a timing segment when duration matters. Use a metric when you want a pre-aggregated numeric series. Use a span attribute when the value belongs on the current span instead of a new one.

import { timed } from "std/timing"

pipeline default() {
  let outcome = timed("benchmark.agent_loop", {case_id: "python-add"}, { ->
    return repair_agent(task)
  })
  __io_println("duration_ms=${outcome.timing.duration_ms}")
  return outcome.result
}

timed is the docs-forward shape because the callback cannot forget to close. The imperative pair is still available for flows that cross callbacks, branches, or async-ish lifecycle boundaries:

import { start_timing, timing_event, end_timing } from "std/timing"

pipeline default() {
  let timing = start_timing("provider.preflight", {provider: "ollama"})
  timing_event(timing, "credentials.checked", {available: true})
  timing_event(timing, "model.warm", {cache: "hit"})
  let result = preflight()
  let finished = end_timing(timing, {status: "ok"})
  return {result: result, duration_ms: finished.duration_ms}
}

TimingSegment shape

The dict returned from timed(...).timing and end_timing(...) looks like:

{
  name: "benchmark.agent_loop",
  trace_id: "trace_...",
  span_id: 42,
  parent_span_id: 41,                // nil at the trace root
  kind: "user_timing",
  started_at_ms: 1700000000123,      // wall-clock millis (UNIX epoch)
  monotonic_started_ms: 12345,       // for elapsed checks via elapsed_ms(...)
  ended_at_ms: 1700000000188,
  duration_ms: 65,
  status: "ok",                      // "ok" | "error" | custom
  attributes: {case_id: "python-add"},
  metadata: {case_id: "python-add", status: "ok"},
  events: [                          // present when timing_event(...) ran
    {name: "checkpoint", offset_ms: 4, time_unix_ms: 0, attributes: {}}
  ]
}

duration_ms is always derived from the monotonic clock, so it stays deterministic under mock_time(...) / advance_time(...). Wall-clock fields (started_at_ms, ended_at_ms) honor the mock as well, so testbench fixtures that pin wall time align with timing output.

Sub-phase events

timing_event(handle, name, attrs?) records a sub-phase annotation on the open span without allocating a child span for every marker. Events ride along with the parent span — they show up in timing.events after end_timing, in trace_spans() output, and in OTel exports as native span events. Returns true when the event was attached, false when the handle is already closed.

Duplicate close is idempotent

Calling end_timing(handle) twice returns the cached segment from the first close instead of corrupting the active span stack. This lets defensive wrappers call end_timing without re-checking handle state, and means a callback path that closes its handle still produces a consistent return value if a follow-up finally-style block calls end_timing again.

Errors are captured automatically

When timed(...) propagates an exception, it closes the span with {status: "error", error: "<message>"} before re-throwing. Imperative callers should pass the same shape explicitly:

import { start_timing, end_timing } from "std/timing"

let timing = start_timing("risky")
try {
  risky_work()
  end_timing(timing, {status: "ok"})
} catch (e) {
  end_timing(timing, {status: "error", error: to_string(e)})
  throw e
}

Profile and OTel export

harn run --profile-json includes user timing spans under the user_timing bucket alongside the existing pipeline / llm_call / tool_call categories. OTel exporters surface them as INTERNAL spans named after the name argument, so they do not collide with the GenAI semconv mappings used by LLM and tool spans. Span attributes flow through the same redaction policy used for receipts, OTel attributes, and OAuth scopes.

OTel exports keep only low-cardinality harn.* attributes as top-level span attributes. Stable exact keys include harn.kind, harn.status, harn.duration_ms, and harn.span_id; runtime-owned namespaces include harn.llm.*, harn.tool.*, harn.worker.*, harn.step.*, harn.lifecycle.*, harn.cost.*, harn.token.*, and harn.timing.*. Other timing metadata is preserved as JSON under harn.meta_json so dynamic keys such as UUIDs or file paths do not create unbounded OTel attribute names.

When to skip a timing span

• Tight inner loops (per-iteration spans are pure overhead).
• Boundary points where std/observability::log or metric is enough — pick a metric when you want pre-aggregated numbers, an attribute when the value belongs on the current span, and a timing span when the duration of a discrete piece of work matters.