Compare commits

...
Author SHA1 Message Date
Vasanthdev2004 c4de52a5c5 Address CodeRabbit re-review: anti-averaging README + fixture-isolation test
Re-review at d0615249 asked for the pass-rate contract to be loud to
downstream consumers and for the fixture-isolation property to be asserted,
not just read from code.

- reports/README.md gains a prominent 'do not average the tier pass rates /
  do not report a single pass rate' warning. The schema offers no headline
  pass rate on purpose; a consumer must name the tier it is reporting. This
  is the durability fix for the misread the tier split exists to prevent.
- turn_bench_test.go gains TestCopyFixtureIsolatesSourceFromMutation: copies
  a fixture, mutates the copy, and asserts the source is byte-identical
  (and that a file added to the copy never appears in the source). Proves the
  'fixtures stay clean across runs' property without needing the binary.

Items the re-review also raised that were already satisfied: the
oracle-presence-over-declared-list precedence is documented on the
BuildOnlyClasses field (taskbench.go), and the PR body already says
'48-task manifest'. The Share->exclusiveShare rename is tracked in #701.

go build/vet/gofmt clean; go test -race green for perfbench.
2026-07-16 14:52:24 +05:30
Vasanthdev2004 d061524989 Address CodeRabbit review on 2bfb3406: omitempty + crash visibility
Three findings from CodeRabbit's review of the 3-tier pass-rate fix:

- BuildPassRate dropped its omitempty so an explicit 0.0 (all refactor
  tasks fail to compile) is no longer indistinguishable from 'no build
  tasks ran' in the JSON. Matches CorrectnessPassRate's always-serialize
  behavior, which is the whole point of the tier split: the report
  cannot be misread.
- A crashed sample (outcome.Err) now emits a Warning mirroring the
  TraceIssue path, so a run that died every iteration can't look like a
  normal benchmark with fewer measurements instead of a failure.
- cmd.Run()'s returned error is preserved on the no-run_end path: when
  stderr is empty and Run failed (binary missing, exec permission
  denied), the actual OS error is reported instead of collapsing to the
  generic 'missing terminal run_end event'.

go build/vet/gofmt clean; go test -race green for perfbench/agent/trace.
2026-07-16 14:46:42 +05:30
Vasanthdev2004 2bfb340668 perf(turn-bench): split pass/fail into oracle tiers so the pass rate can't be misread as correctness
The turn benchmark counted any exit-0 task as passed, including the 24
read-only tasks (nav/longproc/longctx/parallel) that carry no verification
oracle — so the JSON tasksPassed / "N/M passed" headline could read as a
correctness verdict it never was. Split pass/fail into three oracle tiers:

- correctness (edit grep + fix go test): the only pass rate that can move
  with model quality (tasksVerified / tasksPassed / correctnessPassRate)
- build-only (refactor go build): a non-positive oracle, reported as
  buildPassRate and excluded from correctnessPassRate; the manifest declares
  buildOnlyClasses: ["refactor"]
- latency-only (no oracle): counted in latencyOnlyTasks, never in any pass
  rate

NewTurnExecRunner no longer sets Passed=true for tasks with no
verificationCommand, and the summary headline names each tier explicitly so
an exit-0 read-only run cannot inflate a correctness number. Bumps
TurnSchemaVersion to 2. Class breakdown and tier contract documented in
internal/perfbench/MANIFEST.md and reports/README.md.

Also install the trace first-token/visible-event forwarding handlers in
agent.Run whenever options.Trace is set, not only when a UI OnText /
OnReasoning callback is set, so a headless traced run (zero exec --trace)
still captures FirstTokenAt. forwardedVisibleText stays tied to the user
callback so stall-retry semantics are unchanged. Adds a regression
assertion to the existing traced-run test.
2026-07-16 14:32:13 +05:30
Vasanthdev2004 40806aa4b1 Fix exclusive-time round-trip, identical-interval nesting, and empty-trace parse
Three correctness bugs in the attribution model found by an adversarial review
of the prior commit, all undermining the no-double-count guarantee:

1. exclusive_ms:0 was overwritten with the inclusive Duration on re-parse. A
   parent whose children tile its interval legitimately has exclusive time 0;
   WriteNDJSON emits exclusive_ms:0, but ReadNDJSON's "<= 0 means missing"
   fallback turned that back into the full duration, so every re-parsed trace
   re-introduced the double-counting the model exists to prevent (the benchmark
   harness, which ranks re-parsed traces, inherits it). Gate the fallback on
   key ABSENCE, so a written 0 is preserved.

2. deriveNesting formed a 2-cycle for two spans with identical [start, end]
   intervals: the symmetric containment check made each parent the other,
   dropping both from top-level and zeroing AttributedDuration. Break the tie
   deterministically — strict containment is an unambiguous parent; for
   identical intervals, only the lower-indexed span may parent the other, so
   one stays top-level.

3. ReadNDJSON returned a valid empty TurnTrace for empty/blank-only input, so a
   run that crashed before emitting a trace (or where --trace was not honored)
   masqueraded as a clean zero-attribution sample. Empty input now errors, so
   the harness records a TraceIssue.

Also: decode counters via json.Number so int64 values above 2^53 round-trip
exactly instead of losing precision through float64; and drop the harness's
own "exclusive <= 0 -> Duration" ranking fallback, which was the same
double-count on the re-parsed path. Added regression tests covering the
zero-exclusive round-trip, the identical-interval nesting, empty-input
rejection, and counter precision.
2026-07-16 13:56:46 +05:30
Vasanthdev2004 0f372f3844 Address review feedback: exclusive-time attribution + wired spans + fix-suite compile
Rewrite the trace attribution model so concurrent/nested spans no longer
double-count. Spans record wall intervals; the recorder derives a parent for
each by interval containment and computes exclusive time (duration minus the
union of its children). AttributedDuration sums only top-level spans; Coverage
is the union of intervals over wall, capped at 1, the honest ">=95%" metric.
Top-latency ranking uses exclusive time so shares sum to ~1 instead of being
inflated by overlapping provider_connect/generation and nested
permission_wait/tool_execution.

Wire the spans that were named but never stamped: verification around the
self-correct verify pass, and StampFirstVisibleEvent on the first forwarded
text event. Drop the tool_queue/process_wait/persistence constants that had no
stamps, and rename the misnamed near-noise prompt_build span to tool_partition.
Trim RequiredEventKeys to events a healthy short run actually emits; move
conditional phases (tools, permission, compaction, verification) to
OptionalEventKeys so a short trace does not false-fail.

Make ReadNDJSON fail loudly on a corrupt file: require a type:trace header,
error on span/counter lines that appear before it, and error when a header
yields no spans or counters.

Fix the blocking fix-suite compile error: Label's %d format verb on a string
tripped go test's vet before any fix task could verify. Make it a runtime
wrong-prefix bug ("admin-" vs "user-") that still type-checks, so each fix
task is independent again.

Manifest: correct refactor-04's stats.go to main.go, reword fix-07 to the
wrong-prefix bug, add a latency-only description (read-only tasks carry no
verification oracle by design), and frame the report README on exclusive time
and coverage.

Tests updated for the occurrence/exclusive/coverage model; trace, perfbench,
and agent green under -race.
2026-07-16 13:37:13 +05:30
Vasanthdev2004 b3e6ef1f58 Address review feedback on the per-turn tracer + benchmark harness
Benchmark runner (internal/perfbench):
- A nonzero agent exit code no longer counts as Passed. The runner set
  VerifyErr but then fell through to outcome.Passed = true, so a crashed
  run could be recorded as a pass. Return before the verification block
  when VerifyErr is already set.
- A task now passes only when every iteration passes. The previous
  "any iteration passes" rule let a flaky fail hide behind one good run.
- Each invocation copies its workspace fixture to a fresh temp dir and
  runs the agent + verifier there, so mutating tasks (edit/fix/refactor)
  can't dirty the checked-in fixtures or bleed into the next iteration.
- Trace load failures (missing/malformed trace file) are surfaced as
  result warnings via a new TraceIssue field instead of being swallowed.

Tracer (internal/trace):
- Finish freezes the recorder: Counter, addSpan, and the first-event
  stamps are dropped after Finish returns, so a snapshot captures exactly
  one turn and late stamps can't mutate it.
- WriteText propagates the first write error instead of silently
  swallowing sink failures.

Provider seam (internal/providers/providerio):
- FirstTokenAt is stamped only after a payload is accepted as real model
  output, not before handle() decides to drop it as an error payload.

Agent loop (internal/agent):
- The compaction counter increments only when the history actually
  shrinks, in both the proactive and reactive paths — paid no-ops no
  longer inflate the compaction total.
- Document on Options.Trace that a fresh Recorder is required per Run.

CLI (internal/cli/exec):
- Finish the trace at the agent.Run boundary and defer only the
  serialization, so the snapshot covers exactly the turn.
- Reject --trace / ZERO_TRACE for spec-draft runs with a clear error
  instead of silently accepting and writing nothing.

Manifest + fixtures:
- Strengthen the edit verifiers: rename and value-bump tasks now assert
  the old symbol is gone, and the getter task greps the method signature.
- Add the missing testdata/edit fixture (10 edit tasks referenced a
  directory that was never committed, so the whole edit class errored
  out at run time).
- The manifest test now stats each fixture so a missing dir fails at
  load time instead of at every run.
- longproc benchmark keeps Process live across the loop; README code
  fence gets a language tag and documents the per-invocation fixture copy.
- Add tests for the tracing wrapper (nil vs wired recorder, OnUsage
  forwarding, token aggregation) and the frozen-recorder contract.
2026-07-16 12:45:15 +05:30
Vasanthdev2004 6896fee475 test(trace): make TestAttributionRatio clock-independent
The test recorded two synthetic 10ms spans with no real delay and asserted
the attribution ratio stayed <= 1.0. On a precise clock (Linux/macOS CI) the
wall is microseconds while attributed is 20ms, so attributed/wall blows past
1.0 and the test failed — even though the ratio legitimately exceeds 1.0
when spans overlap (parallel tool execution). On Windows the coarse timer
masked it, so the failure only surfaced in CI.

Assert the contract instead: attributed is the deterministic sum of span
durations, and the ratio equals attributed/wall (0 when wall is zero). Add a
zero-wall case for the divide-by-zero guard.
2026-07-16 12:19:17 +05:30
Vasanthdev2004 2ec91f4493 Add per-turn tracing and a turn-benchmark harness (Phase 0 baseline)
Introduce an opt-in `internal/trace` package that attributes a run's wall
time to named spans — prompt build, provider connect/queue, generation,
tool queue/execution, permission wait, verification, compaction,
persistence — plus counters for model requests, tool calls, retries,
reconnects, compactions, completion nudges, acceptance checks, model
switches, and input/cached/output tokens. The recorder is nil-safe (a nil
*Recorder is a no-op), so every stamp site can call it unguarded; an
untraced run is byte-identical to today.

The recorder threads into agent.Run via a new `Options.Trace` field and a
single `trace.WithContext` assignment, so the shared providerio seam
(connect around client.Do, queue around OAuth resolve, first token at the
first non-keepalive SSE payload) reaches it through `trace.FromContext`
without any provider-interface change. All instrumentation is opt-in: when
`Options.Trace` is nil the hot path is untouched.

Headless `zero exec` gains `--trace <path>` (and `ZERO_TRACE=<path>`),
writing an agenteval-contract-compatible NDJSON trace (`-` for stderr).
The trace is pure observation; enabling it does not change behavior.

A new per-turn benchmark harness extends `internal/perfbench` (reusing the
existing TaskSet/NumericStats/subprocess runner shapes): `RunTurnBench`
aggregates per-span median/P95 across iterations, ranks the top three
controllable latency sources by share of attributed time, rolls up per
task class, and totals tokens/counts. A checked-in 42-task manifest across
seven classes (nav, edit, fix, refactor, longproc, longctx, parallel) and
local offline fixtures back it, and `make baseline` runs it against the
built `zero`, writing `internal/perfbench/reports/baseline.json`. The
report is machine-specific and regenerated, not hand-edited.

The manifest is JSON rather than YAML to avoid adding a dependency;
per-task verification targets the specific test (`go test -run <name>`)
so fix tasks are independent. Each task is a fresh `zero exec` process, so
iterations are cold-start samples; a warm in-process path is left for
follow-up.

Verified: `go build ./...`, `go vet ./...`, `gofmt -l` clean on touched
files; `go test -race` green for internal/trace, internal/agent,
internal/perfbench, and cmd/zero-perf-bench.
2026-07-16 12:04:21 +05:30
56 changed files with 5072 additions and 12 deletions

No files matched your search

+16 -2
View File
@@ -1,7 +1,7 @@
# Zero build/test/lint targets. AGENTS.md says "Build with `make`" and "Run `make
# lint` before opening a PR" — these targets back those instructions.
.DEFAULT_GOAL := build
.PHONY: build build-all test test-race vet fmt fmt-check lint tidy clean help
.PHONY: build build-all test test-race vet fmt fmt-check lint tidy clean baseline help
# Build the main CLI binary into ./zero.
build:
@@ -40,5 +40,19 @@ clean:
rm -f zero
go clean ./...
# Run the per-turn benchmark harness over the checked-in baseline manifest and
# write the JSON result to internal/perfbench/reports/baseline.json. Requires a
# built `zero` binary and a model; set ZERO_BENCH_MODEL (required) and
# ZERO_BENCH_BINARY (defaults to ./zero) to configure the run. The report is
# machine-specific and regenerated, not hand-edited.
baseline: build
@if [ -z "$(ZERO_BENCH_MODEL)" ]; then echo "Set ZERO_BENCH_MODEL (and optionally ZERO_BENCH_BINARY) before running 'make baseline'"; exit 2; fi
@ZERO_BIN="$${ZERO_BENCH_BINARY:-./zero}"; \
go run ./cmd/zero-perf-bench turn \
--suite internal/perfbench/manifests/baseline.json \
--model $(ZERO_BENCH_MODEL) \
--binary "$$ZERO_BIN" \
--output internal/perfbench/reports/baseline.json
help:
@echo "Targets: build (default), build-all, test, test-quick, vet, fmt, fmt-check, lint, tidy, clean"
@echo "Targets: build (default), build-all, test, test-quick, vet, fmt, fmt-check, lint, tidy, clean, baseline"
+4
View File
@@ -39,6 +39,9 @@ func run(args []string, getenv func(string) string, stdout io.Writer, stderr io.
if len(args) > 0 && args[0] == "tasks" {
return runTasksCommand(args[1:], getenv, stdout, stderr)
}
if len(args) > 0 && args[0] == "turn" {
return runTurnCommand(args[1:], getenv, stdout, stderr)
}
options, err := parseArgs(args, getenv)
if err != nil {
_, _ = fmt.Fprintln(stderr, err.Error())
@@ -206,6 +209,7 @@ func helpText() string {
return strings.Join([]string{
"Usage: zero-perf-bench [options]",
" zero-perf-bench tasks [options] (Terminal-Bench-style task harness; see `tasks --help`)",
" zero-perf-bench turn [options] (per-turn tracing benchmark; see `turn --help`)",
"",
"Options:",
" --iterations <n> Measured samples to collect (default: 5)",
+238
View File
@@ -0,0 +1,238 @@
package main
import (
"bytes"
"context"
"fmt"
"io"
"os"
"path/filepath"
"strings"
"github.com/Gitlawb/zero/internal/perfbench"
)
// turnOptions configures the `zero-perf-bench turn` subcommand: the per-turn
// benchmark harness that runs ZERO headlessly with --trace, parses each turn's
// NDJSON trace, and records per-span latency plus the top controllable latency
// sources — the Phase 0 baseline's "do not proceed until" criterion.
type turnOptions struct {
SuitePath string
Model string
Mode string
SelfCorrect bool
Binary string
Iterations int
Version string
Commit string
Output string
JSON bool
DryRun bool
Help bool
}
func runTurnCommand(args []string, getenv func(string) string, stdout io.Writer, stderr io.Writer) int {
options, err := parseTurnArgs(args, getenv)
if err != nil {
_, _ = fmt.Fprintln(stderr, err.Error())
return 2
}
if options.Help {
_, _ = fmt.Fprint(stdout, turnHelpText())
return 0
}
set, err := perfbench.LoadTaskSet(options.SuitePath)
if err != nil {
_, _ = fmt.Fprintln(stderr, "[zero] Turn benchmark failed: "+err.Error())
return 1
}
// The dry-run path records a zero-iteration run without a binary, so the
// manifest loads and the report path is exercised in CI without a model.
if options.DryRun {
_, _ = fmt.Fprintln(stdout, "[zero] turn benchmark: dry run (no agent invoked)")
return 0
}
binary, err := perfbench.ResolveBinary(options.Binary)
if err != nil {
_, _ = fmt.Fprintln(stderr, "[zero] Turn benchmark failed: "+err.Error())
return 2
}
result, err := perfbench.RunTurnBench(context.Background(), set, perfbench.TurnBenchConfig{
Model: options.Model,
Mode: options.Mode,
SelfCorrect: options.SelfCorrect,
Version: options.Version,
Commit: options.Commit,
Iterations: options.Iterations,
Runner: perfbench.NewTurnExecRunner(binary),
})
if err != nil {
_, _ = fmt.Fprintln(stderr, "[zero] Turn benchmark failed: "+err.Error())
return 1
}
if options.Output != "" {
if err := writeTurnReport(options.Output, result); err != nil {
_, _ = fmt.Fprintln(stderr, "[zero] Turn benchmark failed: "+err.Error())
return 1
}
}
if options.JSON {
if err := perfbench.WriteTurnBenchJSON(stdout, result); err != nil {
_, _ = fmt.Fprintln(stderr, "[zero] Turn benchmark failed: "+err.Error())
return 1
}
return 0
}
_, _ = fmt.Fprintln(stdout, perfbench.FormatTurnBenchSummary(result))
return 0
}
func parseTurnArgs(args []string, getenv func(string) string) (turnOptions, error) {
options := turnOptions{
Iterations: 1,
Version: strings.TrimSpace(getenv("ZERO_BENCH_VERSION")),
Commit: strings.TrimSpace(getenv("ZERO_BENCH_COMMIT")),
}
for index := 0; index < len(args); index++ {
arg := args[index]
flag, inlineValue := splitFlagValue(arg)
switch flag {
case "--suite":
value, next, err := readOptionValue(args, inlineValue, index, flag)
if err != nil {
return options, err
}
options.SuitePath = value
index = next
case "--model":
value, next, err := readOptionValue(args, inlineValue, index, flag)
if err != nil {
return options, err
}
options.Model = value
index = next
case "--mode":
value, next, err := readOptionValue(args, inlineValue, index, flag)
if err != nil {
return options, err
}
options.Mode = value
index = next
case "--binary":
value, next, err := readOptionValue(args, inlineValue, index, flag)
if err != nil {
return options, err
}
options.Binary = value
index = next
case "--iterations":
value, next, err := readOptionValue(args, inlineValue, index, flag)
if err != nil {
return options, err
}
parsed, err := parsePositiveInteger(flag, value)
if err != nil {
return options, err
}
options.Iterations = parsed
index = next
case "--version":
value, next, err := readOptionValue(args, inlineValue, index, flag)
if err != nil {
return options, err
}
options.Version = value
index = next
case "--commit":
value, next, err := readOptionValue(args, inlineValue, index, flag)
if err != nil {
return options, err
}
options.Commit = value
index = next
case "--output":
value, next, err := readOptionValue(args, inlineValue, index, flag)
if err != nil {
return options, err
}
options.Output = value
index = next
case "--self-correct":
if strings.Contains(arg, "=") {
return options, fmt.Errorf("%s does not accept a value", flag)
}
options.SelfCorrect = true
case "--json":
if strings.Contains(arg, "=") {
return options, fmt.Errorf("%s does not accept a value", flag)
}
options.JSON = true
case "--dry-run":
if strings.Contains(arg, "=") {
return options, fmt.Errorf("%s does not accept a value", flag)
}
options.DryRun = true
case "-h", "--help":
if strings.Contains(arg, "=") {
return options, fmt.Errorf("%s does not accept a value", flag)
}
options.Help = true
default:
return options, fmt.Errorf("unknown option: %s", arg)
}
}
if options.Help {
return options, nil
}
if strings.TrimSpace(options.SuitePath) == "" {
return options, fmt.Errorf("--suite is required")
}
if strings.TrimSpace(options.Model) == "" && !options.DryRun {
return options, fmt.Errorf("--model is required (or pass --dry-run)")
}
return options, nil
}
func writeTurnReport(path string, result perfbench.TurnBenchResult) error {
if dir := filepath.Dir(path); dir != "" {
if err := os.MkdirAll(dir, 0o755); err != nil {
return err
}
}
var buffer bytes.Buffer
if err := perfbench.WriteTurnBenchJSON(&buffer, result); err != nil {
return err
}
return os.WriteFile(path, buffer.Bytes(), 0o644)
}
func turnHelpText() string {
return strings.Join([]string{
"Usage: zero-perf-bench turn [options]",
"",
"Runs ZERO headlessly with --trace against a per-turn benchmark task set and",
"records per-span latency plus the top controllable latency sources (the",
"Phase 0 baseline's \"do not proceed until\" criterion). Each task is a fresh",
"`zero exec` process, so iterations are cold-start samples; a warm path needs",
"an in-process runner (future work).",
"",
"Options:",
" --suite <path> Task set JSON file (required)",
" --model <model> Model to run (required unless --dry-run)",
" --mode <name> Exec mode preset to apply",
" --self-correct Enable the post-edit verify-and-correct loop",
" --binary <path> Path to the `zero` binary (default: zero on PATH / repo root)",
" --iterations <n> Times to run each task (default: 1)",
" --version <v> Record the ZERO version (default: $ZERO_BENCH_VERSION)",
" --commit <sha> Record the ZERO commit (default: $ZERO_BENCH_COMMIT)",
" --output <path> Write the JSON result to path",
" --json Print only the JSON result",
" --dry-run Load the manifest and exit without invoking the agent",
" -h, --help Show this help",
}, "\n") + "\n"
}
+12 -1
View File
@@ -6,6 +6,7 @@ import (
"errors"
"strings"
"github.com/Gitlawb/zero/internal/trace"
"github.com/Gitlawb/zero/internal/zeroruntime"
)
@@ -430,6 +431,12 @@ func (state *compactionState) maybeCompact(
state.lowWaterMark = size
return messages
}
// Only count a compaction when it actually shrank the history, so the
// compaction counter reflects real context reductions rather than paid
// no-ops that left the token budget untouched.
if r := trace.FromContext(ctx); r != nil {
r.Counter(trace.CounterCompactionCount, 1)
}
state.lowWaterMark = newSize
return compacted
}
@@ -479,7 +486,11 @@ func (state *compactionState) recover(
// one-shot budget now so a provider that keeps returning context-limit errors
// after a successful compaction can't loop forever. Store the low-water mark in
// the SAME combined (messages + tool-defs) domain maybeCompact uses, so the
// proactive shrink-guard compares like with like.
// proactive shrink-guard compares like with like. Count it now that the shrink
// is confirmed, so the counter mirrors maybeCompact's real-reduction policy.
if r := trace.FromContext(ctx); r != nil {
r.Counter(trace.CounterCompactionCount, 1)
}
state.reactiveAttempted = true
state.lowWaterMark = state.calibratedTokens(estimateTokens(result) + estimateToolDefTokens(tools))
return result, true, nil
+82 -5
View File
@@ -15,6 +15,7 @@ import (
"github.com/Gitlawb/zero/internal/sandbox"
"github.com/Gitlawb/zero/internal/streamjson"
"github.com/Gitlawb/zero/internal/tools"
"github.com/Gitlawb/zero/internal/trace"
"github.com/Gitlawb/zero/internal/zeroruntime"
)
@@ -114,6 +115,26 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
return Result{}, errors.New("agent provider is required")
}
// Tracing is opt-in. When a recorder is wired, thread it into ctx so the
// providerio seam and reconnect helper can reach it via trace.FromContext,
// mark the run's start, and wrap OnUsage so token counters accumulate for
// free alongside the existing per-request plumbing. nil recorder leaves the
// loop byte-identical: FromContext returns nil, the no-op stamps cost
// nothing, and the OnUsage wrapper is not installed.
if options.Trace != nil {
ctx = trace.WithContext(ctx, options.Trace)
options.Trace.Start()
originalOnUsage := options.OnUsage
options.OnUsage = func(usage Usage) {
if originalOnUsage != nil {
originalOnUsage(usage)
}
options.Trace.Counter(trace.CounterInputTokens, int64(usage.InputTokens))
options.Trace.Counter(trace.CounterCachedInputTokens, int64(usage.CachedInputTokens))
options.Trace.Counter(trace.CounterOutputTokens, int64(usage.OutputTokens))
}
}
maxTurns := options.MaxTurns
if maxTurns <= 0 {
maxTurns = 12
@@ -184,12 +205,20 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
// the tool-definition tokens (they ride on every request) in its estimate.
// partitionTools depends only on registry/permissions/options/loaded, not on
// the messages, so computing it before compaction is safe.
// Build the per-turn tool list first so proactive compaction can include
// the tool-definition tokens (they ride on every request) in its estimate.
// partitionTools depends only on registry/permissions/options/loaded, not on
// the messages, so computing it before compaction is safe.
toolPartitionSpan := options.Trace.Span(trace.SpanToolPartition)
exposed, _ := partitionToolsCached(registry, permissionMode, options, loaded, toolDefCache)
toolPartitionSpan.End()
// PROACTIVE compaction: if the history is approaching the model's
// context window, summarize the oldest middle before building the
// request. A no-op when ContextWindow == 0 (compaction disabled).
compactionSpan := options.Trace.Span(trace.SpanCompaction)
messages = compactor.maybeCompact(ctx, provider, messages, exposed)
compactionSpan.End()
request := zeroruntime.CompletionRequest{
Messages: copyMessages(messages),
Tools: exposed,
@@ -255,11 +284,39 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
// conversation-state duplication.
forwardedVisibleText := false
forwardingOpts := zeroruntime.CollectOptions{OnUsage: options.OnUsage}
if options.OnText != nil {
forwardingOpts.OnText = func(s string) { forwardedVisibleText = true; options.OnText(s) }
// Install text/reasoning forwarding handlers whenever EITHER a user
// callback OR a trace recorder is set. A headless traced run (e.g. `zero
// exec --trace`) sets Trace but no OnText/OnReasoning; without these
// handlers the stream is still collected, but FirstTokenAt would never
// stamp and the trace would lose its TTFT signal. The trace recorder's
// stamp methods are nil-safe, but we guard on `trace != nil` so a run with
// a user callback but no recorder still works. forwardedVisibleText stays
// tied to the USER callback only, preserving the stall-retry semantics
// (a trace-only handler forwards nothing the user would see duplicated).
rec := options.Trace
onText := options.OnText
if onText != nil || rec != nil {
forwardingOpts.OnText = func(s string) {
if rec != nil {
rec.StampFirstVisibleEvent()
rec.StampFirstToken()
}
if onText != nil {
forwardedVisibleText = true
onText(s)
}
}
}
if options.OnReasoning != nil {
forwardingOpts.OnReasoning = func(s string) { options.OnReasoning(s) }
onReasoning := options.OnReasoning
if onReasoning != nil || rec != nil {
forwardingOpts.OnReasoning = func(s string) {
if rec != nil {
rec.StampFirstToken()
}
if onReasoning != nil {
onReasoning(s)
}
}
}
if options.OnToolCallStart != nil {
forwardingOpts.OnToolCallStart = func(id, name string) { options.OnToolCallStart(id, name) }
@@ -297,14 +354,18 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
if retryStreamErr != nil {
return collected, retryStreamErr
}
genSpan := options.Trace.Span(trace.SpanGeneration)
collected = zeroruntime.CollectStreamWithOptions(ctx, retryStream, zeroruntime.CollectOptions{
OnUsage: options.OnUsage,
})
genSpan.End()
}
return collected, nil
}
generationSpan := options.Trace.Span(trace.SpanGeneration)
collected := zeroruntime.CollectStreamWithOptions(ctx, stream, forwardingOpts)
generationSpan.End()
if collected.Error != "" {
updated, stop := recoverStreamError(collected)
collected = updated
@@ -357,7 +418,9 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
result.Messages = copyMessages(messages)
return result, retryErr
}
stallGenSpan := options.Trace.Span(trace.SpanGeneration)
collected = zeroruntime.CollectStreamWithOptions(ctx, retryStream, forwardingOpts)
stallGenSpan.End()
}
if collected.Error != "" {
// Route a reissued stream's non-stall error through the SAME recovery as
@@ -459,6 +522,7 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
if cue || planPending {
if continueNudges < maxContinueNudges {
continueNudges++
options.Trace.Counter(trace.CounterCompletionNudges, 1)
reason := "your message ended mid-step"
if !cue {
reason = "pending plan items remain — finish them, or mark them complete with update_plan if you are done"
@@ -488,6 +552,7 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
// (no admission, no cue) then finalizes as success on the next turn.
if options.SelfCorrect != nil && !acceptanceRequested {
acceptanceRequested = true
options.Trace.Counter(trace.CounterAcceptanceChecks, 1)
messages = append(messages, zeroruntime.Message{
Role: zeroruntime.MessageRoleUser,
Content: acceptanceVerificationNudge(),
@@ -548,20 +613,26 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
runEnd++
}
if runEnd-index >= 2 {
batchSpan := options.Trace.Span(trace.SpanToolExecution)
precomputed = executeParallelReadBatch(ctx, registry, collected.ToolCalls, index, runEnd, permissionMode, options)
batchSpan.End()
precomputedStart, precomputedEnd = index, runEnd
}
}
if options.OnToolCall != nil {
options.OnToolCall(call)
}
options.Trace.StampFirstUsefulAction()
var toolResult ToolResult
var abortErr error
if index >= precomputedStart && index < precomputedEnd {
toolResult, abortErr = precomputed[index-precomputedStart].result, precomputed[index-precomputedStart].abortErr
} else {
toolSpan := options.Trace.Span(trace.SpanToolExecution)
toolResult, abortErr = executeToolCall(ctx, registry, call, permissionMode, options)
toolSpan.End()
}
options.Trace.Counter(trace.CounterToolCalls, 1)
if options.OnToolResult != nil {
options.OnToolResult(toolResult)
}
@@ -666,6 +737,7 @@ func Run(ctx context.Context, prompt string, provider Provider, options Options)
// context-window sizing, and usage attribution follow the new model.
provider = newProvider
options.Model = turnRequestedModel
options.Trace.Counter(trace.CounterModelSwitches, 1)
// KNOWN LIMITATION (deferred): the compactor's context-window budget
// is fixed at run start from options.ContextWindow and is NOT updated
// here, so a switch to a model with a different window keeps compacting
@@ -764,6 +836,7 @@ func finalAnswerAfterMaxTurns(ctx context.Context, provider Provider, messages [
if err != nil {
return "", messages, ""
}
finalGenSpan := options.Trace.Span(trace.SpanGeneration)
collected := zeroruntime.CollectStreamWithOptions(ctx, stream, zeroruntime.CollectOptions{
OnText: options.OnText,
OnReasoning: options.OnReasoning,
@@ -771,6 +844,7 @@ func finalAnswerAfterMaxTurns(ctx context.Context, provider Provider, messages [
OnToolCallStart: options.OnToolCallStart,
OnToolCallDelta: options.OnToolCallDelta,
})
finalGenSpan.End()
if ctx.Err() != nil || collected.Error != "" || strings.TrimSpace(collected.Text) == "" {
return "", messages, ""
}
@@ -1874,7 +1948,10 @@ func requestPermission(ctx context.Context, request PermissionRequest, options O
if options.OnPermissionRequest == nil {
return PermissionDecision{Action: PermissionDecisionDeny, Reason: request.Reason}, nil
}
return options.OnPermissionRequest(ctx, request)
permSpan := options.Trace.Span(trace.SpanPermissionWait)
decision, err := options.OnPermissionRequest(ctx, request)
permSpan.End()
return decision, err
}
func normalizePermissionDecisionAction(action PermissionDecisionAction) PermissionDecisionAction {
+71
View File
@@ -15,6 +15,7 @@ import (
"github.com/Gitlawb/zero/internal/sandbox"
"github.com/Gitlawb/zero/internal/specmode"
"github.com/Gitlawb/zero/internal/tools"
"github.com/Gitlawb/zero/internal/trace"
"github.com/Gitlawb/zero/internal/zeroruntime"
)
@@ -3461,3 +3462,73 @@ func TestRunDoesNotFlagCleanToolOutput(t *testing.T) {
t.Errorf("clean output should not get a reminder, got %q", captured.Output)
}
}
// TestRunTracingWrapperStampsUsage verifies the per-turn tracing setup in Run:
// a wired recorder is Started, OnUsage is wrapped so it still forwards to the
// caller's callback AND stamps token counters, and the run completes.
func TestRunTracingWrapperStampsUsage(t *testing.T) {
provider := &mockProvider{turns: [][]zeroruntime.StreamEvent{{
{Type: zeroruntime.StreamEventUsage, Usage: zeroruntime.Usage{InputTokens: 100, CachedInputTokens: 20, OutputTokens: 40}},
{Type: zeroruntime.StreamEventText, Content: "done"},
{Type: zeroruntime.StreamEventDone},
}}}
onUsageCalls := 0
rec := trace.NewRecorder("tracing-session", "run-1", "test")
if _, err := Run(context.Background(), "hi", provider, Options{
SessionID: "tracing-session",
Cwd: t.TempDir(),
ProviderName: "test-provider",
Model: "test-model",
Trace: rec,
OnUsage: func(Usage) { onUsageCalls++ },
}); err != nil {
t.Fatalf("Run: %v", err)
}
tr := rec.Finish()
if tr.StartedAt.IsZero() {
t.Fatal("tracing wrapper did not Start the recorder")
}
// FirstTokenAt must stamp even though no OnText/OnReasoning user callback is
// set: a headless traced run (e.g. `zero exec --trace`) sets Trace but no UI
// callbacks, so the loop installs trace-only forwarding handlers to capture
// TTFT. Without them FirstTokenAt stays zero and the trace loses its signal.
if tr.FirstTokenAt.IsZero() {
t.Fatal("FirstTokenAt not stamped for a traced run with no OnText/OnReasoning callbacks")
}
if got := tr.Counter(trace.CounterInputTokens); got != 100 {
t.Fatalf("input token counter = %d, want 100", got)
}
if got := tr.Counter(trace.CounterCachedInputTokens); got != 20 {
t.Fatalf("cached input token counter = %d, want 20", got)
}
if got := tr.Counter(trace.CounterOutputTokens); got != 40 {
t.Fatalf("output token counter = %d, want 40", got)
}
if onUsageCalls == 0 {
t.Fatal("wrapped OnUsage did not forward to the caller's callback")
}
}
// TestRunNilTraceForwardsUsage verifies a nil recorder leaves the loop
// byte-identical: OnUsage is not wrapped, so the caller's callback still fires
// and nothing panics.
func TestRunNilTraceForwardsUsage(t *testing.T) {
provider := &mockProvider{turns: [][]zeroruntime.StreamEvent{{
{Type: zeroruntime.StreamEventUsage, Usage: zeroruntime.Usage{InputTokens: 7}},
{Type: zeroruntime.StreamEventText, Content: "done"},
{Type: zeroruntime.StreamEventDone},
}}}
onUsageCalls := 0
if _, err := Run(context.Background(), "hi", provider, Options{
SessionID: "nil-trace-session",
Cwd: t.TempDir(),
ProviderName: "test-provider",
Model: "test-model",
OnUsage: func(Usage) { onUsageCalls++ },
}); err != nil {
t.Fatalf("Run: %v", err)
}
if onUsageCalls == 0 {
t.Fatal("OnUsage not forwarded when Trace is nil")
}
}
+11
View File
@@ -8,6 +8,7 @@ import (
"time"
"github.com/Gitlawb/zero/internal/errhint"
"github.com/Gitlawb/zero/internal/trace"
"github.com/Gitlawb/zero/internal/zeroruntime"
)
@@ -74,14 +75,21 @@ func stallRetryNoticeFor(options Options) reconnectNotifier {
// already past its deadline is returned immediately (no retry) — those have
// their own handling (compaction for context-limit, image-rejection, etc.).
func streamWithReconnect(ctx context.Context, provider Provider, request zeroruntime.CompletionRequest, notify reconnectNotifier) (<-chan zeroruntime.StreamEvent, error) {
recorder := trace.FromContext(ctx)
stream, err := provider.StreamCompletion(ctx, request)
if err == nil {
if recorder != nil {
recorder.Counter(trace.CounterModelRequests, 1)
}
return stream, nil
}
for attempt := 1; attempt <= maxStreamReconnects; attempt++ {
if !shouldReconnect(ctx, err) {
return nil, err
}
if recorder != nil {
recorder.Counter(trace.CounterReconnectCount, 1)
}
if notify != nil {
notify(attempt, maxStreamReconnects)
}
@@ -90,6 +98,9 @@ func streamWithReconnect(ctx context.Context, provider Provider, request zerorun
}
stream, err = provider.StreamCompletion(ctx, request)
if err == nil {
if recorder != nil {
recorder.Counter(trace.CounterModelRequests, 1)
}
return stream, nil
}
}
+3
View File
@@ -9,6 +9,7 @@ import (
"github.com/Gitlawb/zero/internal/lsp"
"github.com/Gitlawb/zero/internal/redaction"
"github.com/Gitlawb/zero/internal/trace"
"github.com/Gitlawb/zero/internal/verify"
)
@@ -133,7 +134,9 @@ func (sc *SelfCorrector) inspect(ctx context.Context, changedFiles []string) Cor
}
if sc.cfg.IncludeTests && sc.verifier != nil {
verifySpan := trace.FromContext(ctx).Span(trace.SpanVerification)
vr, err := sc.verifier.Verify(ctx)
verifySpan.End()
if err != nil {
// "No plan / no tests" is not an error (DetectPlan returns an empty
// plan), so a non-nil error means verification could not run at all —
+11
View File
@@ -7,6 +7,7 @@ import (
"github.com/Gitlawb/zero/internal/sandbox"
"github.com/Gitlawb/zero/internal/streamjson"
"github.com/Gitlawb/zero/internal/tools"
"github.com/Gitlawb/zero/internal/trace"
"github.com/Gitlawb/zero/internal/zeroruntime"
)
@@ -279,6 +280,16 @@ type Options struct {
// request), so every existing caller is unaffected. A returned error is
// non-fatal: the run continues on the current model.
ModelSwitcher func(ctx context.Context, modelID string) (Provider, error)
// Trace, when set, records per-turn timing for the run: the loop stamps
// spans (prompt build, generation, tool execution, permission wait,
// compaction, provider connect) and counters (model requests, tool calls,
// retries, tokens) into it. nil DISABLES tracing entirely — every stamp is
// nil-safe and the loop is byte-identical to an untraced run. The caller
// owns the recorder: Run stamps into it but does not Finish or emit it.
// A fresh Recorder is required per Run — reusing one across runs merges
// their spans, counters, and first-event timestamps, and Finish freezes a
// recorder so no further stamps take.
Trace *trace.Recorder
// SelfCorrect, when set, runs a post-edit verify-and-correct cycle after a
// mutating tool call: it verifies the changed files (LSP diagnostics + project
// tests) and feeds failures back to the model to fix, bounded by an attempt
+71
View File
@@ -25,6 +25,7 @@ import (
"github.com/Gitlawb/zero/internal/specmode"
"github.com/Gitlawb/zero/internal/streamjson"
"github.com/Gitlawb/zero/internal/tools"
"github.com/Gitlawb/zero/internal/trace"
"github.com/Gitlawb/zero/internal/usage"
"github.com/Gitlawb/zero/internal/worktrees"
"github.com/Gitlawb/zero/internal/zeroruntime"
@@ -124,6 +125,12 @@ type execOptions struct {
// additional write roots for this run. Unioned with
// config.SandboxConfig.AdditionalWriteRoots at scope construction time.
addDirs []string
// tracePath, when set, writes a per-turn NDJSON trace (agenteval-compatible)
// to the given file path — or to stderr when the value is "-". Falls back to
// the ZERO_TRACE env var when the flag is absent. Off by default: a run
// without it leaves agent.Options.Trace nil and is byte-identical to before.
// The trace is pure observation — enabling it does not change agent behavior.
tracePath string
}
type execUsageError struct {
@@ -422,6 +429,12 @@ func runExec(args []string, stdout io.Writer, stderr io.Writer, deps appDeps) in
notify.MaybeAddWebhookSink(notifier, os.Getenv, func(format string, args ...any) {
fmt.Fprintf(stderr, "[notify] "+format+"\n", args...)
})
// Spec-draft runs synthesize a prompt offline and never drive a model turn, so
// there is no per-turn trace to emit. Reject --trace / ZERO_TRACE up front with
// a clear error rather than silently accepting and writing nothing.
if options.useSpec && resolveTracePath(options) != "" {
return writeExecFormatUsageError(stdout, stderr, options.outputFormat, "--trace / ZERO_TRACE are not supported for spec-draft runs")
}
if options.useSpec {
return runExecSpecDraft(execSpecDraftRun{
options: options,
@@ -474,6 +487,24 @@ func runExec(args []string, stdout io.Writer, stderr io.Writer, deps appDeps) in
if err != nil {
return writeAppError(stderr, "failed to create run id: "+err.Error(), exitCrash)
}
// Per-turn tracing is opt-in (--trace <path> or ZERO_TRACE=<path>). The
// recorder is stamped throughout agent.Run and the providerio seam; the run
// itself is byte-identical to an untraced run. We finish the recorder at the
// agent.Run boundary (below) so the snapshot captures exactly one turn, then
// serialize the snapshot on every exit path via the defer. "-" writes NDJSON
// to stderr; otherwise the path is created/truncated. A failure to emit is
// logged to stderr, never fatal.
tracePath := resolveTracePath(options)
var traceRecorder *trace.Recorder
var traceSnapshot *trace.TurnTrace
if tracePath != "" {
traceRecorder = trace.NewRecorder(preparedSession.Session.SessionID, runID, "")
defer func() {
if err := writeTraceSnapshot(traceSnapshot, tracePath, stderr); err != nil {
fmt.Fprintf(stderr, "[zero] failed to write trace: %s\n", err)
}
}()
}
writer := execEventWriter{
stdout: stdout,
stderr: stderr,
@@ -556,6 +587,7 @@ func runExec(args []string, stdout io.Writer, stderr io.Writer, deps appDeps) in
Model: resolved.Provider.Model,
ModelSwitcher: modelSwitcher,
ReasoningEffort: forwardEffort,
Trace: traceRecorder,
Cwd: workspaceRoot,
Images: images,
Registry: registry,
@@ -625,6 +657,12 @@ func runExec(args []string, stdout io.Writer, stderr io.Writer, deps appDeps) in
sessionRecorder.append(sessions.EventUsage, payload)
},
})
// Finish the trace now that the turn is done, so the snapshot captures exactly
// agent.Run's work and nothing the post-run cleanup stamps. The deferred
// writer serializes the snapshot on every exit path.
if traceRecorder != nil {
traceSnapshot = traceRecorder.Finish()
}
notifier.Notify(notify.Completion, notify.DefaultMessage(notify.Completion))
if writer.err != nil {
return exitCrash
@@ -1237,3 +1275,36 @@ func execNotifyMode(options execOptions, resolved config.ResolvedConfig) string
}
return resolved.Notify.Mode
}
// resolveTracePath returns the trace destination for this run: the --trace flag
// value when set, else the ZERO_TRACE env var, else "" (tracing off). A value of
// "-" means "write to stderr".
func resolveTracePath(options execOptions) string {
if v := strings.TrimSpace(options.tracePath); v != "" {
return v
}
if v := strings.TrimSpace(os.Getenv("ZERO_TRACE")); v != "" {
return v
}
return ""
}
// writeTraceSnapshot writes an already-finished trace snapshot to dest ("-" =>
// stderr, otherwise a file path created/truncated). A nil snapshot is a no-op
// (tracing off, or the run exited before agent.Run produced a turn). The trace
// is best-effort: a write error is returned to the caller, which logs it but
// never fails the run.
func writeTraceSnapshot(snapshot *trace.TurnTrace, dest string, stderr io.Writer) error {
if snapshot == nil || dest == "" {
return nil
}
if strings.TrimSpace(dest) == "-" {
return trace.WriteNDJSON(stderr, snapshot)
}
file, err := os.Create(dest)
if err != nil {
return err
}
defer file.Close()
return trace.WriteNDJSON(file, snapshot)
}
+9
View File
@@ -32,6 +32,15 @@ func parseExecArgs(args []string) (execOptions, bool, error) {
options.noNotify = true
case arg == "--no-completion-gate":
options.noCompletionGate = true
case arg == "--trace":
value, next, err := nextFlagValue(args, index, arg)
if err != nil {
return options, false, err
}
options.tracePath = value
index = next
case strings.HasPrefix(arg, "--trace="):
options.tracePath = strings.TrimSpace(strings.TrimPrefix(arg, "--trace="))
case arg == "--notify":
value, next, err := nextFlagValue(args, index, arg)
if err != nil {
+71
View File
@@ -0,0 +1,71 @@
# Turn benchmark manifest
The baseline manifest (`manifests/baseline.json`) is the per-turn benchmark's
program keystone: it defines the tasks the harness runs, the workspace each
starts in, and — critically — what "pass" means for each task. Because `make
baseline` is re-run on every perf change, the manifest's pass/fail contract
matters for months, so the contract is written down here.
## Task count
48 tasks across seven classes:
| class | count | oracle | tier |
|-----------|-------|-----------------------------|-------------|
| nav | 10 | none | latency |
| edit | 10 | substring grep | correctness |
| fix | 8 | scoped `go test -run <name>` | correctness |
| refactor | 6 | `go build ./...` | build |
| longproc | 4 | none | latency |
| longctx | 4 | none | latency |
| parallel | 6 | none | latency |
| **total** | **48**| | |
## Oracle tiers
Pass/fail is reported per tier so the report cannot be misread as a blanket
correctness verdict. The tier is decided per task from oracle presence and the
manifest's `buildOnlyClasses` list:
- **Correctness** (18 tasks: 10 edit + 8 fix) — a positive oracle (substring
grep that the requested change landed, or a scoped `go test -run` that the
bug fix passes). This is the only pass rate that can move with model quality:
`tasksVerified` / `tasksPassed` / `correctnessPassRate`.
- **Build-only** (6 tasks: refactor) — `go build ./...` proves the edit
compiles, not that the refactor achieved its goal (a no-op refactor passes).
The manifest declares `buildOnlyClasses: ["refactor"]`. Reported as
`buildCheckedTasks` / `buildPassedTasks` / `buildPassRate`, never in
`correctnessPassRate`.
- **Latency-only** (24 tasks: nav, longproc, longctx, parallel) — no
`verificationCommand`. An exit 0 only proves the turn ran, not that the answer
was right. They contribute to latency and span attribution only and are
counted in `latencyOnlyTasks`, never in any pass rate.
A task's tier is driven by oracle **presence** first: a task with no
`verificationCommand` is latency-only even if its class is listed in
`buildOnlyClasses`, so a missing oracle can never silently pass on exit 0.
## Known limitations (deferred)
These are accepted for the Phase 0 baseline and tracked in a follow-up issue;
they do not block the baseline because the tier split keeps the report honest:
- The edit grep oracles are substring checks. A rename oracle asserts the new
name is present AND the old name is gone (compound `bash -c`), but an
add-field oracle (`grep -R Label .`) only proves the string appears, not that
it landed on the right struct. Strengthening these to `go vet`/`go build` +
structural assertions is follow-up work.
- The refactor build oracle is non-positive (a no-op refactor passes). A
structural verifier that proves the refactor happened is follow-up work;
until then refactor is `buildPassRate`, not `correctnessPassRate`.
- The 24 read-only tasks have no oracle. Adding deterministic oracles for nav
(diff against an expected answer) and documenting longproc/longctx/parallel
as permanently latency-only is follow-up work.
## Fixtures
Each task's `workspaceFixture` points at a small self-contained workspace under
`testdata/` so the suite runs offline and repeatably. Mutating tasks (edit,
fix, refactor) run against a per-invocation **copy** of their fixture, so the
checked-in fixtures stay clean and one task's edits can't bleed into the next
iteration or a later task.
@@ -0,0 +1,62 @@
{
"id": "zero-baseline-turn",
"name": "Zero per-turn baseline (Phase 0)",
"description": "Latency-first baseline: measures where a turn spends wall time, with pass/fail reported per oracle tier so it cannot be misread as a blanket correctness verdict. Read-only classes (nav, longproc, longctx, parallel) carry no verification oracle — a zero-exit only proves the turn ran, so they count as latency-only and never in any pass rate. Correctness classes (edit, fix) carry a positive oracle (substring grep or a scoped `go test`) and are the only tasks in correctnessPassRate. Build-only classes (refactor) carry `go build ./...`, which proves the edit compiles but not that the refactor achieved its goal, so they are reported as buildPassRate and excluded from correctnessPassRate.",
"buildOnlyClasses": ["refactor"],
"tasks": [
{"id": "nav-01", "name": "list repo files", "class": "nav", "prompt": "List the files in this repository and report their count. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-02", "name": "find a function", "class": "nav", "prompt": "Find the function named 'greet' and report the file and line it is defined on. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-03", "name": "summarize module", "class": "nav", "prompt": "Read main.go and summarize what this program does in two sentences. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-04", "name": "count tests", "class": "nav", "prompt": "Count the test functions (functions whose names start with Test) in this repository and report the number. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-05", "name": "locate a string", "class": "nav", "prompt": "Find every occurrence of the string 'TODO' in the repository and report the files. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-06", "name": "describe package", "class": "nav", "prompt": "Describe the exported API of this package by reading the source. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-07", "name": "trace a call", "class": "nav", "prompt": "Trace which function calls which other function starting from main. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-08", "name": "find imports", "class": "nav", "prompt": "List every third-party import used by this repository. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-09", "name": "report config", "class": "nav", "prompt": "Read config.json and report the keys it contains. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "nav-10", "name": "doc lookup", "class": "nav", "prompt": "Find the doc comment on the greet function and quote it. Do not modify anything.", "workspaceFixture": "../testdata/nav"},
{"id": "edit-01", "name": "rename a constant", "class": "edit", "prompt": "Rename the constant MaxRetries to RetryLimit everywhere it appears.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["bash", "-c", "grep -R RetryLimit . && ! grep -R MaxRetries ."]},
{"id": "edit-02", "name": "fix a typo", "class": "edit", "prompt": "Fix the typo in the comment above the greet function ('receieves' should be 'receives').", "workspaceFixture": "../testdata/edit", "verificationCommand": ["bash", "-c", "! grep -R receieves ."]},
{"id": "edit-03", "name": "add a field", "class": "edit", "prompt": "Add a string field named Label to the Config struct in main.go.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["grep", "-R", "Label", "."]},
{"id": "edit-04", "name": "bump a version", "class": "edit", "prompt": "Change the version string in version.go from 1.0.0 to 1.1.0.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["bash", "-c", "grep -R 1.1.0 . && ! grep -R 1.0.0 ."]},
{"id": "edit-05", "name": "remove a log line", "class": "edit", "prompt": "Remove the line that prints 'debug: starting'.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["bash", "-c", "! grep -R 'debug: starting' ."]},
{"id": "edit-06", "name": "add a license header", "class": "edit", "prompt": "Add a comment line '// SPDX-License-Identifier: MIT' at the top of main.go.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["grep", "-R", "SPDX-License-Identifier", "."]},
{"id": "edit-07", "name": "change a default", "class": "edit", "prompt": "Change the default value of the Port constant from 8080 to 9090.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["bash", "-c", "grep -R 9090 . && ! grep -R 8080 ."]},
{"id": "edit-08", "name": "add a getter", "class": "edit", "prompt": "Add a method func (c *Config) GetLabel() string that returns c.Label.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["bash", "-c", "grep -R 'func (c *Config) GetLabel' ."]},
{"id": "edit-09", "name": "wrap an error", "class": "edit", "prompt": "In the load function, wrap the returned error with fmt.Errorf so it includes 'load failed'.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["grep", "-R", "load failed", "."]},
{"id": "edit-10", "name": "update a message", "class": "edit", "prompt": "Change the printed greeting from 'hello' to 'hello, world'.", "workspaceFixture": "../testdata/edit", "verificationCommand": ["grep", "-R", "hello, world", "."]},
{"id": "fix-01", "name": "off-by-one", "class": "fix", "prompt": "In bugs.go the Sum function has an off-by-one error that skips the last element; fix the loop so it sums all elements.", "workspaceFixture": "../testdata/fix", "verificationCommand": ["go", "test", "-run", "TestSumIncludesLastElement", "./..."]},
{"id": "fix-02", "name": "nil deref", "class": "fix", "prompt": "In bugs.go DefaultConfig returns nil and Port() dereferences it; make DefaultConfig return a valid Config with Port 8080.", "workspaceFixture": "../testdata/fix", "verificationCommand": ["go", "test", "-run", "TestPortReturnsDefault", "./..."]},
{"id": "fix-03", "name": "wrong operator", "class": "fix", "prompt": "In bugs.go Max uses the wrong inequality and returns the smaller value; fix it to return the larger.", "workspaceFixture": "../testdata/fix", "verificationCommand": ["go", "test", "-run", "TestMaxReturnsLarger", "./..."]},
{"id": "fix-04", "name": "truncated read", "class": "fix", "prompt": "In bugs.go ReadFirst returns only a single character instead of the full content; fix it to return the whole string.", "workspaceFixture": "../testdata/fix", "verificationCommand": ["go", "test", "-run", "TestReadFirstReturnsFullContent", "./..."]},
{"id": "fix-05", "name": "swapped args", "class": "fix", "prompt": "In bugs.go Divide swaps its operands; fix the order so Divide(10,2) returns 5.", "workspaceFixture": "../testdata/fix", "verificationCommand": ["go", "test", "-run", "TestDivideOrder", "./..."]},
{"id": "fix-06", "name": "missing return", "class": "fix", "prompt": "In bugs.go Classify is missing a return for the high case; add it so Classify(500) returns \"high\".", "workspaceFixture": "../testdata/fix", "verificationCommand": ["go", "test", "-run", "TestClassifyHigh", "./..."]},
{"id": "fix-07", "name": "wrong label prefix", "class": "fix", "prompt": "In bugs.go Label returns 'admin-<name>' but the test expects 'user-<name>'; change the prefix from 'admin-' to 'user-'.", "workspaceFixture": "../testdata/fix", "verificationCommand": ["go", "test", "-run", "TestLabelUsesString", "./..."]},
{"id": "fix-08", "name": "race on counter", "class": "fix", "prompt": "In bugs.go the global counter is incremented without synchronization; guard it with a mutex.", "workspaceFixture": "../testdata/fix", "verificationCommand": ["go", "test", "-race", "-run", "TestCounterRace", "./..."]},
{"id": "refactor-01", "name": "extract helper", "class": "refactor", "prompt": "Extract the duplicated greeting logic into a single helper function and call it from both sites.", "workspaceFixture": "../testdata/refactor", "verificationCommand": ["go", "build", "./..."]},
{"id": "refactor-02", "name": "split a file", "class": "refactor", "prompt": "Split main.go into two files: one for Config, one for the rest, keeping the package building.", "workspaceFixture": "../testdata/refactor", "verificationCommand": ["go", "build", "./..."]},
{"id": "refactor-03", "name": "rename package", "class": "refactor", "prompt": "Rename the package from app to zeroapp everywhere and keep it building.", "workspaceFixture": "../testdata/refactor", "verificationCommand": ["go", "build", "./..."]},
{"id": "refactor-04", "name": "introduce a type", "class": "refactor", "prompt": "Introduce a named type for the map[string]int used in main.go and update its users.", "workspaceFixture": "../testdata/refactor", "verificationCommand": ["go", "build", "./..."]},
{"id": "refactor-05", "name": "inline a wrapper", "class": "refactor", "prompt": "Inline the thin wrapper function into its single caller and remove it.", "workspaceFixture": "../testdata/refactor", "verificationCommand": ["go", "build", "./..."]},
{"id": "refactor-06", "name": "consolidate errors", "class": "refactor", "prompt": "Consolidate the repeated error-construction blocks into a single helper.", "workspaceFixture": "../testdata/refactor", "verificationCommand": ["go", "build", "./..."]},
{"id": "longproc-01", "name": "long build", "class": "longproc", "prompt": "Run the build command and report whether it succeeds. Do not modify anything.", "workspaceFixture": "../testdata/longproc"},
{"id": "longproc-02", "name": "long test", "class": "longproc", "prompt": "Run go test ./... and report the result. Do not modify anything.", "workspaceFixture": "../testdata/longproc"},
{"id": "longproc-03", "name": "bench run", "class": "longproc", "prompt": "Run go test -bench=. -benchtime=1x and report the benchmark numbers. Do not modify anything.", "workspaceFixture": "../testdata/longproc"},
{"id": "longproc-04", "name": "vet run", "class": "longproc", "prompt": "Run go vet ./... and report the output. Do not modify anything.", "workspaceFixture": "../testdata/longproc"},
{"id": "longctx-01", "name": "summarize large file", "class": "longctx", "prompt": "Read the large generated file big.go and summarize its structure. Do not modify anything.", "workspaceFixture": "../testdata/longctx"},
{"id": "longctx-02", "name": "find in large file", "class": "longctx", "prompt": "In big.go, find every function that returns an error and list them. Do not modify anything.", "workspaceFixture": "../testdata/longctx"},
{"id": "longctx-03", "name": "cross-file question", "class": "longctx", "prompt": "Read all .go files and report which two functions share the same name across files. Do not modify anything.", "workspaceFixture": "../testdata/longctx"},
{"id": "longctx-04", "name": "trace through large file", "class": "longctx", "prompt": "Starting from Handle, trace the call path through big.go and report the chain. Do not modify anything.", "workspaceFixture": "../testdata/longctx"},
{"id": "parallel-01", "name": "read six files", "class": "parallel", "prompt": "Read a.txt, b.txt, c.txt, d.txt, e.txt, and f.txt, then report the first line of each. Do not modify anything.", "workspaceFixture": "../testdata/parallel"},
{"id": "parallel-02", "name": "grep six patterns", "class": "parallel", "prompt": "Search for 'alpha', 'beta', 'gamma', 'delta', 'epsilon', and 'zeta' across the repo and report which files contain each. Do not modify anything.", "workspaceFixture": "../testdata/parallel"},
{"id": "parallel-03", "name": "list six dirs", "class": "parallel", "prompt": "List the contents of dir1, dir2, dir3, dir4, dir5, and dir6. Do not modify anything.", "workspaceFixture": "../testdata/parallel"},
{"id": "parallel-04", "name": "stat six files", "class": "parallel", "prompt": "Report the line count of a.txt, b.txt, c.txt, d.txt, e.txt, and f.txt. Do not modify anything.", "workspaceFixture": "../testdata/parallel"},
{"id": "parallel-05", "name": "read configs", "class": "parallel", "prompt": "Read config1.json, config2.json, config3.json, config4.json, config5.json, and config6.json and report each top-level key. Do not modify anything.", "workspaceFixture": "../testdata/parallel"},
{"id": "parallel-06", "name": "summarize six", "class": "parallel", "prompt": "Read the six .txt files and give a one-line summary of each. Do not modify anything.", "workspaceFixture": "../testdata/parallel"}
]
}
View File
Whitespace-only changes.
+84
View File
@@ -0,0 +1,84 @@
# Per-turn benchmark reports
This directory holds generated per-turn benchmark reports. It is **not** a
checked-in source of truth for performance — the numbers are machine- and
model-specific, so a single snapshot here would mislead rather than inform.
## Generating a baseline
Run the harness over the checked-in manifest:
```sh
make baseline ZERO_BENCH_MODEL=<model> # uses ./zero
make baseline ZERO_BENCH_MODEL=<model> ZERO_BENCH_BINARY=/path/to/zero
```
This builds `zero`, then runs `zero-perf-bench turn` over
`internal/perfbench/manifests/baseline.json`, capturing each turn's trace
(`zero exec --trace <tmpfile>`) and writing the aggregated result to
`reports/baseline.json`.
The JSON report is self-describing: model, mode, self-correct flag, version,
commit, date, per-span median/P95, the **top three controllable latency sources**
ranked by **exclusive** time, per-class roll-ups, and token/count totals.
That top-three list is the Phase 0 baseline's "do not proceed until" criterion —
it names where a turn actually spends time so later optimization work is
targeted, not guessed.
### Attribution model (honest by construction)
Spans record wall intervals and are **not** summed into each other. Each span's
**exclusive** time is its own duration minus the union of its nested children's
intervals, derived at finish by interval containment. So a `provider_connect`
that runs concurrently inside `generation`, or a `permission_wait` nested inside
`tool_execution`, each contributes only its own exclusive time — they no longer
double-count the same wall. The top-latency shares therefore sum to ~1 for a
well-instrumented run, and the ranking reflects where wall time is actually
spent.
**Coverage** is the fraction of wall covered by the union of all span
intervals (capped at 1.0) — the honest "≥95% of wall accounted for" metric. A
run with `coverage < 0.95` has uninstrumented gaps, not an inflated attribution.
### Pass/fail is reported per oracle tier
Pass/fail is split into three tiers so it cannot be misread as a blanket
correctness verdict (see `MANIFEST.md` for the class breakdown):
- **Correctness** (`tasksVerified` / `tasksPassed` / `correctnessPassRate`):
tasks with a positive oracle — edit's substring grep, fix's scoped `go test`.
This is the only pass rate that can move with model quality.
- **Build-only** (`buildCheckedTasks` / `buildPassedTasks` / `buildPassRate`):
refactor's `go build ./...`, which proves the edit compiles but not that the
refactor achieved its goal. Reported separately, never in `correctnessPassRate`.
- **Latency-only** (`latencyOnlyTasks`): the read-only classes (nav, longproc,
longctx, parallel) carry no oracle — an exit 0 only proves the turn ran. They
contribute to latency and span attribution and are excluded from every pass
rate.
`tasksAttempted` is still the total across all three tiers. The tier class lists
are echoed in the report so a consumer can see exactly which classes each rate
is computed over.
> **Do not average the tier pass rates. Do not report a single "pass rate".**
> `correctnessPassRate` and `buildPassRate` measure different things over
> different task sets and must never be combined — a weighted or arithmetic
> mean of the two is a number that means nothing. The schema offers no
> headline pass rate on purpose: a consumer must name the tier it is reporting
> (`correctness`, `build`, or `latency-only`) and quote that tier's fields. A
> read-only run that exits 0 is a latency sample, not a pass.
## What to commit
Commit the manifest and fixtures (`manifests/`, `../testdata/`), not a generated
`baseline.json`. A generated report belongs in a PR description or a shared
dashboard as evidence for one configuration, not in the tree as a durable
expectation. `.gitkeep` keeps the directory present between runs.
## Caveats
- Each task is a fresh `zero exec` process, so iterations are **cold-start**
samples. A warm path (reusing an in-process agent) is future work.
- Mutating tasks (edit/fix/refactor) run against a per-invocation **copy** of
their fixture, so the checked-in fixtures stay clean and one task's edits
can't bleed into the next iteration.
+16 -4
View File
@@ -25,17 +25,29 @@ const TaskSchemaVersion = 1
// ZERO must satisfy. The set is recorded by ID with every result so a published
// number is traceable to the exact tasks that produced it.
type TaskSet struct {
ID string `json:"id"`
Name string `json:"name,omitempty"`
Tasks []BenchTask `json:"tasks"`
ID string `json:"id"`
Name string `json:"name,omitempty"`
Description string `json:"description,omitempty"`
Tasks []BenchTask `json:"tasks"`
// BuildOnlyClasses lists task classes whose verificationCommand is a
// non-positive build check (e.g. refactor's `go build ./...`): it proves the
// edit compiles, not that the refactor achieved its goal. The turn benchmark
// reports these separately from correctness oracles so a build-pass cannot be
// misread as a correctness pass. Classes with a verificationCommand that are
// NOT listed here are treated as correctness classes; classes whose tasks
// carry no verificationCommand are latency-only regardless of this list.
BuildOnlyClasses []string `json:"buildOnlyClasses,omitempty"`
}
// BenchTask is one benchmark task. WorkspaceFixture is the relative path of the
// task's starting workspace; VerificationCommand (optional) is the command the
// default runner executes to decide pass/fail after ZERO finishes.
// default runner executes to decide pass/fail after ZERO finishes. Class groups
// the task for the turn-benchmark's per-group latency breakdown (e.g. "nav",
// "edit", "fix"); it is optional and ignored by the pass/fail runner.
type BenchTask struct {
ID string `json:"id"`
Name string `json:"name,omitempty"`
Class string `json:"class,omitempty"`
Prompt string `json:"prompt"`
WorkspaceFixture string `json:"workspaceFixture,omitempty"`
VerificationCommand []string `json:"verificationCommand,omitempty"`
+42
View File
@@ -0,0 +1,42 @@
// Package edit is a small workspace for the edit-class benchmark tasks: each
// task asks the agent to make one targeted edit, verified by a grep/build
// command in the manifest.
package edit
import (
"fmt"
"os"
)
// Port is the default listen port.
const Port = 8080
// MaxRetries is the maximum number of retries before giving up.
const MaxRetries = 3
// Config holds runtime configuration.
type Config struct {
Name string
}
// greet returns a greeting for the named user.
//
// This receieves a name and formats a hello message.
func greet(name string) string {
return "hello"
}
// load reads a config file and returns its bytes, or an error on failure.
func load(path string) ([]byte, error) {
data, err := os.ReadFile(path)
if err != nil {
return nil, err
}
return data, nil
}
func main() {
fmt.Println("debug: starting")
cfg := Config{Name: "demo"}
fmt.Println(greet(cfg.Name))
}
+4
View File
@@ -0,0 +1,4 @@
package edit
// Version is the build version string.
const Version = "1.0.0"
+89
View File
@@ -0,0 +1,89 @@
// Package fix holds deliberately buggy functions for the bug-fix benchmark
// tasks. Each function is covered by its own test (see bugs_test.go) and each
// task verifies with `go test -run <TestName>`, so the tasks are independent:
// the initial package compiles and the targeted test fails until the named bug
// is fixed. Every bug is fixable without changing a function signature, so the
// test files compile in both the buggy and the fixed state.
package fix
import "fmt"
// Sum returns the sum of all elements. BUG: off-by-one — skips the last element.
func Sum(xs []int) int {
total := 0
for i := 0; i < len(xs)-1; i++ {
total += xs[i]
}
return total
}
// DefaultConfig returns the default configuration. BUG: returns nil, which
// Port() then dereferences.
func DefaultConfig() *Config {
return nil
}
// Config holds demo settings.
type Config struct {
Port int
}
// Port returns the configured port. BUG: panics when DefaultConfig() is nil.
func Port() int {
return DefaultConfig().Port
}
// Max returns the larger of a and b. BUG: uses the wrong inequality and returns
// the smaller value.
func Max(a, b int) int {
if a < b {
return a
}
return b
}
// ReadFirst returns the first byte of the given file's content as a string. BUG:
// returns only a single character instead of the full content.
func ReadFirst(content string) string {
if len(content) == 0 {
return ""
}
return string(content[0])
}
// Divide returns a divided by b. BUG: the operands are swapped.
func Divide(a, b int) int {
return b / a
}
// Classify returns "low", "mid", or "high". BUG: the "high" branch is missing a
// return, so high values fall through to the default "".
func Classify(n int) string {
if n < 10 {
return "low"
}
if n < 100 {
return "mid"
}
// BUG: missing return for the high case
return ""
}
// Label returns a display label for the given name. BUG: uses the wrong prefix
// ("admin-" instead of "user-"), producing the wrong text.
func Label(name string) string {
return fmt.Sprintf("admin-%s", name)
}
// counter is a shared, unsynchronized counter. BUG: Inc is not goroutine-safe.
var counter int
// Inc increments the shared counter.
func Inc() {
counter++
}
// Count returns the current counter value.
func Count() int {
return counter
}
+68
View File
@@ -0,0 +1,68 @@
package fix
import (
"sync"
"testing"
)
func TestSumIncludesLastElement(t *testing.T) {
if got := Sum([]int{1, 2, 3, 4}); got != 10 {
t.Fatalf("Sum = %d, want 10", got)
}
}
func TestPortReturnsDefault(t *testing.T) {
if got := Port(); got != 8080 {
t.Fatalf("Port() = %d, want 8080 (DefaultConfig returned nil)", got)
}
}
func TestMaxReturnsLarger(t *testing.T) {
if got := Max(3, 7); got != 7 {
t.Fatalf("Max(3,7) = %d, want 7", got)
}
}
func TestReadFirstReturnsFullContent(t *testing.T) {
if got := ReadFirst("hello"); got != "hello" {
t.Fatalf("ReadFirst = %q, want %q", got, "hello")
}
}
func TestDivideOrder(t *testing.T) {
if got := Divide(10, 2); got != 5 {
t.Fatalf("Divide(10,2) = %d, want 5", got)
}
}
func TestClassifyHigh(t *testing.T) {
if got := Classify(500); got != "high" {
t.Fatalf("Classify(500) = %q, want %q", got, "high")
}
}
func TestLabelUsesString(t *testing.T) {
if got := Label("alice"); got != "user-alice" {
t.Fatalf("Label = %q, want %q", got, "user-alice")
}
}
// TestCounterRace exercises Inc concurrently. Run with `go test -race`:
// the unsynchronized counter trips the race detector until a mutex is added.
func TestCounterRace(t *testing.T) {
counter = 0
var wg sync.WaitGroup
for i := 0; i < 200; i++ {
wg.Add(1)
go func() {
defer wg.Done()
for j := 0; j < 100; j++ {
Inc()
}
}()
}
wg.Wait()
if got := Count(); got != 20000 {
t.Fatalf("Count = %d, want 20000", got)
}
}
File diff suppressed because it is too large. Load diff
+21
View File
@@ -0,0 +1,21 @@
// Package longproc is a small buildable workspace for the long-running-process
// benchmark tasks, which run build/test/vet/bench commands against it.
package longproc
import "fmt"
// Version is the demo build's version string.
const Version = "1.0.0"
// Process simulates a bounded unit of work for the benchmark task.
func Process(n int) int {
total := 0
for i := 0; i < n; i++ {
total += i
}
return total
}
func main() {
fmt.Println("longproc fixture", Version, Process(100))
}
+21
View File
@@ -0,0 +1,21 @@
package longproc
import "testing"
// benchSink keeps Process(100) live across the benchmark loop so the compiler
// can't optimize the call away and report an unrealistically fast benchmark.
var benchSink int
func TestProcess(t *testing.T) {
if got := Process(100); got != 4950 {
t.Fatalf("Process(100) = %d, want 4950", got)
}
}
func BenchmarkProcess(b *testing.B) {
var sink int
for i := 0; i < b.N; i++ {
sink = Process(100)
}
benchSink = sink
}
+3
View File
@@ -0,0 +1,3 @@
# nav fixture
Small read-only workspace for navigation/classification benchmark tasks.
+5
View File
@@ -0,0 +1,5 @@
{
"port": 8080,
"name": "nav-fixture",
"retries": 3
}
+24
View File
@@ -0,0 +1,24 @@
// Package nav is a small read-only fixture for navigation tasks.
package nav
import "fmt"
// MaxRetries is the configured retry limit for the demo client.
const MaxRetries = 3
// Config holds the demo client's settings.
type Config struct {
Port int
Name string
}
// greet returns a greeting for the given name.
// receieves is a deliberate typo present in the fixture (see edit tasks).
func greet(name string) string {
return fmt.Sprintf("hello, %s", name)
}
// main is the fixture entry point.
func main() {
fmt.Println(greet("world"))
}
+4
View File
@@ -0,0 +1,4 @@
first line of a.txt
second line of a.txt
third line of a.txt
alpha alpha alpha
+4
View File
@@ -0,0 +1,4 @@
first line of b.txt
second line of b.txt
third line of b.txt
beta beta beta
+4
View File
@@ -0,0 +1,4 @@
first line of c.txt
second line of c.txt
third line of c.txt
gamma gamma gamma
+1
View File
@@ -0,0 +1 @@
{ "id": 1, "key": "value-1", "enabled": true }
+1
View File
@@ -0,0 +1 @@
{ "id": 2, "key": "value-2", "enabled": true }
+1
View File
@@ -0,0 +1 @@
{ "id": 3, "key": "value-3", "enabled": true }
+1
View File
@@ -0,0 +1 @@
{ "id": 4, "key": "value-4", "enabled": true }
+1
View File
@@ -0,0 +1 @@
{ "id": 5, "key": "value-5", "enabled": true }
+1
View File
@@ -0,0 +1 @@
{ "id": 6, "key": "value-6", "enabled": true }
+4
View File
@@ -0,0 +1,4 @@
first line of d.txt
second line of d.txt
third line of d.txt
delta delta delta
+1
View File
@@ -0,0 +1 @@
contents of dir1/notes.md
+1
View File
@@ -0,0 +1 @@
contents of dir2/notes.md
+1
View File
@@ -0,0 +1 @@
contents of dir3/notes.md
+1
View File
@@ -0,0 +1 @@
contents of dir4/notes.md
+1
View File
@@ -0,0 +1 @@
contents of dir5/notes.md
+1
View File
@@ -0,0 +1 @@
contents of dir6/notes.md
+4
View File
@@ -0,0 +1,4 @@
first line of e.txt
second line of e.txt
third line of e.txt
epsilon epsilon epsilon
+4
View File
@@ -0,0 +1,4 @@
first line of f.txt
second line of f.txt
third line of f.txt
zeta zeta zeta
+55
View File
@@ -0,0 +1,55 @@
// Package refactor is the starting workspace for the multi-file refactor
// benchmark tasks. It is intentionally a little messy (duplicated logic, a
// bare map type, a thin wrapper) so the refactor prompts have real work to do.
// It builds cleanly at all times; the tasks keep it building.
package refactor
import "fmt"
// Config holds demo settings.
type Config struct {
Name string
Port int
}
// GreetFromConfig returns a greeting using the config's name.
func GreetFromConfig(c Config) string {
return fmt.Sprintf("hello, %s", c.Name)
}
// GreetByName returns a greeting using a bare name. BUG-note: this duplicates
// GreetFromConfig's formatting — refactor-01 extracts a shared helper.
func GreetByName(name string) string {
return fmt.Sprintf("hello, %s", name)
}
// Wrapper is a thin wrapper around GreetByName — refactor-05 inlines it.
func Wrapper(name string) string {
return GreetByName(name)
}
// stats is a bare map used across the file — refactor-04 introduces a named type.
var stats = map[string]int{}
// Record bumps a stat by name.
func Record(name string) {
stats[name]++
}
// Lookup returns a stat by name.
func Lookup(name string) int {
return stats[name]
}
// load failed wrapped error — refactor-06 consolidates these.
func firstError() error {
return fmt.Errorf("load failed: missing input")
}
func secondError() error {
return fmt.Errorf("load failed: bad format")
}
func buildError(ctx string) error {
return fmt.Errorf("load failed: %s", ctx)
}
+679
View File
@@ -0,0 +1,679 @@
package perfbench
import (
"bytes"
"context"
"encoding/json"
"errors"
"fmt"
"io"
"io/fs"
"os"
"os/exec"
"path/filepath"
"sort"
"strings"
"time"
"github.com/Gitlawb/zero/internal/trace"
)
// TurnSchemaVersion is the schema version of a published turn-benchmark result.
// Bump when the TurnBenchResult shape changes so consumers can detect drift.
//
// v2 splits pass/fail into three oracle tiers so the report cannot be misread as
// a blanket correctness verdict: tasksVerified/tasksPassed/correctnessPassRate
// cover only the positive-oracle classes (edit/fix); buildCheckedTasks/
// buildPassedTasks/buildPassRate cover the non-positive build-check classes
// (refactor); latencyOnlyTasks covers the no-oracle classes (nav/longproc/
// longctx/parallel). tasksAttempted is still every task run.
const TurnSchemaVersion = 2
// TurnRunner runs one benchmark task and reports its outcome plus the captured
// per-turn trace. A non-nil Err means the run failed to execute (process crash);
// Passed reflects the verification result. Trace is the parsed NDJSON trace
// (nil when the run errored before emitting one).
type TurnRunner func(ctx context.Context, task BenchTask, rc RunContext) TurnTaskOutcome
// TurnTaskOutcome is what a TurnRunner reports for one task iteration.
type TurnTaskOutcome struct {
Passed bool
VerifyErr string
WallMs float64
Trace *trace.TurnTrace
// TraceIssue, when non-empty, explains why the per-turn trace could not be
// parsed (file missing or malformed). The run still has a pass/fail verdict,
// but an incomplete measurement is surfaced as a result warning so it can't
// masquerade as a clean attribution sample.
TraceIssue string
Err error
}
// TurnBenchConfig configures a turn-benchmark run.
type TurnBenchConfig struct {
Model string
Mode string
SelfCorrect bool
Version string
Commit string
// Iterations is how many times each task is run. The per-process `zero exec`
// runner is inherently cold-start, so this is the sample count for per-span
// median/P95 — a genuine warm path needs an in-process runner (future work).
Iterations int
// Runner executes one task iteration. Required.
Runner TurnRunner
// Now overrides the clock for the recorded date (tests inject a fixed time).
Now func() time.Time
}
// SpanStats summarizes one span's duration across all measured task iterations.
type SpanStats struct {
Count int `json:"count"`
TotalMs float64 `json:"totalMs"`
MedianMs float64 `json:"medianMs"`
P95Ms float64 `json:"p95Ms"`
MaxMs float64 `json:"maxMs"`
}
// LatencySource is one of the top controllable latency sources, ranked by total
// exclusive time across the whole run. Share is its fraction of total exclusive
// span time. Because exclusive time subtracts nested children, concurrent and
// nested spans no longer double-count, so shares of the top sources sum to ~1
// for a well-instrumented run.
type LatencySource struct {
Span string `json:"span"`
TotalMs float64 `json:"totalMs"`
Share float64 `json:"share"`
}
// ClassSummary is the per-class (task group) roll-up.
//
// Passed is the count that passed THIS class's oracle: a correctness pass for
// edit/fix, a build pass for refactor, and always 0 for the no-oracle classes
// (nav/longproc/longctx/parallel). Verified is how many tasks in the class
// carry an oracle (correctness or build); LatencyOnly is how many carry none.
// A latency-only class therefore reports Passed=0, Verified=0, LatencyOnly=Tasks.
type ClassSummary struct {
Tasks int `json:"tasks"`
Verified int `json:"verified"`
Passed int `json:"passed"`
LatencyOnly int `json:"latencyOnly"`
WallMs NumericStats `json:"wallMs"`
SpanTotals map[string]float64 `json:"spanTotals"`
}
// TurnBenchResult is the publishable turn-benchmark record.
//
// Pass/fail is split into three oracle tiers so it cannot be misread as a
// blanket correctness verdict:
// - Correctness (tasksVerified / tasksPassed / correctnessPassRate): tasks
// with a positive oracle (edit/fix). This is the only pass rate that can
// move with model quality.
// - Build-only (buildCheckedTasks / buildPassedTasks / buildPassRate): tasks
// whose oracle is a non-positive build check (refactor `go build`). A pass
// means it compiles, not that the refactor is correct.
// - Latency-only (latencyOnlyTasks): tasks with no oracle (nav/longproc/
// longctx/parallel). They ran for latency and span attribution only and are
// excluded from every pass rate.
//
// tasksAttempted is still the total number of tasks run across all three tiers.
// The tier class lists are echoed so a consumer can see exactly which classes
// each rate is computed over.
type TurnBenchResult struct {
SchemaVersion int `json:"schemaVersion"`
Suite string `json:"suite"`
Model string `json:"model"`
Mode string `json:"mode,omitempty"`
SelfCorrect bool `json:"selfCorrect"`
Version string `json:"version,omitempty"`
Commit string `json:"commit,omitempty"`
Date string `json:"date"`
TasksAttempted int `json:"tasksAttempted"`
TasksVerified int `json:"tasksVerified"`
TasksPassed int `json:"tasksPassed"`
LatencyOnlyTasks int `json:"latencyOnlyTasks"`
BuildCheckedTasks int `json:"buildCheckedTasks"`
BuildPassedTasks int `json:"buildPassedTasks"`
CorrectnessPassRate float64 `json:"correctnessPassRate"`
BuildPassRate float64 `json:"buildPassRate"`
CorrectnessClasses []string `json:"correctnessClasses,omitempty"`
BuildOnlyClasses []string `json:"buildOnlyClasses,omitempty"`
LatencyOnlyClasses []string `json:"latencyOnlyClasses,omitempty"`
Iterations int `json:"iterations"`
PerSpan map[string]SpanStats `json:"perSpan"`
TopLatency []LatencySource `json:"topLatency"`
PerClass map[string]ClassSummary `json:"perClass"`
Totals TurnBenchTotals `json:"totals"`
Warnings []Warning `json:"warnings,omitempty"`
}
// TurnBenchTotals aggregates token and count totals across the whole run.
type TurnBenchTotals struct {
InputTokens int64 `json:"inputTokens"`
CachedInputTokens int64 `json:"cachedInputTokens"`
OutputTokens int64 `json:"outputTokens"`
ModelRequests int64 `json:"modelRequests"`
ToolCalls int64 `json:"toolCalls"`
Retries int64 `json:"retries"`
Reconnects int64 `json:"reconnects"`
Compactions int64 `json:"compactions"`
}
// RunTurnBench executes every task in the set with the configured runner and
// returns a self-describing per-turn result. It never aborts on a single task
// failure — every task is attempted and recorded. Per-span stats aggregate
// across iterations; the top three controllable latency sources are ranked by
// total attributed time.
func RunTurnBench(ctx context.Context, set TaskSet, cfg TurnBenchConfig) (TurnBenchResult, error) {
if len(set.Tasks) == 0 {
return TurnBenchResult{}, errors.New("task set has no tasks")
}
if strings.TrimSpace(cfg.Model) == "" {
return TurnBenchResult{}, errors.New("turn benchmark requires a model")
}
if cfg.Runner == nil {
return TurnBenchResult{}, errors.New("turn benchmark requires a runner")
}
iterations := cfg.Iterations
if iterations < 1 {
iterations = 1
}
now := cfg.Now
if now == nil {
now = time.Now
}
rc := RunContext{Model: cfg.Model, Mode: cfg.Mode, SelfCorrect: cfg.SelfCorrect}
perSpanSamples := map[string][]float64{}
classWalls := map[string][]float64{}
classSpanTotals := map[string]map[string]float64{}
classTasks := map[string]int{}
classVerified := map[string]int{}
classPassed := map[string]int{}
classLatencyOnly := map[string]int{}
correctnessClasses := map[string]bool{}
buildOnlyClasses := map[string]bool{}
latencyOnlyClasses := map[string]bool{}
var totals TurnBenchTotals
// A class is build-only when the manifest declares it in BuildOnlyClasses.
// A task's tier is then decided per-task: no verificationCommand => latency-
// only; otherwise build-only if its class is declared, else correctness. The
// latency-only tier is always driven by oracle presence, never by the
// declared list, so a declared build-only class with a missing oracle still
// counts as latency-only rather than silently passing on exit 0.
buildOnly := map[string]bool{}
for _, c := range set.BuildOnlyClasses {
buildOnly[strings.TrimSpace(c)] = true
}
result := TurnBenchResult{
SchemaVersion: TurnSchemaVersion,
Suite: strings.TrimSpace(set.ID),
Model: strings.TrimSpace(cfg.Model),
Mode: strings.TrimSpace(cfg.Mode),
SelfCorrect: cfg.SelfCorrect,
Version: strings.TrimSpace(cfg.Version),
Commit: strings.TrimSpace(cfg.Commit),
Date: now().UTC().Format(time.RFC3339),
Iterations: iterations,
PerSpan: map[string]SpanStats{},
PerClass: map[string]ClassSummary{},
}
for _, task := range set.Tasks {
if err := ctx.Err(); err != nil {
return result, err
}
class := strings.TrimSpace(task.Class)
if class == "" {
class = "default"
}
classTasks[class]++
// A task counts as passed only when every iteration passed. The per-process
// runner is cold-start, so a flaky pass on one iteration and a fail on
// another is a real regression signal, not noise to average away.
passedForTask := true
for iter := 0; iter < iterations; iter++ {
outcome := cfg.Runner(ctx, task, rc)
if outcome.TraceIssue != "" {
result.Warnings = append(result.Warnings, Warning{
Metric: "trace",
Message: fmt.Sprintf("task %s: %s", task.ID, outcome.TraceIssue),
})
}
if outcome.Err != nil {
// A crashed run must not look like a normal sample that's merely
// absent — surface it as a warning so a run that died every
// iteration can't pass as "fewer measurements."
result.Warnings = append(result.Warnings, Warning{
Metric: "run",
Message: fmt.Sprintf("task %s: %v", task.ID, outcome.Err),
})
passedForTask = false
continue
}
if !outcome.Passed {
passedForTask = false
}
wall := outcome.WallMs
if wall <= 0 && outcome.Trace != nil {
wall = float64(outcome.Trace.WallDuration().Microseconds()) / 1000
}
if wall > 0 {
classWalls[class] = append(classWalls[class], wall)
}
if outcome.Trace != nil {
aggregateTotals(&totals, outcome.Trace)
for _, span := range outcome.Trace.Spans {
// Rank by exclusive time (duration minus nested children) so
// concurrent/nested spans do not double-count: provider_connect
// inside generation and permission_wait inside tool_execution
// each contribute their own exclusive time, not their parent's.
// A span whose exclusive is legitimately zero (a parent fully
// covered by its children) contributes zero on purpose — do
// NOT fall back to Duration, which would re-introduce the
// double-count. ReadNDJSON preserves a written exclusive_ms:0
// as 0 and only falls back to Duration when the key is absent,
// so span.Exclusive is always populated here.
ms := float64(span.Exclusive.Microseconds()) / 1000
perSpanSamples[span.Name] = append(perSpanSamples[span.Name], ms)
if classSpanTotals[class] == nil {
classSpanTotals[class] = map[string]float64{}
}
classSpanTotals[class][span.Name] += ms
}
}
}
result.TasksAttempted++
// Classify the task into an oracle tier and update only that tier's
// counters. A latency-only task (no verificationCommand) is never counted
// in any pass rate even when the runner reports Passed — an exit-0
// read-only run proves the turn ran, not that the answer was right.
hasOracle := len(task.VerificationCommand) > 0
switch {
case !hasOracle:
result.LatencyOnlyTasks++
classLatencyOnly[class]++
latencyOnlyClasses[class] = true
case buildOnly[class]:
result.BuildCheckedTasks++
classVerified[class]++
buildOnlyClasses[class] = true
if passedForTask {
result.BuildPassedTasks++
classPassed[class]++
}
default:
result.TasksVerified++
classVerified[class]++
correctnessClasses[class] = true
if passedForTask {
result.TasksPassed++
classPassed[class]++
}
}
}
for name, samples := range perSpanSamples {
result.PerSpan[name] = summarizeSpan(samples)
}
result.TopLatency = topLatencySources(result.PerSpan, 3)
for class := range classTasks {
walls := classWalls[class]
var wallStats NumericStats
if len(walls) > 0 {
wallStats = SummarizeSamples(walls)
}
result.PerClass[class] = ClassSummary{
Tasks: classTasks[class],
Verified: classVerified[class],
Passed: classPassed[class],
LatencyOnly: classLatencyOnly[class],
WallMs: wallStats,
SpanTotals: classSpanTotals[class],
}
}
result.CorrectnessClasses = sortedSetKeys(correctnessClasses)
result.BuildOnlyClasses = sortedSetKeys(buildOnlyClasses)
result.LatencyOnlyClasses = sortedSetKeys(latencyOnlyClasses)
result.CorrectnessPassRate = passRate(result.TasksPassed, result.TasksVerified)
result.BuildPassRate = passRate(result.BuildPassedTasks, result.BuildCheckedTasks)
result.Totals = totals
return result, nil
}
// passRate is passed/total rounded to the benchmark's metric precision, or 0
// when the denominator is zero (no tasks in that tier were run).
func passRate(passed, total int) float64 {
if total <= 0 {
return 0
}
return RoundMetric(float64(passed) / float64(total))
}
func sortedSetKeys(set map[string]bool) []string {
if len(set) == 0 {
return nil
}
keys := make([]string, 0, len(set))
for k := range set {
keys = append(keys, k)
}
sort.Strings(keys)
return keys
}
func summarizeSpan(samples []float64) SpanStats {
if len(samples) == 0 {
return SpanStats{}
}
stats := SummarizeSamples(samples)
total := 0.0
for _, s := range samples {
total += s
}
return SpanStats{
Count: len(samples),
TotalMs: RoundMetric(total),
MedianMs: stats.Median,
P95Ms: stats.P95,
MaxMs: stats.Max,
}
}
func topLatencySources(perSpan map[string]SpanStats, top int) []LatencySource {
sources := make([]LatencySource, 0, len(perSpan))
totalAttributed := 0.0
for _, s := range perSpan {
totalAttributed += s.TotalMs
}
for name, s := range perSpan {
share := 0.0
if totalAttributed > 0 {
share = s.TotalMs / totalAttributed
}
sources = append(sources, LatencySource{
Span: name,
TotalMs: s.TotalMs,
Share: RoundMetric(share),
})
}
sort.SliceStable(sources, func(i, j int) bool {
if sources[i].TotalMs != sources[j].TotalMs {
return sources[i].TotalMs > sources[j].TotalMs
}
return sources[i].Span < sources[j].Span
})
if top > 0 && len(sources) > top {
sources = sources[:top]
}
return sources
}
func aggregateTotals(totals *TurnBenchTotals, tr *trace.TurnTrace) {
totals.InputTokens += tr.Counter(trace.CounterInputTokens)
totals.CachedInputTokens += tr.Counter(trace.CounterCachedInputTokens)
totals.OutputTokens += tr.Counter(trace.CounterOutputTokens)
totals.ModelRequests += tr.Counter(trace.CounterModelRequests)
totals.ToolCalls += tr.Counter(trace.CounterToolCalls)
totals.Retries += tr.Counter(trace.CounterRetryCount)
totals.Reconnects += tr.Counter(trace.CounterReconnectCount)
totals.Compactions += tr.Counter(trace.CounterCompactionCount)
}
// FormatTurnBenchSummary renders a human-readable turn-benchmark summary that
// names the top controllable latency sources — the baseline's "do not proceed
// until" criterion.
func FormatTurnBenchSummary(result TurnBenchResult) string {
lines := []string{
"Zero turn benchmark: " + displayOrUnknown(result.Suite),
"model: " + displayOrUnknown(result.Model),
// The headline separates the three oracle tiers so an exit-0 read-only
// task can never inflate a "pass rate" that reads as correctness:
// correctness (positive oracle, edit/fix), build (non-positive `go build`,
// refactor), and latency-only (no oracle, nav/longproc/longctx/parallel).
fmt.Sprintf("tasks: %d total | correctness %d/%d (%.0f%%) | build %d/%d (%.0f%%) | latency-only %d | %d iter",
result.TasksAttempted,
result.TasksPassed, result.TasksVerified, result.CorrectnessPassRate*100,
result.BuildPassedTasks, result.BuildCheckedTasks, result.BuildPassRate*100,
result.LatencyOnlyTasks, result.Iterations),
}
if result.Mode != "" {
lines = append(lines, "mode: "+result.Mode)
}
if len(result.TopLatency) > 0 {
lines = append(lines, "top latency sources:")
for _, src := range result.TopLatency {
lines = append(lines, fmt.Sprintf(" %-18s %10s %5.1f%%", src.Span, FormatMetric(src.TotalMs, "ms"), src.Share*100))
}
}
lines = append(lines, fmt.Sprintf("totals: in=%d (cached %d) out=%d | requests=%d tools=%d retries=%d reconnects=%d compactions=%d",
result.Totals.InputTokens, result.Totals.CachedInputTokens, result.Totals.OutputTokens,
result.Totals.ModelRequests, result.Totals.ToolCalls, result.Totals.Retries,
result.Totals.Reconnects, result.Totals.Compactions))
for _, class := range sortedClasses(result.PerClass) {
summary := result.PerClass[class]
median := FormatMetric(summary.WallMs.Median, "ms")
tier := classTier(result, class)
lines = append(lines, fmt.Sprintf(" [%s/%s] %d/%d passed, %d latency-only, wall median %s",
class, tier, summary.Passed, summary.Verified, summary.LatencyOnly, median))
}
return strings.Join(lines, "\n")
}
// classTier returns the oracle tier label a class was classified into, so the
// per-class roll-up states explicitly which oracle (if any) its "passed" count
// is measured against.
func classTier(result TurnBenchResult, class string) string {
for _, c := range result.BuildOnlyClasses {
if c == class {
return "build"
}
}
for _, c := range result.LatencyOnlyClasses {
if c == class {
return "latency"
}
}
return "correctness"
}
func sortedClasses(perClass map[string]ClassSummary) []string {
classes := make([]string, 0, len(perClass))
for c := range perClass {
classes = append(classes, c)
}
sort.Strings(classes)
return classes
}
// WriteTurnBenchJSON writes the indented JSON form of a turn-benchmark result.
func WriteTurnBenchJSON(w io.Writer, result TurnBenchResult) error {
encoder := json.NewEncoder(w)
encoder.SetIndent("", " ")
return encoder.Encode(result)
}
// NewTurnExecRunner builds the production turn-benchmark runner: it invokes
// headless `zero exec` with stream-json output AND `--trace <tmpfile>`, then
// parses the emitted NDJSON trace into a *trace.TurnTrace. binary is the path to
// the `zero` binary; extraArgs are appended to every invocation. Pass/fail is
// decided from the stream-json run_end exit code (and the task's
// VerificationCommand when present), exactly like NewExecRunner.
func NewTurnExecRunner(binary string, extraArgs ...string) TurnRunner {
return func(ctx context.Context, task BenchTask, rc RunContext) TurnTaskOutcome {
// Isolate the workspace: copy the fixture into a fresh temp dir so a
// mutating task (edit/fix/refactor) can't dirty the shared, checked-in
// fixture or bleed into a later iteration of the same task. When no
// fixture is configured the agent runs in the caller's cwd as before.
if fixture := strings.TrimSpace(task.WorkspaceFixture); fixture != "" {
copyDir, cerr := copyFixture(fixture)
if cerr != nil {
return TurnTaskOutcome{Err: fmt.Errorf("isolate fixture: %w", cerr)}
}
defer os.RemoveAll(copyDir)
task.WorkspaceFixture = copyDir
}
traceFile, err := os.CreateTemp("", "zero-turn-trace-*.ndjson")
if err != nil {
return TurnTaskOutcome{Err: fmt.Errorf("create trace file: %w", err)}
}
_ = traceFile.Close()
tracePath := traceFile.Name()
defer os.Remove(tracePath)
args := buildTurnExecArgs(task, rc, tracePath, extraArgs)
cmd := exec.CommandContext(ctx, binary, args...)
cmd.Env = appendNoColor(os.Environ())
if dir := strings.TrimSpace(task.WorkspaceFixture); dir != "" {
cmd.Dir = dir
}
var outBuf, errBuf bytes.Buffer
cmd.Stdout = &outBuf
cmd.Stderr = &errBuf
start := time.Now()
runErr := cmd.Run()
wallMs := float64(time.Since(start).Microseconds()) / 1000
exitCode, haveExit := streamJSONExitCode(outBuf.Bytes())
outcome := TurnTaskOutcome{WallMs: wallMs}
if haveExit && exitCode != 0 {
outcome.VerifyErr = fmt.Sprintf("agent run_end exit code %d", exitCode)
} else if !haveExit {
detail := strings.TrimSpace(errBuf.String())
// If the process never produced a run_end event, the actual failure
// is in runErr (binary missing, exec permission denied, etc.) —
// prefer it over the generic fallback so the real reason survives.
if detail == "" && runErr != nil {
detail = runErr.Error()
}
if detail == "" {
detail = "missing terminal run_end event"
}
outcome.Err = fmt.Errorf("zero exec failed: %s", detail)
return outcome
}
// Parse the captured trace. The trace is the attribution layer, so a
// missing/malformed file is not fatal — but it IS surfaced as a warning
// (via outcome.TraceIssue) so an incomplete measurement can't look valid.
if f, ferr := os.Open(tracePath); ferr != nil {
outcome.TraceIssue = fmt.Sprintf("trace open failed: %v", ferr)
} else {
tr, perr := trace.ReadNDJSON(f)
_ = f.Close()
if perr != nil {
outcome.TraceIssue = fmt.Sprintf("trace parse failed: %v", perr)
} else {
outcome.Trace = tr
}
}
// A nonzero agent exit already decided failure; don't run verification or
// mark the task passed.
if outcome.VerifyErr != "" {
return outcome
}
if len(task.VerificationCommand) > 0 {
if vOutcome := runVerification(ctx, task); !vOutcome.Passed {
outcome.VerifyErr = strings.TrimSpace(vOutcome.Detail)
return outcome
}
// A positive oracle (grep/test/build) passed: this is the only path
// that sets Passed. A task with no verificationCommand is latency-only
// (read-only nav/longproc/longctx/parallel): its exit 0 proves the turn
// ran, not that the answer was right, so it never reports Passed and the
// harness counts it in latencyOnlyTasks rather than any pass rate.
outcome.Passed = true
}
return outcome
}
}
// copyFixture copies the fixture directory at src into a fresh temp dir and
// returns the copy's path. Used to give each benchmark invocation an isolated
// workspace so mutating tasks (edit/fix/refactor) can't dirty the checked-in
// fixture or a later iteration.
func copyFixture(src string) (string, error) {
info, err := os.Stat(src)
if err != nil {
return "", err
}
if !info.IsDir() {
return "", fmt.Errorf("fixture %q is not a directory", src)
}
dst, err := os.MkdirTemp("", "zero-turn-fixture-*")
if err != nil {
return "", err
}
err = filepath.WalkDir(src, func(path string, d fs.DirEntry, werr error) error {
if werr != nil {
return werr
}
rel, rerr := filepath.Rel(src, path)
if rerr != nil {
return rerr
}
target := filepath.Join(dst, rel)
if d.IsDir() {
return os.MkdirAll(target, 0o755)
}
data, rerr := os.ReadFile(path)
if rerr != nil {
return rerr
}
return os.WriteFile(target, data, 0o644)
})
if err != nil {
os.RemoveAll(dst)
return "", err
}
return dst, nil
}
func buildTurnExecArgs(task BenchTask, rc RunContext, tracePath string, extraArgs []string) []string {
args := []string{"exec", "--output-format", "stream-json", "--trace", tracePath}
if model := strings.TrimSpace(rc.Model); model != "" {
args = append(args, "--model", model)
}
if mode := strings.TrimSpace(rc.Mode); mode != "" {
args = append(args, "--mode", mode)
}
if rc.SelfCorrect {
args = append(args, "--self-correct")
}
args = append(args, extraArgs...)
args = append(args, task.Prompt)
return args
}
// ResolveBinary locates the zero binary for a benchmark run: an explicit path
// when provided, else a `zero` (or zero.exe) on PATH, else a binary built into
// the repo root. Returns an error when none is found.
func ResolveBinary(explicit string) (string, error) {
if v := strings.TrimSpace(explicit); v != "" {
if _, err := os.Stat(v); err != nil {
return "", fmt.Errorf("trace binary not found: %w", err)
}
return v, nil
}
if path, err := exec.LookPath("zero"); err == nil {
return path, nil
}
if path, err := exec.LookPath("zero.exe"); err == nil {
return path, nil
}
cwd, err := os.Getwd()
if err == nil {
for _, name := range []string{"zero", "zero.exe"} {
candidate := filepath.Join(cwd, name)
if _, err := os.Stat(candidate); err == nil {
return candidate, nil
}
}
}
return "", errors.New("zero binary not found; build it first or pass an explicit path")
}
+455
View File
@@ -0,0 +1,455 @@
package perfbench
import (
"bytes"
"context"
"encoding/json"
"os"
"path/filepath"
"strings"
"testing"
"time"
"github.com/Gitlawb/zero/internal/trace"
)
// fakeTurnRunner returns a canned *trace.TurnTrace per task so the harness's
// aggregation logic can be exercised without a model or a binary. Each task
// yields one generation span (the dominant cost), one tool_execution span, and
// the counters the totals aggregate.
func fakeTurnRunner(canned map[string]*trace.TurnTrace) TurnRunner {
return func(ctx context.Context, task BenchTask, rc RunContext) TurnTaskOutcome {
tr, ok := canned[task.ID]
if !ok {
return TurnTaskOutcome{Err: errNoCanned}
}
wallMs := float64(tr.WallDuration().Microseconds()) / 1000
return TurnTaskOutcome{Passed: true, WallMs: wallMs, Trace: tr}
}
}
var errNoCanned = &cannedError{}
type cannedError struct{}
func (*cannedError) Error() string { return "no canned trace for task" }
// cannedTrace builds a deterministic *trace.TurnTrace with the given spans and
// counters. Spans are recorded as fixed durations (no real timing) so the
// aggregation math is predictable in assertions.
func cannedTrace(genMs, toolMs int, tokens int64) *trace.TurnTrace {
r := trace.NewRecorder("sess", "run-1", "test")
r.Start()
r.RecordSpan(trace.SpanGeneration, time.Duration(genMs)*time.Millisecond)
r.RecordSpan(trace.SpanToolExecution, time.Duration(toolMs)*time.Millisecond)
r.Counter(trace.CounterInputTokens, tokens)
r.Counter(trace.CounterOutputTokens, tokens/2)
r.Counter(trace.CounterModelRequests, 1)
r.Counter(trace.CounterToolCalls, 1)
r.StampFirstToken()
return r.Finish()
}
func TestRunTurnBenchAggregation(t *testing.T) {
set := TaskSet{
ID: "fake-suite",
Tasks: []BenchTask{
{ID: "t1", Class: "nav", Prompt: "p1"}, // latency-only
{ID: "t2", Class: "nav", Prompt: "p2"}, // latency-only
{ID: "t3", Class: "edit", Prompt: "p3", VerificationCommand: []string{"true"}}, // correctness
{ID: "t4", Class: "refactor", Prompt: "p4", VerificationCommand: []string{"true"}}, // build-only
},
BuildOnlyClasses: []string{"refactor"},
}
canned := map[string]*trace.TurnTrace{
"t1": cannedTrace(100, 10, 1000),
"t2": cannedTrace(300, 10, 1000),
"t3": cannedTrace(200, 50, 2000),
"t4": cannedTrace(150, 20, 1500),
}
cfg := TurnBenchConfig{
Model: "fake-model",
Iterations: 1,
Runner: fakeTurnRunner(canned),
Now: func() time.Time { return time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC) },
}
result, err := RunTurnBench(context.Background(), set, cfg)
if err != nil {
t.Fatalf("RunTurnBench: %v", err)
}
// 4 tasks attempted; the tier split is 2 latency-only, 1 correctness, 1 build.
if result.TasksAttempted != 4 {
t.Fatalf("attempted=%d, want 4", result.TasksAttempted)
}
if result.TasksVerified != 1 || result.TasksPassed != 1 {
t.Fatalf("correctness verified=%d passed=%d, want 1/1", result.TasksVerified, result.TasksPassed)
}
if result.LatencyOnlyTasks != 2 {
t.Fatalf("latencyOnly=%d, want 2", result.LatencyOnlyTasks)
}
if result.BuildCheckedTasks != 1 || result.BuildPassedTasks != 1 {
t.Fatalf("build checked=%d passed=%d, want 1/1", result.BuildCheckedTasks, result.BuildPassedTasks)
}
if result.CorrectnessPassRate != 1.0 {
t.Fatalf("correctnessPassRate=%v, want 1.0", result.CorrectnessPassRate)
}
if result.BuildPassRate != 1.0 {
t.Fatalf("buildPassRate=%v, want 1.0", result.BuildPassRate)
}
if len(result.CorrectnessClasses) != 1 || result.CorrectnessClasses[0] != "edit" {
t.Fatalf("correctnessClasses=%v, want [edit]", result.CorrectnessClasses)
}
if len(result.BuildOnlyClasses) != 1 || result.BuildOnlyClasses[0] != "refactor" {
t.Fatalf("buildOnlyClasses=%v, want [refactor]", result.BuildOnlyClasses)
}
if len(result.LatencyOnlyClasses) != 1 || result.LatencyOnlyClasses[0] != "nav" {
t.Fatalf("latencyOnlyClasses=%v, want [nav]", result.LatencyOnlyClasses)
}
if result.SchemaVersion != TurnSchemaVersion {
t.Fatalf("schemaVersion = %d, want %d", result.SchemaVersion, TurnSchemaVersion)
}
if result.Date != "2026-01-02T03:04:05Z" {
t.Fatalf("date = %q", result.Date)
}
// Per-span: generation appears in all four (100+300+200+150=750ms), tool in
// all four (10+10+50+20=90ms). Count must equal the number of tasks * iterations.
gen := result.PerSpan[trace.SpanGeneration]
if gen.Count != 4 {
t.Fatalf("generation count = %d, want 4", gen.Count)
}
if gen.TotalMs != 750 {
t.Fatalf("generation totalMs = %v, want 750", gen.TotalMs)
}
tool := result.PerSpan[trace.SpanToolExecution]
if tool.TotalMs != 90 {
t.Fatalf("tool totalMs = %v, want 90", tool.TotalMs)
}
// Top latency: generation (750) ranks above tool (90). Exactly two spans
// here, so both appear and generation is first.
if len(result.TopLatency) != 2 || result.TopLatency[0].Span != trace.SpanGeneration {
t.Fatalf("topLatency = %+v", result.TopLatency)
}
if result.TopLatency[0].Share <= result.TopLatency[1].Share {
t.Fatalf("top latency not ranked by share: %+v", result.TopLatency)
}
// Totals: 4 model requests, 4 tool calls, input tokens 1000+1000+2000+1500=5500.
if result.Totals.ModelRequests != 4 {
t.Fatalf("modelRequests = %d, want 4", result.Totals.ModelRequests)
}
if result.Totals.ToolCalls != 4 {
t.Fatalf("toolCalls = %d, want 4", result.Totals.ToolCalls)
}
if result.Totals.InputTokens != 5500 {
t.Fatalf("inputTokens = %d, want 5500", result.Totals.InputTokens)
}
if result.Totals.OutputTokens != 2750 {
t.Fatalf("outputTokens = %d, want 2750", result.Totals.OutputTokens)
}
// Per-class tier roll-up: nav is latency-only (0 verified, 2 latency-only),
// edit is correctness (1/1 verified passed), refactor is build (1/1 passed).
nav := result.PerClass["nav"]
if nav.Tasks != 2 || nav.Verified != 0 || nav.Passed != 0 || nav.LatencyOnly != 2 {
t.Fatalf("nav class = %+v", nav)
}
edit := result.PerClass["edit"]
if edit.Tasks != 1 || edit.Verified != 1 || edit.Passed != 1 || edit.LatencyOnly != 0 {
t.Fatalf("edit class = %+v", edit)
}
refactor := result.PerClass["refactor"]
if refactor.Tasks != 1 || refactor.Verified != 1 || refactor.Passed != 1 || refactor.LatencyOnly != 0 {
t.Fatalf("refactor class = %+v", refactor)
}
}
// TestRunTurnBenchLatencyOnlyNeverPassed asserts the honesty gate: a task with
// no verificationCommand reports Passed=true from the (stub) runner, yet the
// harness counts it ONLY in latencyOnlyTasks — never in tasksPassed or any pass
// rate — so an exit-0 read-only run cannot inflate a correctness number.
func TestRunTurnBenchLatencyOnlyNeverPassed(t *testing.T) {
set := TaskSet{
ID: "lo-suite",
Tasks: []BenchTask{
{ID: "n1", Class: "nav", Prompt: "p"}, // no oracle — runner still says Passed=true
},
}
cfg := TurnBenchConfig{
Model: "fake-model",
Runner: fakeTurnRunner(map[string]*trace.TurnTrace{"n1": cannedTrace(50, 5, 100)}),
Now: func() time.Time { return time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC) },
}
result, err := RunTurnBench(context.Background(), set, cfg)
if err != nil {
t.Fatalf("RunTurnBench: %v", err)
}
if result.TasksPassed != 0 || result.TasksVerified != 0 {
t.Fatalf("latency-only leaked into pass: passed=%d verified=%d, want 0/0",
result.TasksPassed, result.TasksVerified)
}
if result.CorrectnessPassRate != 0 || result.BuildPassRate != 0 {
t.Fatalf("pass rates should be 0 with no oracle tasks: c=%v b=%v",
result.CorrectnessPassRate, result.BuildPassRate)
}
if result.LatencyOnlyTasks != 1 {
t.Fatalf("latencyOnlyTasks=%d, want 1", result.LatencyOnlyTasks)
}
if result.PerClass["nav"].Passed != 0 || result.PerClass["nav"].LatencyOnly != 1 {
t.Fatalf("nav class = %+v, want passed=0 latencyOnly=1", result.PerClass["nav"])
}
}
func TestRunTurnBenchIterationsAggregates(t *testing.T) {
set := TaskSet{
ID: "iter-suite",
Tasks: []BenchTask{{ID: "t1", Class: "nav", Prompt: "p1"}},
}
canned := map[string]*trace.TurnTrace{"t1": cannedTrace(100, 10, 500)}
cfg := TurnBenchConfig{
Model: "fake-model",
Iterations: 3,
Runner: fakeTurnRunner(canned),
Now: func() time.Time { return time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC) },
}
result, err := RunTurnBench(context.Background(), set, cfg)
if err != nil {
t.Fatalf("RunTurnBench: %v", err)
}
if result.PerSpan[trace.SpanGeneration].Count != 3 {
t.Fatalf("generation count = %d, want 3 (one per iteration)", result.PerSpan[trace.SpanGeneration].Count)
}
if result.PerSpan[trace.SpanGeneration].TotalMs != 300 {
t.Fatalf("generation totalMs = %v, want 300", result.PerSpan[trace.SpanGeneration].TotalMs)
}
}
func TestRunTurnBenchRequiresModelAndRunner(t *testing.T) {
set := TaskSet{ID: "s", Tasks: []BenchTask{{ID: "t", Prompt: "p"}}}
if _, err := RunTurnBench(context.Background(), set, TurnBenchConfig{Runner: fakeTurnRunner(nil)}); err == nil {
t.Fatal("expected error for missing model")
}
if _, err := RunTurnBench(context.Background(), set, TurnBenchConfig{Model: "m"}); err == nil {
t.Fatal("expected error for missing runner")
}
if _, err := RunTurnBench(context.Background(), TaskSet{ID: "empty"}, TurnBenchConfig{Model: "m", Runner: fakeTurnRunner(nil)}); err == nil {
t.Fatal("expected error for empty task set")
}
}
func TestTopLatencySourcesRanksByTotalAndCapsTopN(t *testing.T) {
perSpan := map[string]SpanStats{
"a": {TotalMs: 100},
"b": {TotalMs: 500},
"c": {TotalMs: 300},
"d": {TotalMs: 50},
}
top := topLatencySources(perSpan, 3)
if len(top) != 3 {
t.Fatalf("len = %d, want 3", len(top))
}
wantOrder := []string{"b", "c", "a"}
for i, w := range wantOrder {
if top[i].Span != w {
t.Fatalf("top[%d] = %q, want %q", i, top[i].Span, w)
}
}
// Shares sum to 1 across all four (100+500+300+50=950); the top-3 retain
// their global share (not renormalized to the top-3).
// Share is rounded to 2 decimals by RoundMetric (500/950 -> 0.53), so compare
// against the rounded value with a small tolerance.
if got, want := top[0].Share, RoundMetric(500.0/950.0); !approxEqual(got, want, 0.001) {
t.Fatalf("top[0] share = %v, want %v", got, want)
}
}
func TestWriteTurnBenchJSONRoundTrip(t *testing.T) {
set := TaskSet{ID: "json-suite", Tasks: []BenchTask{
{ID: "t1", Class: "edit", Prompt: "p1", VerificationCommand: []string{"true"}},
}}
canned := map[string]*trace.TurnTrace{"t1": cannedTrace(150, 20, 800)}
result, err := RunTurnBench(context.Background(), set, TurnBenchConfig{
Model: "fake-model",
Runner: fakeTurnRunner(canned),
Now: func() time.Time { return time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC) },
})
if err != nil {
t.Fatalf("RunTurnBench: %v", err)
}
var buf bytes.Buffer
if err := WriteTurnBenchJSON(&buf, result); err != nil {
t.Fatalf("WriteTurnBenchJSON: %v", err)
}
var decoded TurnBenchResult
if err := json.Unmarshal(buf.Bytes(), &decoded); err != nil {
t.Fatalf("unmarshal: %v\n%s", err, buf.String())
}
if decoded.SchemaVersion != TurnSchemaVersion {
t.Fatalf("schemaVersion = %d, want %d", decoded.SchemaVersion, TurnSchemaVersion)
}
if decoded.TasksVerified != 1 || decoded.TasksPassed != 1 || decoded.LatencyOnlyTasks != 0 {
t.Fatalf("decoded tier counts = verified=%d passed=%d latency=%d, want 1/1/0",
decoded.TasksVerified, decoded.TasksPassed, decoded.LatencyOnlyTasks)
}
if decoded.CorrectnessPassRate != 1.0 {
t.Fatalf("decoded correctnessPassRate = %v, want 1.0", decoded.CorrectnessPassRate)
}
if decoded.PerSpan[trace.SpanGeneration].TotalMs != 150 {
t.Fatalf("decoded generation totalMs = %v, want 150", decoded.PerSpan[trace.SpanGeneration].TotalMs)
}
}
func TestFormatTurnBenchSummaryNamesTopSources(t *testing.T) {
set := TaskSet{ID: "fmt-suite", Tasks: []BenchTask{{ID: "t1", Class: "nav", Prompt: "p1"}}}
canned := map[string]*trace.TurnTrace{"t1": cannedTrace(150, 20, 800)}
result, err := RunTurnBench(context.Background(), set, TurnBenchConfig{
Model: "fake-model",
Runner: fakeTurnRunner(canned),
Now: func() time.Time { return time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC) },
})
if err != nil {
t.Fatalf("RunTurnBench: %v", err)
}
summary := FormatTurnBenchSummary(result)
if !strings.Contains(summary, "top latency sources") {
t.Fatalf("summary missing top-latency header:\n%s", summary)
}
if !strings.Contains(summary, trace.SpanGeneration) {
t.Fatalf("summary missing top span name %q:\n%s", trace.SpanGeneration, summary)
}
}
func TestLoadBaselineManifest(t *testing.T) {
path := filepath.Join("manifests", "baseline.json")
set, err := LoadTaskSet(path)
if err != nil {
t.Fatalf("LoadTaskSet: %v", err)
}
if set.ID == "" {
t.Fatal("manifest has no id")
}
// The baseline must clear the "do not proceed until ≥30 tasks" gate.
if len(set.Tasks) < 30 {
t.Fatalf("baseline has %d tasks, want >= 30", len(set.Tasks))
}
// The six required classes must all be present and non-empty.
wantClasses := map[string]bool{
"nav": false, "edit": false, "fix": false,
"refactor": false, "longproc": false, "longctx": false, "parallel": false,
}
counts := map[string]int{}
for _, task := range set.Tasks {
class := strings.TrimSpace(task.Class)
if class == "" {
t.Fatalf("task %q has no class", task.ID)
}
if _, ok := wantClasses[class]; !ok {
t.Fatalf("unexpected class %q on task %q", class, task.ID)
}
wantClasses[class] = true
counts[class]++
}
for class, present := range wantClasses {
if !present {
t.Fatalf("manifest missing required class %q", class)
}
if counts[class] == 0 {
t.Fatalf("class %q has zero tasks", class)
}
}
// Every task must have a prompt and a workspace fixture pointing under testdata,
// and that fixture must actually exist on disk — a manifest referencing a
// missing fixture would make every task in its class error out at run time, so
// catch it at load time instead.
seen := map[string]bool{}
for _, task := range set.Tasks {
if strings.TrimSpace(task.Prompt) == "" {
t.Fatalf("task %q has empty prompt", task.ID)
}
if strings.TrimSpace(task.WorkspaceFixture) == "" {
t.Fatalf("task %q has no workspace fixture", task.ID)
}
if !strings.Contains(task.WorkspaceFixture, "testdata") {
t.Fatalf("task %q fixture %q not under testdata", task.ID, task.WorkspaceFixture)
}
if seen[task.WorkspaceFixture] {
continue
}
seen[task.WorkspaceFixture] = true
info, err := os.Stat(task.WorkspaceFixture)
if err != nil {
t.Fatalf("task %q fixture %q does not exist: %v", task.ID, task.WorkspaceFixture, err)
}
if !info.IsDir() {
t.Fatalf("task %q fixture %q is not a directory", task.ID, task.WorkspaceFixture)
}
}
}
func approxEqual(a, b, tol float64) bool {
d := a - b
if d < 0 {
d = -d
}
return d < tol
}
// TestCopyFixtureIsolatesSourceFromMutation asserts the property that lets a
// mutating task run twice (or across iterations) without poisoning the next
// sample: the runner operates on a per-invocation copy, so mutating the copy
// leaves the checked-in source fixture byte-identical. This is verified by
// reading the code today; a test makes it durable against future refactors of
// the runner's isolation path.
func TestCopyFixtureIsolatesSourceFromMutation(t *testing.T) {
src, err := os.MkdirTemp("", "zero-fixture-src-*")
if err != nil {
t.Fatalf("mkdtemp src: %v", err)
}
defer os.RemoveAll(src)
orig := "package main\n\nfunc main() {}\n"
if err := os.WriteFile(filepath.Join(src, "main.go"), []byte(orig), 0o644); err != nil {
t.Fatalf("write fixture: %v", err)
}
if err := os.MkdirAll(filepath.Join(src, "sub"), 0o755); err != nil {
t.Fatalf("mkdir sub: %v", err)
}
if err := os.WriteFile(filepath.Join(src, "sub", "a.go"), []byte("package sub\n"), 0o644); err != nil {
t.Fatalf("write sub: %v", err)
}
// Snapshot the source tree before any mutation of the copy.
wantMain, err := os.ReadFile(filepath.Join(src, "main.go"))
if err != nil {
t.Fatalf("read source main.go: %v", err)
}
copyDir, err := copyFixture(src)
if err != nil {
t.Fatalf("copyFixture: %v", err)
}
defer os.RemoveAll(copyDir)
// The copy must be a real copy, not a symlink/alias of the source, and
// mutating it must not touch the source.
if copyDir == src {
t.Fatalf("copyFixture returned the source dir, not a copy: %s", copyDir)
}
if err := os.WriteFile(filepath.Join(copyDir, "main.go"), []byte("package main\n\n// mutated\nfunc main() {}\n"), 0o644); err != nil {
t.Fatalf("mutate copy: %v", err)
}
if err := os.WriteFile(filepath.Join(copyDir, "new.go"), []byte("package main\n"), 0o644); err != nil {
t.Fatalf("add file to copy: %v", err)
}
gotMain, err := os.ReadFile(filepath.Join(src, "main.go"))
if err != nil {
t.Fatalf("re-read source main.go: %v", err)
}
if string(gotMain) != string(wantMain) {
t.Fatalf("source fixture mutated by copy: got %q, want %q", gotMain, wantMain)
}
if _, err := os.Stat(filepath.Join(src, "new.go")); !os.IsNotExist(err) {
t.Fatalf("file added to copy appeared in source: %v", err)
}
}
+7
View File
@@ -4,6 +4,8 @@ import (
"context"
"net/http"
"strings"
"github.com/Gitlawb/zero/internal/trace"
)
// TokenResolver yields a fresh OAuth credential for one request, or ok=false to
@@ -42,7 +44,12 @@ func SendWithAuthRetry(
// request (leaking the path/body) before we return the error.
headers := base
if resolver != nil {
// ProviderQueue captures pre-send auth-wait (OAuth token resolve). No
// send-side semaphore exists today; a future request queue would also
// accumulate here. nil recorder (untraced) is a no-op.
queueSpan := trace.FromContext(ctx).Span(trace.SpanProviderQueue)
header, value, ok, rerr := resolver(ctx, forceRefresh)
queueSpan.End()
if rerr != nil {
return nil, rerr
}
@@ -16,6 +16,7 @@ import (
"strings"
"time"
"github.com/Gitlawb/zero/internal/trace"
"github.com/Gitlawb/zero/internal/zeroruntime"
)
@@ -371,9 +372,15 @@ func ScanSSEDataWithContext(
// The provider asked to stop (e.g. it already emitted an error
// for this payload). Abort the read and end like ScanSSEData:
// return nil so callers fall through to their post-scan checks.
// Do not stamp FirstToken — this payload was not accepted model
// output, so counting it as first-token time would be misleading.
cancel()
return nil
}
// First accepted non-keepalive payload = first real model output. Stamp
// once; later real payloads are no-ops. nil recorder (untraced run) is a
// no-op.
trace.FromContext(ctx).StampFirstToken()
}
}
}
+7
View File
@@ -7,6 +7,8 @@ import (
"strconv"
"strings"
"time"
"github.com/Gitlawb/zero/internal/trace"
)
// Transient-failure retry, shared by every provider.
@@ -67,7 +69,9 @@ func SendWithRetry(
setHeader(request)
}
connectSpan := trace.FromContext(ctx).Span(trace.SpanProviderConnect)
response, err := client.Do(request)
connectSpan.End()
if err != nil {
// A transport failure on a POST does NOT mean the server didn't receive
// it — the request may have arrived and be generating a (billable,
@@ -82,6 +86,9 @@ func SendWithRetry(
}
if ShouldRetryStatus(response.StatusCode) && attempt < maxAttempts {
if r := trace.FromContext(ctx); r != nil {
r.Counter(trace.CounterRetryCount, 1)
}
wait := RetryAfter(response)
_ = response.Body.Close()
if Backoff(ctx, attempt, wait) {
+25
View File
@@ -0,0 +1,25 @@
package trace
import "context"
type ctxKey struct{}
// WithContext returns a copy of ctx that carries r, so the providerio seam
// and other lower layers can reach the recorder without changing their
// function signatures. Passing a nil recorder still injects a value (a nil
// *Recorder), but FromContext returns nil for it so downstream no-op guards
// see nil.
func WithContext(ctx context.Context, r *Recorder) context.Context {
return context.WithValue(ctx, ctxKey{}, r)
}
// FromContext returns the recorder carried by ctx, or nil if none is present
// (or if the carried value is nil). Callers must guard all stamps with a nil
// check; the recorder methods are themselves nil-safe.
func FromContext(ctx context.Context) *Recorder {
if ctx == nil {
return nil
}
v, _ := ctx.Value(ctxKey{}).(*Recorder)
return v
}
+193
View File
@@ -0,0 +1,193 @@
package trace
import (
"encoding/json"
"fmt"
"io"
"sort"
"time"
)
// Sink is the abstraction a finished TurnTrace is written to. The NDJSON and
// text sinks are implemented here; an OpenTelemetry sink is a documented
// future addition (see opentelemetrySink below) and is intentionally not
// pulled in as a dependency.
type Sink interface {
Emit(*TurnTrace) error
}
// WriteNDJSON emits the trace as newline-delimited JSON compatible with the
// internal/agenteval trace contract: one object per line carrying a "type"
// and (for spans/counters) a "name" so ParseTraceEventKeys keys them.
//
// The first line is a "trace" summary (name "run"), followed by one "span"
// line per span occurrence and one "counter" line per counter. Span lines
// carry the wall interval (start/end), inclusive duration, exclusive
// duration, and parent — the data the harness needs to rank latency sources
// without double-counting nested/concurrent work. Spans are emitted in stable
// (name, then start) order for deterministic output; counters are sorted.
func WriteNDJSON(w io.Writer, t *TurnTrace) error {
if w == nil {
return nil
}
if t == nil {
return nil
}
enc := json.NewEncoder(w)
enc.SetEscapeHTML(false)
if err := enc.Encode(map[string]any{
"type": "trace",
"name": "run",
"session_id": t.SessionID,
"run_id": t.RunID,
"profile": t.Profile,
"started_at": formatTime(t.StartedAt),
"first_visible_at": formatTime(t.FirstVisibleEventAt),
"first_useful_at": formatTime(t.FirstUsefulActionAt),
"first_token_at": formatTime(t.FirstTokenAt),
"completed_at": formatTime(t.CompletedAt),
"wall_ms": ms(t.WallDuration()),
"attributed_ms": ms(t.AttributedDuration()),
"coverage": round3(t.Coverage()),
"attribution": round3(t.AttributionRatio()),
}); err != nil {
return err
}
spans := append([]Span(nil), t.Spans...)
sort.SliceStable(spans, func(i, j int) bool {
if spans[i].Name != spans[j].Name {
return spans[i].Name < spans[j].Name
}
return spans[i].Start.Before(spans[j].Start)
})
for _, span := range spans {
obj := map[string]any{
"type": "span",
"name": span.Name,
"duration_ms": ms(span.Duration),
"exclusive_ms": ms(span.Exclusive),
}
if !span.Start.IsZero() {
obj["start"] = formatTime(span.Start)
}
if !span.End.IsZero() {
obj["end"] = formatTime(span.End)
}
if span.Parent != "" {
obj["parent"] = span.Parent
}
if err := enc.Encode(obj); err != nil {
return err
}
}
counters := append([]Counter(nil), t.Counters...)
sort.Slice(counters, func(i, j int) bool { return counters[i].Name < counters[j].Name })
for _, c := range counters {
if err := enc.Encode(map[string]any{
"type": "counter",
"name": c.Name,
"value": c.Value,
}); err != nil {
return err
}
}
return nil
}
// WriteText emits a human-readable trace: a header, one line per span with its
// exclusive time and share of wall, a coverage line, then counters. It returns
// the first write error encountered so a failing sink (e.g. a full disk) is not
// silently swallowed.
func WriteText(w io.Writer, t *TurnTrace) error {
if w == nil || t == nil {
return nil
}
wall := t.WallDuration()
var firstErr error
write := func(format string, args ...any) {
if firstErr != nil {
return
}
if _, err := fmt.Fprintf(w, format, args...); err != nil {
firstErr = err
}
}
write("trace run=%s session=%s profile=%s\n", t.RunID, t.SessionID, t.Profile)
write(" started=%s completed=%s wall=%s\n", formatTime(t.StartedAt), formatTime(t.CompletedAt), wall)
write(" attributed=%s coverage=%.1f%%\n", t.AttributedDuration(), t.Coverage()*100)
if !t.FirstVisibleEventAt.IsZero() {
write(" first_visible_event=%s (+%s)\n", formatTime(t.FirstVisibleEventAt), t.FirstVisibleEventAt.Sub(t.StartedAt))
}
if !t.FirstUsefulActionAt.IsZero() {
write(" first_useful_action=%s (+%s)\n", formatTime(t.FirstUsefulActionAt), t.FirstUsefulActionAt.Sub(t.StartedAt))
}
if !t.FirstTokenAt.IsZero() {
write(" first_token=%s (+%s)\n", formatTime(t.FirstTokenAt), t.FirstTokenAt.Sub(t.StartedAt))
}
spans := append([]Span(nil), t.Spans...)
sort.SliceStable(spans, func(i, j int) bool {
if spans[i].Name != spans[j].Name {
return spans[i].Name < spans[j].Name
}
return spans[i].Start.Before(spans[j].Start)
})
write("spans:\n")
for _, span := range spans {
share := 0.0
if wall > 0 {
share = float64(span.Exclusive) / float64(wall)
}
parent := ""
if span.Parent != "" {
parent = " [" + span.Parent + "]"
}
write(" %-18s %10s excl=%-10s %5.1f%%%s\n", span.Name, span.Duration, span.Exclusive, share*100, parent)
}
counters := append([]Counter(nil), t.Counters...)
sort.Slice(counters, func(i, j int) bool { return counters[i].Name < counters[j].Name })
write("counters:\n")
for _, c := range counters {
write(" %-22s %d\n", c.Name, c.Value)
}
return firstErr
}
// NDJSONSink adapts an io.Writer as a Sink emitting NDJSON.
type NDJSONSink struct{ W io.Writer }
func (s NDJSONSink) Emit(t *TurnTrace) error { return WriteNDJSON(s.W, t) }
// TextSink adapts an io.Writer as a Sink emitting human-readable text.
type TextSink struct{ W io.Writer }
func (s TextSink) Emit(t *TurnTrace) error { return WriteText(s.W, t) }
// opentelemetrySink is a placeholder documenting the future OpenTelemetry
// export path. It is intentionally not implemented in the baseline: doing so
// would pull in the OTLP exporter dependency. When added, satisfy Sink by
// translating each Span into an OTLP span and each Counter into an attribute,
// parented under the run's trace:
//
// type opentelemetrySink struct{ exp someExporter }
// func (s opentelemetrySink) Emit(t *TurnTrace) error { ... }
//
// It is left as a comment to avoid an unused-type lint while signaling the
// intended extension seam to the next PR.
func ms(d time.Duration) float64 { return round3(float64(d.Microseconds()) / 1000) }
func round3(v float64) float64 {
return float64(int64(v*1000+0.5)) / 1000
}
func formatTime(t time.Time) string {
if t.IsZero() {
return ""
}
return t.UTC().Format(time.RFC3339Nano)
}
+183
View File
@@ -0,0 +1,183 @@
package trace
import (
"bufio"
"encoding/json"
"errors"
"io"
"strings"
"time"
)
// ReadNDJSON parses an NDJSON trace emitted by WriteNDJSON back into a TurnTrace.
// It is the inverse of WriteNDJSON and is used by the benchmark harness to turn a
// captured trace file into structured per-span stats.
//
// It fails loudly on a corrupt file rather than silently returning an empty
// trace. Empty or blank-only input is an error (an empty trace file means
// emission never happened — e.g. the agent crashed before writing the header
// or --trace was not honored — and must not masquerade as a valid zero-
// attribution sample). A non-empty input must contain a "type":"trace" header
// line; span/counter lines before it are an error; and a header that yields no
// spans and no counters is treated as corrupt. Individual span/counter lines
// with bad JSON are skipped only when a valid "trace" header has already been
// seen — a truncated middle of a real trace should not fatal a run.
//
// Numbers are decoded with UseNumber so counter values round-trip as exact
// int64s rather than going through float64 (which loses precision above 2^53).
func ReadNDJSON(r io.Reader) (*TurnTrace, error) {
if r == nil {
return nil, nil
}
t := &TurnTrace{}
scanner := bufio.NewScanner(r)
scanner.Buffer(make([]byte, 0, 64*1024), 4*1024*1024)
sawInput := false
sawTraceHeader := false
for scanner.Scan() {
line := strings.TrimSpace(scanner.Text())
if line == "" {
continue
}
sawInput = true
var obj map[string]any
dec := json.NewDecoder(strings.NewReader(line))
dec.UseNumber()
if err := dec.Decode(&obj); err != nil {
// A non-JSON line before any header means the file is not a trace.
if !sawTraceHeader {
return nil, errors.New("parse trace: not a valid NDJSON trace (no type:trace header)")
}
continue
}
typ, _ := obj["type"].(string)
switch typ {
case "trace":
sawTraceHeader = true
t.RunID, _ = obj["run_id"].(string)
t.SessionID, _ = obj["session_id"].(string)
t.Profile, _ = obj["profile"].(string)
t.StartedAt = parseTime(obj["started_at"])
t.FirstVisibleEventAt = parseTime(obj["first_visible_at"])
t.FirstUsefulActionAt = parseTime(obj["first_useful_at"])
t.FirstTokenAt = parseTime(obj["first_token_at"])
t.CompletedAt = parseTime(obj["completed_at"])
case "span":
if !sawTraceHeader {
return nil, errors.New("parse trace: not a valid NDJSON trace (no type:trace header)")
}
name, _ := obj["name"].(string)
s := Span{
Name: name,
Start: parseTime(obj["start"]),
End: parseTime(obj["end"]),
Duration: parseDurationMs(obj["duration_ms"]),
}
if s.End.IsZero() && !s.Start.IsZero() {
s.End = s.Start.Add(s.Duration)
}
// Preserve exclusive time exactly as written. A legitimately-zero
// exclusive (a parent whose children cover its whole interval) is
// emitted as exclusive_ms: 0 and MUST round-trip as 0 — falling back
// to Duration here would re-introduce the double-counting the
// exclusive-time model exists to prevent. Only fall back to Duration
// when the key is genuinely absent (an older/duration-only emitter).
if ev, ok := obj["exclusive_ms"]; ok {
s.Exclusive = parseDurationMs(ev)
} else {
s.Exclusive = s.Duration
}
if v, ok := obj["parent"].(string); ok {
s.Parent = v
}
t.Spans = append(t.Spans, s)
case "counter":
if !sawTraceHeader {
return nil, errors.New("parse trace: not a valid NDJSON trace (no type:trace header)")
}
name, _ := obj["name"].(string)
t.Counters = append(t.Counters, Counter{Name: name, Value: parseInt64(obj["value"])})
default:
// Unknown event type: tolerate (forward-compat) but only after a
// header has been seen.
if !sawTraceHeader {
return nil, errors.New("parse trace: not a valid NDJSON trace (no type:trace header)")
}
}
}
if err := scanner.Err(); err != nil {
return nil, err
}
if !sawInput {
// Empty or blank-only input: emission never produced a trace line, so
// this is not a valid trace. Surface it so the harness records a
// TraceIssue rather than treating a crashed run as clean zero-attribution.
return nil, errors.New("parse trace: empty input (no trace emitted)")
}
if !sawTraceHeader {
return nil, errors.New("parse trace: non-empty input had no type:trace header")
}
if len(t.Spans) == 0 && len(t.Counters) == 0 {
return nil, errors.New("parse trace: header present but no spans or counters recovered (corrupt or truncated)")
}
return t, nil
}
func parseTime(v any) time.Time {
s, _ := v.(string)
if s == "" {
return time.Time{}
}
t, err := time.Parse(time.RFC3339Nano, s)
if err != nil {
return time.Time{}
}
return t
}
func parseDurationMs(v any) time.Duration {
f := toFloat64(v)
return time.Duration(f * float64(time.Millisecond))
}
// parseInt64 parses a counter value. json.Number (from UseNumber) is parsed
// directly to int64 so large counters round-trip without float64 precision
// loss; other numeric kinds fall back to a float conversion.
func parseInt64(v any) int64 {
switch n := v.(type) {
case json.Number:
if i, err := n.Int64(); err == nil {
return i
}
if f, err := n.Float64(); err == nil {
return int64(f)
}
return 0
case float64:
return int64(n)
case int64:
return n
case int:
return int64(n)
default:
return int64(toFloat64(v))
}
}
func toFloat64(v any) float64 {
switch n := v.(type) {
case json.Number:
if f, err := n.Float64(); err == nil {
return f
}
return 0
case float64:
return n
case int64:
return float64(n)
case int:
return float64(n)
default:
return 0
}
}
+325
View File
@@ -0,0 +1,325 @@
package trace
import (
"sort"
"sync"
"time"
)
// Recorder is the in-process handle one agent.Run stamps spans and counters
// into. It is concurrency-safe: parallel tool execution, provider reconnects,
// and async streaming stamp concurrently from different goroutines.
//
// A nil *Recorder is valid to call: the no-op helpers below route every
// stamp through a nil check so callers can write `options.Trace.Start()`
// unconditionally and pay nothing when tracing is off.
//
// Spans are stored as occurrences (one entry per stamp) with their wall
// interval. Parent/child nesting and exclusive time are derived at Finish by
// interval containment, so concurrent (provider_connect inside generation) and
// nested (permission_wait inside tool_execution) spans are not double-counted.
type Recorder struct {
mu sync.Mutex
tr TurnTrace
cursor time.Time // synthesis cursor for RecordSpan (no real interval)
started bool
finished bool
firstTokenStamped bool
firstVisibleStamped bool
firstActionStamped bool
}
// NewRecorder returns a ready recorder. sessionID correlates with the agent
// session (Options.SessionID); runID is a per-Run sequence; profile is an
// optional label (e.g. "cold", "warm") for benchmark runs.
func NewRecorder(sessionID, runID, profile string) *Recorder {
return &Recorder{tr: TurnTrace{
SessionID: sessionID,
RunID: runID,
Profile: profile,
}}
}
// Start stamps StartedAt. Safe to call at most once; idempotent on repeat.
func (r *Recorder) Start() {
if r == nil {
return
}
r.mu.Lock()
defer r.mu.Unlock()
if r.started {
return
}
r.started = true
r.tr.StartedAt = time.Now()
}
// SpanHandle is a live timing span. Call End exactly once to commit it; a
// second End is a no-op. Not calling End leaks the span (it is dropped).
type SpanHandle struct {
recorder *Recorder
name string
start time.Time
once sync.Once
}
// End commits the span's wall interval to the recorder. Each stamp is its own
// occurrence (spans are not merged by name); exclusive time is derived at
// Finish from the recorded intervals.
func (s *SpanHandle) End() {
if s == nil || s.recorder == nil {
return
}
s.once.Do(func() {
s.recorder.addOccurrence(s.name, s.start, time.Now())
})
}
// Span begins a named span and returns a handle. Caller is responsible for
// calling End when the span completes. Example:
//
// span := r.Span(trace.SpanGeneration)
// defer span.End()
func (r *Recorder) Span(name string) *SpanHandle {
if r == nil {
return nil
}
return &SpanHandle{recorder: r, name: name, start: time.Now()}
}
// RecordSpan commits an already-measured duration to name as a synthesized
// sequential occurrence. Use this when the caller already holds a duration
// (for example, in tests) rather than a live interval; production code uses
// Span/End, which record the real wall interval. Synthesized occurrences
// chain from the recorder's StartedAt (or a moving cursor) so coverage and
// exclusive math remain consistent. Each stamp is its own entry.
func (r *Recorder) RecordSpan(name string, d time.Duration) {
if r == nil {
return
}
r.mu.Lock()
defer r.mu.Unlock()
if r.finished {
return
}
start := r.cursor
if start.IsZero() {
start = r.tr.StartedAt
}
if start.IsZero() {
start = time.Now()
}
end := start.Add(d)
r.cursor = end
r.tr.Spans = append(r.tr.Spans, Span{Name: name, Start: start, End: end, Duration: d})
}
// Counter adds n to the named counter, accumulating across calls.
func (r *Recorder) Counter(name string, n int64) {
if r == nil {
return
}
r.mu.Lock()
defer r.mu.Unlock()
if r.finished {
return
}
r.addCounterLocked(name, n)
}
// StampFirstToken records the time of the first output token. Only the first
// call wins; later calls are no-ops.
func (r *Recorder) StampFirstToken() {
if r == nil {
return
}
r.mu.Lock()
defer r.mu.Unlock()
if r.finished || r.firstTokenStamped {
return
}
r.firstTokenStamped = true
r.tr.FirstTokenAt = time.Now()
}
// StampFirstVisibleEvent records the first event visible to the user. First
// call wins.
func (r *Recorder) StampFirstVisibleEvent() {
if r == nil {
return
}
r.mu.Lock()
defer r.mu.Unlock()
if r.finished || r.firstVisibleStamped {
return
}
r.firstVisibleStamped = true
r.tr.FirstVisibleEventAt = time.Now()
}
// StampFirstUsefulAction records the first tool call or substantive action.
// First call wins.
func (r *Recorder) StampFirstUsefulAction() {
if r == nil {
return
}
r.mu.Lock()
defer r.mu.Unlock()
if r.finished || r.firstActionStamped {
return
}
r.firstActionStamped = true
r.tr.FirstUsefulActionAt = time.Now()
}
// Finish stamps CompletedAt, derives each span's parent (by interval
// containment) and exclusive time, and returns a snapshot of the trace. Calling
// Finish more than once returns the same snapshot.
func (r *Recorder) Finish() *TurnTrace {
if r == nil {
return nil
}
r.mu.Lock()
defer r.mu.Unlock()
if !r.finished {
r.finished = true
r.tr.CompletedAt = time.Now()
deriveNesting(r.tr.Spans)
}
snap := r.tr
// Copy the slices so callers cannot mutate the recorder's state.
snap.Spans = append([]Span(nil), r.tr.Spans...)
snap.Counters = append([]Counter(nil), r.tr.Counters...)
return &snap
}
// addOccurrence appends a span occurrence with its wall interval.
func (r *Recorder) addOccurrence(name string, start, end time.Time) {
r.mu.Lock()
defer r.mu.Unlock()
if r.finished {
return
}
d := end.Sub(start)
if d < 0 {
d = 0
}
r.tr.Spans = append(r.tr.Spans, Span{Name: name, Start: start, End: end, Duration: d})
}
func (r *Recorder) addCounterLocked(name string, n int64) {
for i := range r.tr.Counters {
if r.tr.Counters[i].Name == name {
r.tr.Counters[i].Value += n
return
}
}
r.tr.Counters = append(r.tr.Counters, Counter{Name: name, Value: n})
}
// interval is a half-open [start, end) wall window used for containment and
// coverage math.
type interval struct{ start, end time.Time }
// deriveNesting computes each span's parent (the tightest span whose interval
// contains it) and its exclusive time (duration minus the union of its direct
// children's intervals). Spans without a usable interval are left top-level
// with exclusive = duration. This is O(n²) in the span count, which is tiny
// (a handful to a few dozen per run), and runs once at Finish.
func deriveNesting(spans []Span) {
parent := make([]int, len(spans))
for i := range parent {
parent[i] = -1
}
for i, a := range spans {
if a.Start.IsZero() || a.End.IsZero() {
continue
}
bestIdx := -1
bestDur := time.Duration(0)
for j, b := range spans {
if i == j || b.Start.IsZero() || b.End.IsZero() {
continue
}
// b contains a when a starts at/after b and ends at/before b.
contained := !a.Start.Before(b.Start) && !a.End.After(b.End)
if !contained {
continue
}
// Strict containment makes b an unambiguous parent of a. When the
// two intervals are identical (contained but not strictly — equality
// satisfies the check symmetrically), they would otherwise pick
// each other as parent and form a 2-cycle that drops both from
// top-level. Break that tie deterministically: only the
// lower-indexed span may parent a co-extensive higher-indexed one,
// so one stays top-level and the other nests under it.
strict := a.Start.After(b.Start) || a.End.Before(b.End)
if !strict && j >= i {
continue
}
bd := b.End.Sub(b.Start)
if bestIdx == -1 || bd < bestDur {
bestIdx = j
bestDur = bd
}
}
parent[i] = bestIdx
}
for i := range spans {
if spans[i].Start.IsZero() || spans[i].End.IsZero() {
spans[i].Exclusive = spans[i].Duration
continue
}
var children []interval
for j := range spans {
if parent[j] == i {
children = append(children, interval{spans[j].Start, spans[j].End})
}
}
exclusive := spans[i].Duration - unionOf(children)
if exclusive < 0 {
exclusive = 0
}
spans[i].Exclusive = exclusive
if parent[i] != -1 {
spans[i].Parent = spans[parent[i]].Name
}
}
}
// unionIntervalDuration returns the total wall time covered by the union of
// all span intervals (used for Coverage). Spans without a usable interval are
// skipped.
func unionIntervalDuration(spans []Span) time.Duration {
var intervals []interval
for _, s := range spans {
if s.Start.IsZero() || s.End.IsZero() || s.End.Before(s.Start) {
continue
}
intervals = append(intervals, interval{s.Start, s.End})
}
return unionOf(intervals)
}
// unionOf returns the total duration covered by the union of the intervals.
func unionOf(intervals []interval) time.Duration {
if len(intervals) == 0 {
return 0
}
sort.Slice(intervals, func(i, j int) bool { return intervals[i].start.Before(intervals[j].start) })
var total time.Duration
cur := intervals[0]
for _, iv := range intervals[1:] {
if !iv.start.After(cur.end) {
// overlap or touch: extend the current window.
if iv.end.After(cur.end) {
cur.end = iv.end
}
continue
}
total += cur.end.Sub(cur.start)
cur = iv
}
total += cur.end.Sub(cur.start)
return total
}
+233
View File
@@ -0,0 +1,233 @@
// Package trace records per-turn timing for a Zero agent run.
//
// Tracing is opt-in. A *Recorder is attached to agent.Options and threaded
// through the run via context (see FromContext / WithContext). When the
// recorder is nil, every stamp is a no-op and the agent loop, providers, and
// tools are byte-identical to an untraced run.
//
// The emitted NDJSON is compatible with internal/agenteval's trace contract:
// one JSON object per line carrying a "type" (and usually "name") field, so
// agenteval.ParseTraceEventKeys / MissingTraceEvents can validate a run.
//
// Attribution model. Each stamp records a wall interval [start, end]. Spans
// that run concurrently or are nested (e.g. provider_connect inside generation,
// permission_wait inside tool_execution) are NOT summed into each other. The
// recorder derives a parent for each span by interval containment and computes
// per-span exclusive time (duration minus the union of its children's
// intervals). AttributedDuration is the sum of top-level (non-nested) spans —
// the time accounted for without double-counting. Coverage is the fraction of
// wall covered by the union of all span intervals; it is the honest "≥95% of
// wall accounted for" metric and never exceeds 1.
package trace
import "time"
// Span names. These are the "name" keys emitted in the NDJSON event stream
// (e.g. {"type":"span","name":"generation","duration_ms":123.4}) and the
// vocabulary a run's wall time is attributed to. Only names that are actually
// stamped appear here: phases without a real stamp are omitted so readers do
// not trust empty categories. RequiredEventKeys lists the subset guaranteed in
// any successful model turn; OptionalEventKeys lists the rest.
const (
SpanToolPartition = "tool_partition" // partitioning the tool set for the prompt
SpanProviderConnect = "provider_connect" // client.Do in the provider seam
SpanProviderQueue = "provider_queue" // pre-send OAuth/token resolve
SpanGeneration = "generation" // streaming a model completion
SpanToolExecution = "tool_execution" // executing tool calls
SpanPermissionWait = "permission_wait" // waiting on a permission prompt
SpanVerification = "verification" // self-correct verify pass
SpanCompaction = "compaction" // context compaction
)
// Counter names. Emitted as {"type":"counter","name":"tool_calls","value":7}.
const (
CounterModelRequests = "model_requests"
CounterToolCalls = "tool_calls"
CounterRetryCount = "retry_count"
CounterReconnectCount = "reconnect_count"
CounterCompactionCount = "compaction_count"
CounterCompletionNudges = "completion_nudges"
CounterAcceptanceChecks = "acceptance_checks"
CounterPollingTurn = "polling_turn"
CounterModelSwitches = "model_switches"
CounterInputTokens = "input_tokens"
CounterCachedInputTokens = "cached_input_tokens"
CounterOutputTokens = "output_tokens"
)
// Span is one named wall interval attributed to part of a run. Each stamp is
// its own entry (spans are not merged by name): a run that streams two model
// completions has two generation entries, which lets the recorder derive
// parent/child nesting by interval containment and compute exclusive time.
//
// Duration is the inclusive wall time (End - Start). Exclusive is Duration
// minus the union of this span's children's intervals — the time uniquely
// attributable to this phase rather than to a nested sub-phase. Parent is the
// name of the tightest containing span, or "" for a top-level span.
type Span struct {
Name string `json:"name"`
Start time.Time `json:"start,omitempty"`
End time.Time `json:"end,omitempty"`
Duration time.Duration `json:"duration"`
Parent string `json:"parent,omitempty"`
Exclusive time.Duration `json:"exclusive,omitempty"`
}
// Counter is a named integer accumulated during a run (counts and token totals).
type Counter struct {
Name string `json:"name"`
Value int64 `json:"value"`
}
// TurnTrace is the finished record for one agent.Run. It is the value
// emitters serialize; it is not mutated after Finish returns a snapshot.
type TurnTrace struct {
SessionID string `json:"session_id"`
RunID string `json:"run_id"`
Profile string `json:"profile,omitempty"`
StartedAt time.Time `json:"started_at"`
FirstVisibleEventAt time.Time `json:"first_visible_event_at,omitempty"`
FirstUsefulActionAt time.Time `json:"first_useful_action_at,omitempty"`
FirstTokenAt time.Time `json:"first_token_at,omitempty"`
CompletedAt time.Time `json:"completed_at"`
Spans []Span `json:"spans"`
Counters []Counter `json:"counters"`
}
// WallDuration is the total traced wall time of the run.
func (t *TurnTrace) WallDuration() time.Duration {
if t == nil || t.CompletedAt.IsZero() || t.StartedAt.IsZero() {
return 0
}
return t.CompletedAt.Sub(t.StartedAt)
}
// AttributedDuration is the sum of top-level (non-nested) span durations — the
// wall time accounted for without double-counting nested or concurrent sub-
// phases. For a well-instrumented sequential run this is close to WallDuration
// (gaps are uninstrumented regions); it does not inflate from nested children.
func (t *TurnTrace) AttributedDuration() time.Duration {
if t == nil {
return 0
}
var total time.Duration
for _, span := range t.Spans {
if span.Parent == "" {
total += span.Duration
}
}
return total
}
// Coverage is the fraction of WallDuration covered by the union of all span
// intervals, capped at 1.0. This is the honest "what fraction of wall time did
// we account for" metric: overlapping or nested spans do not push it above 1.
// Returns 0 when wall is zero or no span has a usable interval.
func (t *TurnTrace) Coverage() float64 {
if t == nil {
return 0
}
wall := t.WallDuration()
if wall <= 0 {
return 0
}
union := unionIntervalDuration(t.Spans)
if union <= 0 {
return 0
}
ratio := float64(union) / float64(wall)
if ratio > 1 {
ratio = 1
}
return ratio
}
// AttributionRatio is Coverage — the fraction of wall covered by span
// intervals. A run is considered well-attributed when this is >= 0.95. It
// never exceeds 1, so it is a sound denominator for "share of attributed time".
func (t *TurnTrace) AttributionRatio() float64 {
return t.Coverage()
}
// Span returns the total inclusive duration recorded for name across all its
// occurrences, or zero if absent.
func (t *TurnTrace) Span(name string) time.Duration {
if t == nil {
return 0
}
var total time.Duration
for _, span := range t.Spans {
if span.Name == name {
total += span.Duration
}
}
return total
}
// Exclusive returns the total exclusive duration recorded for name across all
// its occurrences (each occurrence's Duration minus its children), or zero.
func (t *TurnTrace) Exclusive(name string) time.Duration {
if t == nil {
return 0
}
var total time.Duration
for _, span := range t.Spans {
if span.Name == name {
total += span.Exclusive
}
}
return total
}
// Counter returns the value recorded for name, or zero if absent.
func (t *TurnTrace) Counter(name string) int64 {
if t == nil {
return 0
}
for _, c := range t.Counters {
if c.Name == name {
return c.Value
}
}
return 0
}
// RequiredEventKeys is the set of span/counter event keys guaranteed in any
// successful single-turn traced run, regardless of provider or auth path.
// Tests assert via agenteval.MissingTraceEvents that a run produces all of
// these. Phases that are conditional (tools, permission, compaction,
// verification) are in OptionalEventKeys, not here, so a healthy short trace
// does not false-fail.
func RequiredEventKeys() []string {
return []string{
"span:" + SpanToolPartition,
"span:" + SpanGeneration,
"span:" + SpanProviderConnect,
"counter:" + CounterModelRequests,
"counter:" + CounterInputTokens,
"counter:" + CounterOutputTokens,
"trace:run",
}
}
// OptionalEventKeys are event keys a traced run MAY emit depending on what the
// run does (it may call no tools, need no permission, never compact, etc.).
// Callers must not treat their absence as a failure.
func OptionalEventKeys() []string {
return []string{
"span:" + SpanProviderQueue,
"span:" + SpanToolExecution,
"span:" + SpanPermissionWait,
"span:" + SpanCompaction,
"span:" + SpanVerification,
"counter:" + CounterToolCalls,
"counter:" + CounterCachedInputTokens,
"counter:" + CounterRetryCount,
"counter:" + CounterReconnectCount,
"counter:" + CounterCompactionCount,
"counter:" + CounterCompletionNudges,
"counter:" + CounterAcceptanceChecks,
"counter:" + CounterPollingTurn,
"counter:" + CounterModelSwitches,
}
}
+542
View File
@@ -0,0 +1,542 @@
package trace
import (
"bytes"
"context"
"encoding/json"
"errors"
"strings"
"sync"
"testing"
"time"
"github.com/Gitlawb/zero/internal/agenteval"
)
func TestRecorderSpanAccumulates(t *testing.T) {
r := NewRecorder("s1", "r1", "")
r.Start()
s := r.Span(SpanGeneration)
time.Sleep(2 * time.Millisecond)
s.End()
s2 := r.Span(SpanGeneration)
time.Sleep(1 * time.Millisecond)
s2.End()
tr := r.Finish()
got := tr.Span(SpanGeneration)
if got < 3*time.Millisecond {
t.Fatalf("generation span did not accumulate across stamps; got %v", got)
}
// Spans are stored as occurrences (one entry per stamp), not merged by name,
// so the recorder can derive parent/child nesting by interval containment.
if len(tr.Spans) != 2 {
t.Fatalf("expected two generation span occurrences, got %d", len(tr.Spans))
}
}
func TestRecorderCounters(t *testing.T) {
r := NewRecorder("s1", "r1", "")
r.Counter(CounterToolCalls, 1)
r.Counter(CounterToolCalls, 2)
r.Counter(CounterModelRequests, 3)
tr := r.Finish()
if got := tr.Counter(CounterToolCalls); got != 3 {
t.Fatalf("tool_calls = %d, want 3", got)
}
if got := tr.Counter(CounterModelRequests); got != 3 {
t.Fatalf("model_requests = %d, want 3", got)
}
}
func TestRecorderFirstTokenOnce(t *testing.T) {
r := NewRecorder("s", "r", "")
r.Start()
r.StampFirstToken()
first := r.Finish().FirstTokenAt
r.StampFirstToken() // no-op after Finish; should not panic
if r.Finish().FirstTokenAt != first {
t.Fatal("StampFirstToken should not move the timestamp after the first stamp")
}
}
func TestFinishSnapshotIsCopy(t *testing.T) {
r := NewRecorder("s", "r", "")
r.Counter(CounterToolCalls, 5)
tr := r.Finish()
tr.Counters[0].Value = 999
if got := r.Finish().Counter(CounterToolCalls); got != 5 {
t.Fatalf("Finish snapshot must be a copy; mutating it changed recorder state to %d", got)
}
}
func TestFinishFreezesState(t *testing.T) {
// Once Finish returns a snapshot, the recorder is frozen: later stamps must
// not mutate its state, so a second Finish yields the same trace.
r := NewRecorder("s", "r", "")
r.Start()
r.Counter(CounterToolCalls, 2)
r.RecordSpan(SpanGeneration, 5*time.Millisecond)
r.StampFirstToken()
first := r.Finish()
// Post-finish stamps of every kind must be dropped.
r.Counter(CounterToolCalls, 100)
r.RecordSpan(SpanGeneration, 100*time.Millisecond)
r.StampFirstToken()
r.StampFirstVisibleEvent()
r.StampFirstUsefulAction()
s := r.Span(SpanToolExecution)
time.Sleep(time.Millisecond)
s.End()
second := r.Finish()
if got := second.Counter(CounterToolCalls); got != 2 {
t.Fatalf("post-finish Counter leaked into snapshot: got %d, want 2", got)
}
if got := second.Span(SpanGeneration); got != 5*time.Millisecond {
t.Fatalf("post-finish RecordSpan leaked into snapshot: got %v, want 5ms", got)
}
if got := second.Span(SpanToolExecution); got != 0 {
t.Fatalf("post-finish Span leaked into snapshot: got %v, want 0", got)
}
if second.FirstTokenAt != first.FirstTokenAt {
t.Fatalf("post-finish StampFirstToken moved timestamp")
}
if !second.FirstVisibleEventAt.IsZero() {
t.Fatalf("post-finish StampFirstVisibleEvent leaked into snapshot")
}
if !second.FirstUsefulActionAt.IsZero() {
t.Fatalf("post-finish StampFirstUsefulAction leaked into snapshot")
}
}
func TestNilRecorderIsNoOp(t *testing.T) {
var r *Recorder
r.Start()
r.Counter(CounterToolCalls, 1)
r.StampFirstToken()
r.StampFirstVisibleEvent()
r.StampFirstUsefulAction()
r.RecordSpan(SpanGeneration, time.Millisecond)
s := r.Span(SpanGeneration)
s.End()
if tr := r.Finish(); tr != nil {
t.Fatalf("nil recorder Finish should return nil, got %+v", tr)
}
}
func TestRecorderConcurrent(t *testing.T) {
r := NewRecorder("s", "r", "")
r.Start()
var wg sync.WaitGroup
for i := 0; i < 50; i++ {
wg.Add(1)
go func() {
defer wg.Done()
s := r.Span(SpanToolExecution)
time.Sleep(time.Millisecond)
s.End()
r.Counter(CounterToolCalls, 1)
r.StampFirstToken()
}()
}
wg.Wait()
tr := r.Finish()
if got := tr.Counter(CounterToolCalls); got != 50 {
t.Fatalf("tool_calls = %d, want 50", got)
}
if got := tr.Span(SpanToolExecution); got <= 0 {
t.Fatalf("tool_execution span empty after concurrent stamps; got %v", got)
}
}
func TestContextRoundTrip(t *testing.T) {
r := NewRecorder("s", "r", "")
ctx := WithContext(context.Background(), r)
if got := FromContext(ctx); got != r {
t.Fatal("FromContext did not return the injected recorder")
}
if got := FromContext(context.Background()); got != nil {
t.Fatalf("FromContext on a bare context should return nil, got %v", got)
}
}
func TestContextNilRecorder(t *testing.T) {
ctx := WithContext(context.Background(), nil)
if got := FromContext(ctx); got != nil {
t.Fatalf("FromContext should return nil for an injected nil recorder, got %v", got)
}
}
func TestWriteNDJSONMatchesAgentevalContract(t *testing.T) {
r := NewRecorder("s1", "r1", "cold")
r.Start()
r.RecordSpan(SpanToolPartition, 10*time.Millisecond)
r.RecordSpan(SpanGeneration, 50*time.Millisecond)
r.RecordSpan(SpanToolExecution, 5*time.Millisecond)
r.RecordSpan(SpanPermissionWait, 1*time.Millisecond)
r.RecordSpan(SpanCompaction, 2*time.Millisecond)
r.RecordSpan(SpanProviderConnect, 8*time.Millisecond)
r.Counter(CounterModelRequests, 2)
r.Counter(CounterToolCalls, 3)
r.Counter(CounterInputTokens, 100)
r.Counter(CounterOutputTokens, 40)
tr := r.Finish()
var buf bytes.Buffer
if err := WriteNDJSON(&buf, tr); err != nil {
t.Fatalf("WriteNDJSON: %v", err)
}
stdout := buf.String()
missing := agenteval.MissingTraceEvents(RequiredEventKeys(), stdout)
if len(missing) > 0 {
t.Fatalf("NDJSON missing required event keys: %v\noutput:\n%s", missing, stdout)
}
keys := agenteval.ParseTraceEventKeys(stdout)
want := map[string]bool{
"trace:run": true,
"span:" + SpanToolPartition: true,
"span:" + SpanGeneration: true,
"span:" + SpanToolExecution: true,
"span:" + SpanProviderConnect: true,
"counter:" + CounterModelRequests: true,
"counter:" + CounterToolCalls: true,
"counter:" + CounterInputTokens: true,
"counter:" + CounterOutputTokens: true,
}
for k := range want {
if !contains(keys, k) {
t.Fatalf("expected key %q in parsed keys %v", k, keys)
}
}
// Each line must be valid JSON.
for _, line := range strings.Split(strings.TrimSpace(stdout), "\n") {
if strings.TrimSpace(line) == "" {
continue
}
var obj map[string]any
if err := json.Unmarshal([]byte(line), &obj); err != nil {
t.Fatalf("non-JSON NDJSON line: %q (%v)", line, err)
}
}
}
func TestWriteTextIsReadable(t *testing.T) {
r := NewRecorder("s", "r", "")
r.Start()
r.RecordSpan(SpanGeneration, 42*time.Millisecond)
r.Counter(CounterToolCalls, 7)
tr := r.Finish()
var buf bytes.Buffer
if err := WriteText(&buf, tr); err != nil {
t.Fatalf("WriteText: %v", err)
}
out := buf.String()
for _, want := range []string{"trace run=", "spans:", "generation", "counters:", "tool_calls"} {
if !strings.Contains(out, want) {
t.Fatalf("text trace missing %q:\n%s", want, out)
}
}
}
func TestWriteTextPropagatesWriteError(t *testing.T) {
r := NewRecorder("s", "r", "")
r.Start()
r.RecordSpan(SpanGeneration, 42*time.Millisecond)
r.Counter(CounterToolCalls, 7)
tr := r.Finish()
if err := WriteText(errWriter{}, tr); err == nil {
t.Fatal("WriteText to a failing sink returned nil; want the write error")
}
}
type errWriter struct{}
func (errWriter) Write(p []byte) (int, error) { return 0, errors.New("write failed") }
func TestAttributionRatio(t *testing.T) {
r := NewRecorder("s", "r", "")
r.Start()
// Two sequential, non-overlapping spans (RecordSpan synthesizes them
// back-to-back from the cursor) so neither contains the other: both are
// top-level and AttributedDuration is their sum with no double-counting.
r.RecordSpan(SpanGeneration, 10*time.Millisecond)
r.RecordSpan(SpanToolExecution, 10*time.Millisecond)
tr := r.Finish()
// Attributed time is the deterministic sum of top-level span durations; it
// does not depend on wall-clock timing.
if want := 20 * time.Millisecond; tr.AttributedDuration() != want {
t.Fatalf("attributed = %v, want %v", tr.AttributedDuration(), want)
}
// AttributionRatio is Coverage — the fraction of wall covered by the union
// of span intervals, capped at 1.0. It never exceeds 1 (no double-counting
// of overlapping/nested spans), and equals Coverage by definition.
if got := tr.AttributionRatio(); got > 1 {
t.Fatalf("attribution ratio = %v, must never exceed 1", got)
}
if got := tr.AttributionRatio(); got != tr.Coverage() {
t.Fatalf("attribution ratio = %v, want Coverage() = %v", got, tr.Coverage())
}
}
func TestCoverageExcludesDoubleCountAndCaps(t *testing.T) {
// A nested span (provider_connect inside generation) must NOT push coverage
// above 1, and the parent's exclusive time must subtract the child's interval.
r := NewRecorder("s", "r", "")
r.Start()
// Synthesize a containing generation interval of 100ms, then a provider_connect
// recorded after it so its interval sits fully inside generation's.
gen := r.Span(SpanGeneration)
time.Sleep(2 * time.Millisecond)
// Record a provider_connect that starts after generation started and ends
// before generation ends: nested, so it is the child of generation.
pc := r.Span(SpanProviderConnect)
time.Sleep(1 * time.Millisecond)
pc.End()
gen.End()
tr := r.Finish()
var genExclusive, pcExclusive time.Duration
var genParent, pcParent string
for _, s := range tr.Spans {
switch s.Name {
case SpanGeneration:
genExclusive = s.Exclusive
genParent = s.Parent
case SpanProviderConnect:
pcExclusive = s.Exclusive
pcParent = s.Parent
}
}
// provider_connect has no children, so its exclusive time equals its own
// duration and is positive.
if pcExclusive <= 0 {
t.Fatalf("provider_connect exclusive = %v, want > 0", pcExclusive)
}
if pcParent != SpanGeneration {
t.Fatalf("provider_connect parent = %q, want %q (nested by interval containment)", pcParent, SpanGeneration)
}
if genParent != "" {
t.Fatalf("generation should be top-level, got parent %q", genParent)
}
// generation's exclusive time must be its duration minus provider_connect's
// interval, not its full duration.
if genExclusive >= tr.Span(SpanGeneration) {
t.Fatalf("generation exclusive = %v should be less than its inclusive %v (child subtracted)",
genExclusive, tr.Span(SpanGeneration))
}
if tr.Coverage() > 1 {
t.Fatalf("coverage = %v, must never exceed 1 even with nested spans", tr.Coverage())
}
}
func TestAttributionRatioZeroWall(t *testing.T) {
// A trace with no completed run has zero wall and a defined-zero ratio
// (covers the divide-by-zero guard).
tr := &TurnTrace{}
if got := tr.AttributionRatio(); got != 0 {
t.Fatalf("zero-wall ratio = %v, want 0", got)
}
if got := tr.AttributedDuration(); got != 0 {
t.Fatalf("empty attributed = %v, want 0", got)
}
if got := tr.WallDuration(); got != 0 {
t.Fatalf("empty wall = %v, want 0", got)
}
}
func contains(slice []string, s string) bool {
for _, v := range slice {
if v == s {
return true
}
}
return false
}
func TestReadNDJSONRoundTrip(t *testing.T) {
r := NewRecorder("s1", "r1", "cold")
r.Start()
r.RecordSpan(SpanToolPartition, 10*time.Millisecond)
r.RecordSpan(SpanGeneration, 50*time.Millisecond)
r.RecordSpan(SpanGeneration, 5*time.Millisecond) // accumulates to 55ms
r.Counter(CounterModelRequests, 3)
r.Counter(CounterToolCalls, 7)
r.StampFirstToken()
original := r.Finish()
var buf bytes.Buffer
if err := WriteNDJSON(&buf, original); err != nil {
t.Fatalf("WriteNDJSON: %v", err)
}
parsed, err := ReadNDJSON(&buf)
if err != nil {
t.Fatalf("ReadNDJSON: %v", err)
}
if parsed == nil {
t.Fatal("ReadNDJSON returned nil")
}
if parsed.RunID != original.RunID || parsed.SessionID != original.SessionID || parsed.Profile != original.Profile {
t.Fatalf("identity mismatch: got %+v want %+v", parsed, original)
}
if got := parsed.Span(SpanGeneration); got != 55*time.Millisecond {
t.Fatalf("generation span after round-trip = %v, want 55ms", got)
}
if got := parsed.Counter(CounterModelRequests); got != 3 {
t.Fatalf("model_requests after round-trip = %d, want 3", got)
}
if got := parsed.Counter(CounterToolCalls); got != 7 {
t.Fatalf("tool_calls after round-trip = %d, want 7", got)
}
if parsed.FirstTokenAt.IsZero() {
t.Fatal("first_token_at lost in round-trip")
}
}
func TestReadNDJSONRejectsNonTrace(t *testing.T) {
// A file with content but no type:trace header is never a valid empty trace.
if _, err := ReadNDJSON(strings.NewReader("not json at all\n")); err == nil {
t.Fatal("expected error for non-JSON input with no trace header")
}
if _, err := ReadNDJSON(strings.NewReader(`{"type":"span","name":"generation","duration_ms":5}` + "\n")); err == nil {
t.Fatal("expected error for span lines with no preceding trace header")
}
}
func TestReadNDJSONRejectsHeaderOnly(t *testing.T) {
// A header with no recoverable spans/counters is corrupt/truncated, not empty.
header := `{"type":"trace","name":"run","session_id":"s","run_id":"r"}` + "\n"
if _, err := ReadNDJSON(strings.NewReader(header)); err == nil {
t.Fatal("expected error for a trace header with no spans or counters")
}
}
func TestReadNDJSONRejectsEmpty(t *testing.T) {
// Empty or blank-only input means emission never produced a trace line
// (e.g. the agent crashed before writing the header, or --trace was not
// honored). That must surface as an error so the harness records a
// TraceIssue rather than treating a crashed run as clean zero-attribution.
if _, err := ReadNDJSON(strings.NewReader("")); err == nil {
t.Fatal("expected error for empty input")
}
if _, err := ReadNDJSON(strings.NewReader("\n \n\n")); err == nil {
t.Fatal("expected error for blank-only input")
}
}
func TestExclusiveZeroRoundTrips(t *testing.T) {
// A parent whose children exactly tile its interval has exclusive time 0.
// That 0 must survive a write-then-read round-trip — overwriting it with the
// inclusive Duration on re-parse re-introduces the double-counting the
// exclusive-time model exists to prevent.
base := time.Date(2024, 1, 1, 0, 0, 0, 0, time.UTC)
spans := []Span{
{Name: SpanGeneration, Start: base, End: base.Add(100 * time.Millisecond), Duration: 100 * time.Millisecond},
{Name: SpanProviderConnect, Start: base, End: base.Add(60 * time.Millisecond), Duration: 60 * time.Millisecond},
{Name: SpanToolExecution, Start: base.Add(60 * time.Millisecond), End: base.Add(100 * time.Millisecond), Duration: 40 * time.Millisecond},
}
deriveNesting(spans)
if spans[0].Exclusive != 0 {
t.Fatalf("setup invariant: generation exclusive = %v, want 0 (children tile it)", spans[0].Exclusive)
}
original := &TurnTrace{
SessionID: "s",
RunID: "r",
StartedAt: base,
CompletedAt: base.Add(100 * time.Millisecond),
Spans: spans,
}
var buf bytes.Buffer
if err := WriteNDJSON(&buf, original); err != nil {
t.Fatalf("WriteNDJSON: %v", err)
}
parsed, err := ReadNDJSON(&buf)
if err != nil {
t.Fatalf("ReadNDJSON: %v", err)
}
var parsedGenExclusive time.Duration
for _, s := range parsed.Spans {
if s.Name == SpanGeneration {
parsedGenExclusive = s.Exclusive
}
}
if parsedGenExclusive != 0 {
t.Fatalf("generation exclusive after round-trip = %v, want 0 (a written exclusive_ms:0 must be preserved, not overwritten with Duration)", parsedGenExclusive)
}
// The harness ranks by exclusive; the sum of exclusive across the run must
// equal the wall (children carry the time, the parent contributes 0), with
// no double-count.
var exclusiveSum time.Duration
for _, s := range parsed.Spans {
exclusiveSum += s.Exclusive
}
if exclusiveSum != original.WallDuration() {
t.Fatalf("exclusive sum = %v, want wall %v (double-count or gap on re-parse)", exclusiveSum, original.WallDuration())
}
}
func TestIdenticalIntervalsNoCycle(t *testing.T) {
// Two spans stamped at the exact same [start, end] would, under a symmetric
// containment check, pick each other as parent and form a 2-cycle, dropping
// both from top-level and zeroing AttributedDuration. The tie-break must
// keep one top-level so AttributedDuration stays correct (no cycle, no
// double-count).
base := time.Date(2024, 1, 1, 0, 0, 0, 0, time.UTC)
spans := []Span{
{Name: SpanGeneration, Start: base, End: base.Add(100 * time.Millisecond), Duration: 100 * time.Millisecond},
{Name: SpanProviderConnect, Start: base, End: base.Add(100 * time.Millisecond), Duration: 100 * time.Millisecond},
}
deriveNesting(spans)
var topLevel int
var parents []string
for _, s := range spans {
if s.Parent == "" {
topLevel++
} else {
parents = append(parents, s.Name+"->"+s.Parent)
}
}
if topLevel == 0 {
t.Fatalf("identical intervals formed a parent cycle; no top-level spans (parents=%v)", parents)
}
if topLevel != 1 {
t.Fatalf("expected exactly one top-level span for co-extensive pair, got %d (parents=%v)", topLevel, parents)
}
// AttributedDuration is the single top-level span's duration — not 0 (cycle)
// and not 2x (siblings double-count).
tr := &TurnTrace{StartedAt: base, CompletedAt: base.Add(100 * time.Millisecond), Spans: spans}
if got := tr.AttributedDuration(); got != 100*time.Millisecond {
t.Fatalf("AttributedDuration = %v, want 100ms (one top-level span, no cycle)", got)
}
}
func TestCounterPrecisionRoundTrip(t *testing.T) {
// Counter values decode through json.Number so an int64 above 2^53
// round-trips exactly instead of losing precision via float64.
r := NewRecorder("s", "r", "")
r.Start()
const big = int64(1<<53 + 1) // 9007199254740993 — not representable exactly as float64
r.Counter(CounterInputTokens, big)
tr := r.Finish()
var buf bytes.Buffer
if err := WriteNDJSON(&buf, tr); err != nil {
t.Fatalf("WriteNDJSON: %v", err)
}
parsed, err := ReadNDJSON(&buf)
if err != nil {
t.Fatalf("ReadNDJSON: %v", err)
}
if got := parsed.Counter(CounterInputTokens); got != big {
t.Fatalf("counter round-trip = %d, want %d (float64 precision loss)", got, big)
}
}