From 09cdc8e2d2b213ef30b9482d25c508cdf85d681f Mon Sep 17 00:00:00 2001 From: esengine <359807859@qq.com> Date: Fri, 7 Aug 2026 19:27:30 -0700 Subject: [PATCH] =?UTF-8?q?feat(e2ebench):=20cold/warm=20cache=20arms=20?= =?UTF-8?q?=E2=80=94=20never=20report=20one=20blended=20wall=20time?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit -cache cold (default) keeps today's fresh-session-per-task behavior and names it; -cache warm primes the provider prefix cache with a one-step run in the same workdir before the graded run's clock starts, measuring the long-lived-session steady state the prefix-cache design optimizes for. The warming pass's cost is deliberately untracked (the arm prices the steady state, not the ramp) and its prefix-shaping flags (model, profile, ablation, cwd) match the graded invocation exactly. Results carry cache_arm so arms can never be silently mixed; the report title labels warm runs. The digest gains first-request cache hit/miss tokens — the cold/warm verdict signal: a cold session pays the whole prefix as miss, a warmed one starts near-hit. The KPI line adds TTFT median and first-request cache hit; the pairwise compare table adds Pass@1, TTFT median, TTCS median/p90, cache hit, and first-request cache hit rows, so '-mode compare cold.json warm.json' renders the cold/warm decomposition directly. Multi-arm tables gain TTFT and first-request cache columns. Cross-agent fairness note recorded in the README: cold TTCS is the comparable number against fresh-environment competitors; warm is the product's steady state. Both are value — they must not be blended. --- benchmarks/README.md | 1 + cmd/e2ebench/compare.go | 22 ++++++++++++--- cmd/e2ebench/main.go | 47 ++++++++++++++++++++++++++++----- cmd/e2ebench/mechanisms_test.go | 18 +++++++++++++ cmd/e2ebench/profile.go | 16 +++++++++++ cmd/e2ebench/profile_test.go | 11 ++++++++ cmd/e2ebench/report.go | 21 ++++++++++++--- cmd/e2ebench/trajectory.go | 11 ++++++++ 8 files changed, 134 insertions(+), 13 deletions(-) diff --git a/benchmarks/README.md b/benchmarks/README.md index 8f5fc45959..4e93f93a82 100644 --- a/benchmarks/README.md +++ b/benchmarks/README.md @@ -118,6 +118,7 @@ own outcome). | `-json` | *(none)* | Write the JSON report here (optional). | | `-trajectories` | *(none)* | Suite mode: write one `.trajectory.jsonl` per task into this directory (the agent's full event stream with timestamps — see `reasonix run --trajectory`). The report gains a time-attribution line (tools vs. model) and each JSON result a `trajectory` digest. | | `-force-planner` | `false` | Suite mode: prefix each prompt with a plan-first directive so the two-model turn engages regardless of the planner gate. Use for the "with planner" arm of an A/B; results carry `plan_forced` so arms are only comparable with equal forcing. | +| `-cache` | `cold` | Suite mode: `cold` runs each task as a fresh session (the fair cross-agent comparison arm); `warm` primes the provider prefix cache with a one-step run in the same workdir first, measuring the long-lived-session steady state. Never mix arms in one report — compare them with `-mode compare cold.json warm.json`. | | `-budget` | `800000` | Abort once total tokens cross this (`0` = no cap). Remaining tasks are reported as skipped. | Diff-mode flags: diff --git a/cmd/e2ebench/compare.go b/cmd/e2ebench/compare.go index ed5a9b1e42..023fb48145 100644 --- a/cmd/e2ebench/compare.go +++ b/cmd/e2ebench/compare.go @@ -45,10 +45,11 @@ func requestsBySourceLine(bySource map[string]sourceUsage) string { type armStats struct { Ran, Pass1, Solved, AccountedSolved int Steps, Tools, Rounds, PlannerCalls int - Tokens int + Tokens, Hit, Miss int Cost float64 WallMs int64 - TTCS []int64 + FirstHit, FirstMiss int64 + TTCS, TTFT []int64 ByClass map[string]classStats } @@ -101,11 +102,18 @@ func aggregateArm(results []result) armStats { s.Steps += r.Steps s.Tools += r.ToolCalls s.Tokens += r.PromptTokens + r.CompletionTokens + s.Hit += r.CacheHitTokens + s.Miss += r.CacheMissTokens s.Cost += r.Cost s.WallMs += r.WallMs s.PlannerCalls += r.UsageBySource["planner"].Calls if r.Trajectory != nil { s.Rounds += r.Trajectory.ModelRounds + if r.Trajectory.TTFTMs > 0 { + s.TTFT = append(s.TTFT, r.Trajectory.TTFTMs) + } + s.FirstHit += r.Trajectory.FirstReqCacheHitTokens + s.FirstMiss += r.Trajectory.FirstReqCacheMissTokens } } return s @@ -155,8 +163,8 @@ func loadArm(path string) (armStats, error) { func multiCompareReport(paths []string) (string, error) { var b strings.Builder fmt.Fprintf(&b, "## e2ebench comparison: %d arms\n\n", len(paths)) - b.WriteString("| Arm | Pass@1 | Solved | TTCS median | TTCS p90 | Solved/hour | Requests/solved | Tokens/solved | Cost/solved |\n") - b.WriteString("|---|---:|---:|---:|---:|---:|---:|---:|---:|\n") + b.WriteString("| Arm | Pass@1 | Solved | TTFT | TTCS median | TTCS p90 | Solved/hour | 1st-req cache | Requests/solved | Tokens/solved | Cost/solved |\n") + b.WriteString("|---|---:|---:|---:|---:|---:|---:|---:|---:|---:|---:|\n") points := make([]paretoPoint, 0, len(paths)) for _, path := range paths { s, err := loadArm(path) @@ -212,6 +220,12 @@ func compareReports(pathA, pathB string) (string, error) { fmt.Fprintf(&b, "## e2ebench A/B: `%s` vs `%s`\n\n", pathA, pathB) fmt.Fprintf(&b, "| Metric | A | B |\n|---|---:|---:|\n") fmt.Fprintf(&b, "| Solved | %d/%d (%s) | %d/%d (%s) |\n", a.Solved, a.Ran, pct(a.Solved, a.Ran), bStats.Solved, bStats.Ran, pct(bStats.Solved, bStats.Ran)) + fmt.Fprintf(&b, "| Pass@1 | %s | %s |\n", pct(a.Pass1, a.Ran), pct(bStats.Pass1, bStats.Ran)) + fmt.Fprintf(&b, "| TTFT median | %s | %s |\n", durMs(median(a.TTFT)), durMs(median(bStats.TTFT))) + fmt.Fprintf(&b, "| TTCS median | %s | %s |\n", dur(median(a.TTCS)), dur(median(bStats.TTCS))) + fmt.Fprintf(&b, "| TTCS p90 | %s | %s |\n", dur(pctile(a.TTCS, 90)), dur(pctile(bStats.TTCS, 90))) + fmt.Fprintf(&b, "| Cache hit | %s | %s |\n", pct(a.Hit, a.Hit+a.Miss), pct(bStats.Hit, bStats.Hit+bStats.Miss)) + fmt.Fprintf(&b, "| First-request cache hit | %s | %s |\n", pct(int(a.FirstHit), int(a.FirstHit+a.FirstMiss)), pct(int(bStats.FirstHit), int(bStats.FirstHit+bStats.FirstMiss))) fmt.Fprintf(&b, "| Model requests / solved | %s | %s |\n", perSolved(float64(a.Steps), a.AccountedSolved), perSolved(float64(bStats.Steps), bStats.AccountedSolved)) fmt.Fprintf(&b, "| Planner requests / solved | %s | %s |\n", perSolved(float64(a.PlannerCalls), a.AccountedSolved), perSolved(float64(bStats.PlannerCalls), bStats.AccountedSolved)) fmt.Fprintf(&b, "| Model rounds / solved | %s | %s |\n", perSolved(float64(a.Rounds), a.AccountedSolved), perSolved(float64(bStats.Rounds), bStats.AccountedSolved)) diff --git a/cmd/e2ebench/main.go b/cmd/e2ebench/main.go index 1236cd43d2..54284dc729 100644 --- a/cmd/e2ebench/main.go +++ b/cmd/e2ebench/main.go @@ -115,6 +115,9 @@ type result struct { // PhaseTrace is the per-task privacy-safe latency trace (counts and ms // only); nil unless the run recorded a trajectory. PhaseTrace *phaseTrace `json:"phase_trace,omitempty"` + // CacheArm records whether the run was cold (fresh session) or warm + // (prefix pre-warmed in the same workdir), so arms never get mixed. + CacheArm string `json:"cache_arm,omitempty"` // Attempt is this entry's 1-based try for its task; suite retries stop at // the first passing attempt. Zero on skipped entries and old JSON. Attempt int `json:"attempt,omitempty"` @@ -170,6 +173,7 @@ func main() { keepImages := flag.Bool("keep-images", false, "swebench mode: keep instance images instead of removing them after each run") suite := flag.String("suite", "benchmarks/e2e", "suite root (contains tasks//)") taskFilter := flag.String("task", "", "suite mode: run only these comma-separated task IDs (e.g. -task fix-add-bug)") + cacheArm := flag.String("cache", "cold", "suite mode: cold (fresh session per task) | warm (prefix-warming one-step run in the same workdir before the graded run)") bin := flag.String("bin", "reasonix", "path to the reasonix binary") model := flag.String("model", "", "provider/model name (default: config default)") profileFlag := flag.String("profile", benchmarkProfileBaseline, "prompt profile: baseline | delivery") @@ -189,7 +193,8 @@ func main() { flag.Parse() profile, perr := normalizeBenchmarkProfile(*profileFlag) arm, aerr := ablation.Parse(*ablateFlag) - if err := errors.Join(perr, aerr); err != nil { + cache, cerr := normalizeCacheArm(*cacheArm) + if err := errors.Join(perr, aerr, cerr); err != nil { fmt.Fprintln(os.Stderr, err) os.Exit(2) } @@ -245,7 +250,7 @@ func main() { os.Exit(2) } - results := runSuite(*bin, *model, profile, arm, tasks, *budget, *trajDir, *forcePlanner, *attempts) + results := runSuite(*bin, *model, profile, arm, tasks, *budget, *trajDir, *forcePlanner, *attempts, cache) report := render(results) if *outMD != "" { @@ -358,7 +363,7 @@ func filterTasks(tasks []task, filter string) ([]task, error) { // task retries up to attempts times, stopping at the first passing attempt; // TTCS accumulates the failed attempts' wall too — a solution found on try 3 // took three tries' worth of time to reach. -func runSuite(bin, model, profile string, arm ablation.Set, tasks []task, budget int, trajDir string, forcePlanner bool, attempts int) []result { +func runSuite(bin, model, profile string, arm ablation.Set, tasks []task, budget int, trajDir string, forcePlanner bool, attempts int, cacheArm string) []result { var results []result total := 0 for _, t := range tasks { @@ -368,7 +373,7 @@ func runSuite(bin, model, profile string, arm ablation.Set, tasks []task, budget } var cumWallMs int64 for attempt := 1; attempt <= max(attempts, 1); attempt++ { - r := runTask(bin, model, profile, arm, t, trajDir, forcePlanner) + r := runTask(bin, model, profile, arm, t, trajDir, forcePlanner, cacheArm) r.Attempt = attempt cumWallMs += r.WallMs if r.Passed { @@ -387,8 +392,8 @@ func runSuite(bin, model, profile string, arm ablation.Set, tasks []task, budget // runTask copies the task's seed workdir into a temp dir, runs the agent there, // then drops in verify.sh and runs it as the grader. The grader is added only // after the run so the agent can't read the answer key. -func runTask(bin, model, profile string, arm ablation.Set, t task, trajDir string, forcePlanner bool) result { - r := result{task: t, Profile: profile} +func runTask(bin, model, profile string, arm ablation.Set, t task, trajDir string, forcePlanner bool, cacheArm string) result { + r := result{task: t, Profile: profile, CacheArm: cacheArm} r.Arm = arm.Arm() if forcePlanner { // Leading directive matched by the planner gate's @@ -421,6 +426,10 @@ func runTask(bin, model, profile string, arm ablation.Set, t task, trajDir strin } } + if cacheArm == benchmarkCacheWarm { + warmPrefix(bin, model, profile, arm, work) + } + ctx, cancel := context.WithTimeout(context.Background(), time.Duration(t.TimeoutSec)*time.Second) defer cancel() @@ -481,6 +490,32 @@ func buildRunTaskArgs(metricsPath, trajectoryPath, model, profile string, arm ab return append(args, prompt) } +// warmPrefix primes the provider prefix cache for work's session shape with a +// minimal one-step run before the graded run starts its clock. Its cost is +// deliberately untracked: the warm arm measures a long-lived session's steady +// state, not the price of reaching it. Prefix-shaping flags (model, profile, +// ablation, cwd) must match the graded invocation exactly. +func warmPrefix(bin, model, profile string, arm ablation.Set, work string) { + ctx, cancel := context.WithTimeout(context.Background(), 90*time.Second) + defer cancel() + args := []string{"run", "--auto", "--max-steps", "1"} + if model != "" { + args = append(args, "--model", model) + } + args = appendBenchmarkProfileArgs(args, profile) + if !arm.Empty() { + args = append(args, "--ablate", arm.String()) + } + args = append(args, "Reply with exactly: ok") + cmd := exec.CommandContext(ctx, bin, args...) + cmd.Dir = work + cmd.Stdout = os.Stderr + cmd.Stderr = os.Stderr + if err := cmd.Run(); err != nil { + fmt.Fprintln(os.Stderr, "warm-cache pass:", err) + } +} + func grade(work, taskDir string) bool { verify := filepath.Join(taskDir, "verify.sh") if !fileExists(verify) { diff --git a/cmd/e2ebench/mechanisms_test.go b/cmd/e2ebench/mechanisms_test.go index 1a91ed838b..263d0d1d4e 100644 --- a/cmd/e2ebench/mechanisms_test.go +++ b/cmd/e2ebench/mechanisms_test.go @@ -72,6 +72,24 @@ func TestSummarizeTrajectoryCollectsToolSurface(t *testing.T) { } } +func TestKPILineIncludesTTFTAndFirstRequestCacheHit(t *testing.T) { + cold := result{task: task{ID: "a"}, Passed: true, WallMs: 10_000, Attempt: 1, TTCSMs: 10_000} + cold.Trajectory = &trajectorySummary{ + TTFTMs: 2800, + FirstReqCacheHitTokens: 400, + FirstReqCacheMissTokens: 13_600, + } + got := renderBody([]result{cold}) + for _, want := range []string{ + "**TTFT median** 2.8s", + "**first-request cache hit** 3%", + } { + if !strings.Contains(got, want) { + t.Fatalf("KPI line missing %q:\n%s", want, got) + } + } +} + func TestRenderToolSurfaceLine(t *testing.T) { r := result{task: task{ID: "a"}, Passed: true} r.Trajectory = &trajectorySummary{ diff --git a/cmd/e2ebench/profile.go b/cmd/e2ebench/profile.go index 5eb7d66fac..52a0b8cf5c 100644 --- a/cmd/e2ebench/profile.go +++ b/cmd/e2ebench/profile.go @@ -36,3 +36,19 @@ func appendBenchmarkProfileArgs(args []string, profile string) []string { } return append(args, "--profile", profile) } + +const ( + benchmarkCacheCold = "cold" + benchmarkCacheWarm = "warm" +) + +func normalizeCacheArm(arm string) (string, error) { + switch strings.ToLower(strings.TrimSpace(arm)) { + case "", benchmarkCacheCold: + return benchmarkCacheCold, nil + case benchmarkCacheWarm: + return benchmarkCacheWarm, nil + default: + return "", fmt.Errorf("unknown cache arm %q (want cold or warm)", arm) + } +} diff --git a/cmd/e2ebench/profile_test.go b/cmd/e2ebench/profile_test.go index 61f2447334..314b273661 100644 --- a/cmd/e2ebench/profile_test.go +++ b/cmd/e2ebench/profile_test.go @@ -69,6 +69,17 @@ func TestNormalizeBenchmarkProfile(t *testing.T) { } } +func TestNormalizeCacheArm(t *testing.T) { + for input, want := range map[string]string{"": "cold", "cold": "cold", " WARM ": "warm"} { + if got, err := normalizeCacheArm(input); err != nil || got != want { + t.Fatalf("normalizeCacheArm(%q) = %q, %v", input, got, err) + } + } + if _, err := normalizeCacheArm("hot"); err == nil { + t.Fatal("unknown cache arm should fail") + } +} + func TestAppendBenchmarkProfileArgsPassesToolSurfaceTiers(t *testing.T) { for _, tier := range []string{"economy", "balanced"} { got := appendBenchmarkProfileArgs([]string{"run"}, tier) diff --git a/cmd/e2ebench/report.go b/cmd/e2ebench/report.go index 1ccea13497..e9b6adda52 100644 --- a/cmd/e2ebench/report.go +++ b/cmd/e2ebench/report.go @@ -19,7 +19,11 @@ func render(results []result) string { arm = results[0].Arm } } - return fmt.Sprintf("## 🤖 Reasonix e2e benchmark (%s · arm `%s`)\n\n", profile, arm) + renderBody(results) + cache := "" + if len(results) > 0 && results[0].CacheArm != "" && results[0].CacheArm != benchmarkCacheCold { + cache = " · " + results[0].CacheArm + "-cache" + } + return fmt.Sprintf("## 🤖 Reasonix e2e benchmark (%s · arm `%s`%s)\n\n", profile, arm, cache) + renderBody(results) } // suiteStats aggregates result entries; ran/pass1 count tasks (first @@ -29,8 +33,8 @@ type suiteStats struct { accounted, accountedSolved, unaccounted, unaccountedSolved, partial int pTok, cTok, hit, miss, compacts, tools, toolFails, steps, modelRounds int cost float64 - walls, ttcs []int64 - wallAccountedMs, wallTotalMs int64 + walls, ttcs, ttft []int64 + wallAccountedMs, wallTotalMs, firstHit, firstMiss int64 currency string classes, prefixChangeReasons map[string]int bySource map[string]sourceUsage @@ -88,6 +92,11 @@ func gatherSuiteStats(results []result) suiteStats { accumulateSources(s.bySource, r.UsageBySource) if r.Trajectory != nil { s.modelRounds += r.Trajectory.ModelRounds + if r.Trajectory.TTFTMs > 0 { + s.ttft = append(s.ttft, r.Trajectory.TTFTMs) + } + s.firstHit += r.Trajectory.FirstReqCacheHitTokens + s.firstMiss += r.Trajectory.FirstReqCacheMissTokens } s.cost += r.Cost if r.Currency != "" { @@ -116,6 +125,12 @@ func kpiLine(s suiteStats) string { if s.wallTotalMs > 0 { line += fmt.Sprintf(" · **Solved/hour** %.1f", float64(s.passed)*3_600_000/float64(s.wallTotalMs)) } + if len(s.ttft) > 0 { + line += fmt.Sprintf(" · **TTFT median** %s", durMs(median(s.ttft))) + } + if s.firstHit+s.firstMiss > 0 { + line += fmt.Sprintf(" · **first-request cache hit** %s", pct(int(s.firstHit), int(s.firstHit+s.firstMiss))) + } return line + "\n\n" } diff --git a/cmd/e2ebench/trajectory.go b/cmd/e2ebench/trajectory.go index 3abb4fe032..2d7e2bb82b 100644 --- a/cmd/e2ebench/trajectory.go +++ b/cmd/e2ebench/trajectory.go @@ -90,6 +90,11 @@ type trajectorySummary struct { PromptTokensSeen int64 `json:"prompt_tokens_seen,omitempty"` // Σ prompt tokens (schema share denominator) PrefixResets int `json:"prefix_resets,omitempty"` // usage events with prefixChanged ConnectCalls int `json:"connect_calls,omitempty"` // connect_tool_source dispatches + + // Cold/warm evidence: the first top-level request's cache split. A cold + // session pays the whole prefix as miss; a warmed one starts near-hit. + FirstReqCacheHitTokens int64 `json:"first_req_cache_hit_tokens,omitempty"` + FirstReqCacheMissTokens int64 `json:"first_req_cache_miss_tokens,omitempty"` } // toolWall is the best available tool wall-clock: interval union when the @@ -116,6 +121,8 @@ type trajectoryRecord struct { Usage *struct { Source string `json:"source"` PromptTokens int64 `json:"promptTokens"` + CacheHitTokens int64 `json:"cacheHitTokens"` + CacheMissTokens int64 `json:"cacheMissTokens"` CacheDiagnostics *struct { ToolSchemaTokens int64 `json:"toolSchemaTokens"` PrefixChanged bool `json:"prefixChanged"` @@ -393,6 +400,10 @@ func (t *trajScan) recordModelPhase(rec trajectoryRecord) { default: t.s.ExecutorRequests++ } + if t.s.PromptTokensSeen == 0 && u.PromptTokens > 0 { + t.s.FirstReqCacheHitTokens = u.CacheHitTokens + t.s.FirstReqCacheMissTokens = u.CacheMissTokens + } t.s.PromptTokensSeen += u.PromptTokens if d := u.CacheDiagnostics; d != nil { t.s.SchemaTokensTotal += d.ToolSchemaTokens