mirror of
https://github.com/Twigpine/zero.git
synced 2026-11-08 09:49:34 -10:00
Compare commits
8
Commits
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
c4de52a5c5 | ||
|
|
d061524989 | ||
|
|
2bfb340668 | ||
|
|
40806aa4b1 | ||
|
|
0f372f3844 | ||
|
|
b3e6ef1f58 | ||
|
|
6896fee475 | ||
|
|
2ec91f4493 |
No files matched your search
@@ -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"
|
||||
@@ -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)",
|
||||
|
||||
@@ -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"
|
||||
}
|
||||
@@ -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
@@ -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 {
|
||||
|
||||
@@ -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")
|
||||
}
|
||||
}
|
||||
@@ -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
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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 —
|
||||
|
||||
@@ -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
|
||||
|
||||
@@ -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)
|
||||
}
|
||||
@@ -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 {
|
||||
|
||||
@@ -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"}
|
||||
]
|
||||
}
|
||||
Whitespace-only changes.
@@ -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.
|
||||
@@ -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
@@ -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
@@ -0,0 +1,4 @@
|
||||
package edit
|
||||
|
||||
// Version is the build version string.
|
||||
const Version = "1.0.0"
|
||||
+89
@@ -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
@@ -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)
|
||||
}
|
||||
}
|
||||
+1287
File diff suppressed because it is too large.
Load diff
+21
@@ -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))
|
||||
}
|
||||
@@ -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
@@ -0,0 +1,3 @@
|
||||
# nav fixture
|
||||
|
||||
Small read-only workspace for navigation/classification benchmark tasks.
|
||||
+5
@@ -0,0 +1,5 @@
|
||||
{
|
||||
"port": 8080,
|
||||
"name": "nav-fixture",
|
||||
"retries": 3
|
||||
}
|
||||
+24
@@ -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
@@ -0,0 +1,4 @@
|
||||
first line of a.txt
|
||||
second line of a.txt
|
||||
third line of a.txt
|
||||
alpha alpha alpha
|
||||
+4
@@ -0,0 +1,4 @@
|
||||
first line of b.txt
|
||||
second line of b.txt
|
||||
third line of b.txt
|
||||
beta beta beta
|
||||
+4
@@ -0,0 +1,4 @@
|
||||
first line of c.txt
|
||||
second line of c.txt
|
||||
third line of c.txt
|
||||
gamma gamma gamma
|
||||
@@ -0,0 +1 @@
|
||||
{ "id": 1, "key": "value-1", "enabled": true }
|
||||
@@ -0,0 +1 @@
|
||||
{ "id": 2, "key": "value-2", "enabled": true }
|
||||
@@ -0,0 +1 @@
|
||||
{ "id": 3, "key": "value-3", "enabled": true }
|
||||
@@ -0,0 +1 @@
|
||||
{ "id": 4, "key": "value-4", "enabled": true }
|
||||
@@ -0,0 +1 @@
|
||||
{ "id": 5, "key": "value-5", "enabled": true }
|
||||
@@ -0,0 +1 @@
|
||||
{ "id": 6, "key": "value-6", "enabled": true }
|
||||
+4
@@ -0,0 +1,4 @@
|
||||
first line of d.txt
|
||||
second line of d.txt
|
||||
third line of d.txt
|
||||
delta delta delta
|
||||
@@ -0,0 +1 @@
|
||||
contents of dir1/notes.md
|
||||
@@ -0,0 +1 @@
|
||||
contents of dir2/notes.md
|
||||
@@ -0,0 +1 @@
|
||||
contents of dir3/notes.md
|
||||
@@ -0,0 +1 @@
|
||||
contents of dir4/notes.md
|
||||
@@ -0,0 +1 @@
|
||||
contents of dir5/notes.md
|
||||
@@ -0,0 +1 @@
|
||||
contents of dir6/notes.md
|
||||
+4
@@ -0,0 +1,4 @@
|
||||
first line of e.txt
|
||||
second line of e.txt
|
||||
third line of e.txt
|
||||
epsilon epsilon epsilon
|
||||
+4
@@ -0,0 +1,4 @@
|
||||
first line of f.txt
|
||||
second line of f.txt
|
||||
third line of f.txt
|
||||
zeta zeta zeta
|
||||
+55
@@ -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)
|
||||
}
|
||||
@@ -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")
|
||||
}
|
||||
@@ -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)
|
||||
}
|
||||
}
|
||||
@@ -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,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) {
|
||||
|
||||
@@ -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
|
||||
}
|
||||
@@ -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)
|
||||
}
|
||||
@@ -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
|
||||
}
|
||||
}
|
||||
@@ -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
|
||||
}
|
||||
@@ -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,
|
||||
}
|
||||
}
|
||||
@@ -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)
|
||||
}
|
||||
}
|
||||
Reference in new issue
Block a user