From 1c012880b54b76cee0b9b2a57d6be2945c6ec157 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 03:14:10 +0000 Subject: [PATCH 01/16] =?UTF-8?q?feat(proxy):=20three=20operating=20modes?= =?UTF-8?q?=20=E2=80=94=20sync,=20async=20(cache-safe=20deferred=20compact?= =?UTF-8?q?ion),=20observe?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Compaction was unconditionally synchronous, so the only way to get savings was to accept ~450 ms/req of latency, and the only way to find out whether context-guru helps a workload was to enforce it in production. Add an explicit `mode:` with three settings; sync remains the default and is byte-identical to before. async defers the expensive part (the compaction LLM call) off the request path. The inline pass gets no model clients, so it only replays decisions an earlier turn's off-path job already froze; the deferred pass gets them and its result benefits subsequent turns. The hard part is the cache. A cache-write costs 11.5x a cache-read, so letting the un-compacted tail get provider-cached and THEN replacing it converts a read into a write and is strictly worse than sync — exactly what tripled headroom's cache-write on Terminal-Bench. So by default no breakpoint is placed at or beyond the tail a pending compaction will replace (cacheinject drops those positions and anchors at the highest safe index instead). async.cache_uncompacted_tail: true is the escape hatch for a backend confirmed not to cache. Correctness rests on a per-session compaction generation. A request records the generation it was built from; a deferred job writes into a store.Buffer and the buffer is committed ONLY if the session is still at that generation, under the same lock that advances it. A stale result is discarded, never applied, and counted. The pool is one bounded queue with a fixed worker count owned by the proxy — dedup by (session, generation) with the pending slot claimed before the job is observable, drop rather than block, clean cancellation, no goroutine leaks. observe forwards the original body and never touches it: the request path does not run the pipeline at all (and skips expand tool injection), while a copy runs off-path against a buffer that is never committed. Its numbers live in a physically separate metric namespace with their own vocabulary (potential_* / projected_*) that shares no key with an enforced metric — a mislabelled hypothetical would silently inflate the product's headline claim. Also folds prevLen into a locked Tracker call. It was read then written back in a defer, so two concurrent turns of one session raced on it (overlaps #25). /stats gains mode, sync_enforced, async_enforced, the full async queue tuple including dropped and stale_discarded, and the observe hypotheticals. Every pre-existing field keeps its name and shape — deploy/harbor/*.py parses it. Tests are -race throughout: sync byte-identical to the legacy entry point, observe byte-identity of the forwarded body, stale-generation discard end to end, concurrent turns of one session, atomic enqueue dedup, a full queue that drops and counts without blocking, no goroutine leak on cancellation, no breakpoint at or beyond the un-compacted tail, and observe metrics unreachable from every enforced aggregate. Signed-off-by: Osher-Elhadad --- apply/apply.go | 116 +++++-- apply/modes_test.go | 211 +++++++++++++ apply/opts.go | 94 ++++++ cmd/context-guru-proxy/main.go | 21 +- components/component.go | 77 +++++ components/pipeline.go | 4 +- components/reformat/cacheinject.go | 18 ++ components/reformat/cacheinject_test.go | 82 +++++ config/config.go | 29 ++ metrics/metrics.go | 205 +++++++++++- modes/modes_test.go | 294 +++++++++++++++++ modes/pool.go | 212 +++++++++++++ modes/tracker.go | 130 ++++++++ proxy/modes.go | 185 +++++++++++ proxy/modes_test.go | 398 ++++++++++++++++++++++++ proxy/proxy.go | 86 ++++- store/buffer.go | 105 +++++++ 17 files changed, 2225 insertions(+), 42 deletions(-) create mode 100644 apply/modes_test.go create mode 100644 apply/opts.go create mode 100644 modes/modes_test.go create mode 100644 modes/pool.go create mode 100644 modes/tracker.go create mode 100644 proxy/modes.go create mode 100644 proxy/modes_test.go create mode 100644 store/buffer.go diff --git a/apply/apply.go b/apply/apply.go index bc23d27..db3daaa 100644 --- a/apply/apply.go +++ b/apply/apply.go @@ -112,7 +112,19 @@ func BodyWithModelWindow(ctx context.Context, pipe *components.Pipeline, st stor // cache-awareness when the backend is a prompt-caching provider or the request // already carries cache_control breakpoints; "on" forces it; "off" restores the // legacy compact-everything behavior (correct for confirmed non-caching backends). -func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, provider bschemas.ModelProvider, body []byte, explicitSession string, bypass bool, models components.ModelSpec, window int, cacheMode string) (result []byte, changedBody bool) { +func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, provider bschemas.ModelProvider, body []byte, explicitSession string, bypass bool, models components.ModelSpec, window int, cacheMode string) ([]byte, bool) { + r := BodyOpts(ctx, pipe, st, Opts{ + Provider: provider, Body: body, Session: explicitSession, Bypass: bypass, + Models: models, Window: window, CacheMode: cacheMode, + }) + return r.Body, r.Changed +} + +// BodyOpts is the full entry point: everything BodyFull takes plus the operating mode +// (#31) and the per-session generation snapshot async mode needs. Hosts that support +// modes call this; BodyFull is the positional shim every other caller keeps using. +func BodyOpts(ctx context.Context, pipe *components.Pipeline, st store.Store, o Opts) (res Result) { + body, provider, bypass := o.Body, o.Provider, o.Bypass // Top-level fail-open backstop: the per-component recover in pipeline.runOne only // covers component code. A panic anywhere else on the rewrite path (normalize, the // sjson splice, rebuildCountChanged, a marshal) must NOT 500 the client — forward @@ -120,13 +132,26 @@ func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, pr // the whole entry point, not just inside components. defer func() { if r := recover(); r != nil { - slog.Error("context-guru: recovered from panic in BodyFull; forwarding original request", "panic", r) - result, changedBody = body, false + slog.Error("context-guru: recovered from panic in BodyOpts; forwarding original request", "panic", r) + res = Result{Body: body} } }() + mode := o.Mode + if mode == "" { + mode = components.ModeSync + } + models := o.Models + // Async, on the REQUEST path: replay only decisions that are already computed. The + // expensive part of a compaction is the LLM call, which is the entire reason async + // exists, so the inline pass gets no model clients and every NeedsModel component + // degrades to its deterministic path or no-ops (that degradation is already a + // documented contract). The off-path job (Deferred) gets the clients. + if mode == components.ModeAsync && !o.Deferred { + models = components.ModelSpec{} + } msgsRaw := gjson.GetBytes(body, "messages") if !msgsRaw.Exists() || !msgsRaw.IsArray() { - return body, false + return Result{Body: body} } // Volatile-tail split, before anything else touches the body. This is a @@ -142,7 +167,7 @@ func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, pr norm, slots := normalize(provider, msgsRaw.Array()) if len(norm) == 0 { - return body, systemSplit // keep the split even with nothing to compact + return Result{Body: body, Changed: systemSplit} // keep the split even with nothing to compact } if debugTraffic { @@ -150,27 +175,62 @@ func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, pr } chat := &bschemas.BifrostChatRequest{Provider: provider, Input: norm} sys, firstUser := systemAndFirstUser(norm) - sessionID := session.Resolve(explicitSession, sys, firstUser) - cacheAware := resolveCacheAware(cacheMode, provider, body) + sessionID := session.Resolve(o.Session, sys, firstUser) + cacheAware := resolveCacheAware(o.CacheMode, provider, body) maxCachedIdx := -1 if cacheAware && !bypass { // Messages present on the previous turn of this session are already committed // to the provider cache; only the new tail is being cache-written this turn. // Restrict supersession/age offloaders to that tail so they never mutate the // cached prefix. Growth-based (dialect-agnostic; needs no cache_control mapping). - maxCachedIdx = prevLen(st, sessionID) - 1 - defer putLen(st, sessionID, len(norm)) + // + // The boundary comes from the Tracker when the host supplies one: it reads the + // previous length and records this turn's in ONE locked call, which is what + // removes the concurrent-turn race the old read-then-deferred-write had + // (#31/#25). Without a tracker (library callers, /compact) the legacy store path + // stands — same numbers, same race, no behavior change for them. + switch { + case o.PrevLen != nil: + maxCachedIdx = *o.PrevLen - 1 + case o.Tracker != nil: + pl, gen := o.Tracker.Turn(sessionID, len(norm)) + maxCachedIdx = pl - 1 + res.PrevLen = pl + res.Generation = gen + default: + maxCachedIdx = prevLen(st, sessionID) - 1 + defer putLen(st, sessionID, len(norm)) + } + } else if o.Tracker != nil { + res.Generation = o.Tracker.Gen(sessionID) + } + // Async cache policy: while a compaction for this session is queued but not landed, + // the un-compacted tail is about to be REPLACED, so no breakpoint may be committed + // at or beyond it (see components.Ctx.NoCacheAtOrAfter). CacheUncompactedTail=true + // is the escape hatch for a confirmed non-caching backend, where the protection buys + // nothing. + tailPending, noCacheAt := false, 0 + if mode == components.ModeAsync && !o.Deferred && !bypass && !o.CacheUncompactedTail { + tailPending = true + if noCacheAt = maxCachedIdx + 1; noCacheAt < 0 { + noCacheAt = 0 + } } c := &components.Ctx{ - Ctx: ctx, - Session: sessionID, - Store: st, - Model: models, - Bypass: bypass, - CtxWindow: window, - CacheAware: cacheAware, - MaxCachedIdx: maxCachedIdx, - } + Ctx: ctx, + Session: sessionID, + Store: st, + Model: models, + Bypass: bypass, + CtxWindow: o.Window, + CacheAware: cacheAware, + MaxCachedIdx: maxCachedIdx, + Mode: mode, + Deferred: o.Deferred, + TailCachePending: tailPending, + NoCacheAtOrAfter: noCacheAt, + } + res.Session = sessionID // Canonical form of each normalized message BEFORE the pipeline, so a // count-changing component (summarize) can be mapped back to the body. @@ -179,7 +239,7 @@ func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, pr normPre[i], _ = json.Marshal(norm[i]) } - pipe.Run(chat, c) + res.Run = pipe.Run(chat, c) // A component changed the message count (summarize restructures the transcript // to [msg0, , last-K]). Rebuild the messages array preserving each @@ -188,9 +248,11 @@ func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, pr if len(chat.Input) != len(norm) { nb, ok := rebuildCountChanged(body, msgsRaw.Array(), normPre, slots, chat.Input) if !ok && systemSplit { - return body, true // keep the split even when the rebuild declined + res.Body, res.Changed = body, true // keep the split even when the rebuild declined + return res } - return nb, ok || systemSplit + res.Body, res.Changed = nb, ok || systemSplit + return res } out := body @@ -208,14 +270,16 @@ func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, pr } var err error if out, err = sjson.SetBytes(out, s.path, newText); err != nil { - return body, false + res.Body = body + return res } changed = true changes = append(changes, mkChange(s.path, s.preText, newText)) default: // wholeMessage post, err := json.Marshal(chat.Input[i]) if err != nil { - return body, false + res.Body = body + return res } if bytes.Equal(post, s.pre) { continue // unmodified — keep the original bytes verbatim (I1) @@ -227,7 +291,8 @@ func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, pr continue } if out, err = sjson.SetRawBytes(out, s.path, post); err != nil { - return body, false + res.Body = body + return res } changed = true var pm bschemas.ChatMessage @@ -238,7 +303,8 @@ func BodyFull(ctx context.Context, pipe *components.Pipeline, st store.Store, pr if changed && dumpPath != "" { dumpChanges(c.Session, changes) } - return out, changed + res.Body, res.Changed = out, changed + return res } // resolveCacheAware decides whether cache-aware compaction is active for this diff --git a/apply/modes_test.go b/apply/modes_test.go new file mode 100644 index 0000000..57f1779 --- /dev/null +++ b/apply/modes_test.go @@ -0,0 +1,211 @@ +package apply_test + +import ( + "bytes" + "context" + "encoding/json" + "strings" + "sync" + "testing" + + bschemas "github.com/maximhq/bifrost/core/schemas" + "github.com/rossoctl/context-guru/apply" + "github.com/rossoctl/context-guru/components" + _ "github.com/rossoctl/context-guru/components/all" + "github.com/rossoctl/context-guru/config" + "github.com/rossoctl/context-guru/modes" + "github.com/rossoctl/context-guru/store" +) + +func modePipe(t *testing.T, yaml string) *components.Pipeline { + t.Helper() + cfg, err := config.LoadBytes([]byte(yaml)) + if err != nil { + t.Fatal(err) + } + p, err := cfg.Build(nil) + if err != nil { + t.Fatal(err) + } + return p +} + +func dupJSON(t *testing.T) []byte { + t.Helper() + dump := strings.Repeat("a verbose repeated tool output line\n", 60) + b, err := json.Marshal(map[string]any{ + "model": "gpt-x", + "messages": []map[string]any{ + {"role": "user", "content": "go"}, + {"role": "tool", "tool_call_id": "a", "content": dump}, + {"role": "tool", "tool_call_id": "b", "content": dump}, + }, + }) + if err != nil { + t.Fatal(err) + } + return b +} + +// TestModeDefaultsToSync: an Opts with no Mode must produce exactly what the explicit +// sync mode does, which is what the positional BodyFull has always produced. +func TestModeDefaultsToSync(t *testing.T) { + pipe := modePipe(t, "pipeline: [dedup]\n") + body := dupJSON(t) + + legacy, changed := apply.BodyFull(context.Background(), pipe, store.NewMemory(store.Options{}), + bschemas.OpenAI, body, "s", false, components.ModelSpec{}, 0, "auto") + if !changed { + t.Fatal("the legacy entry point compacted nothing; the comparison is vacuous") + } + res := apply.BodyOpts(context.Background(), modePipe(t, "pipeline: [dedup]\n"), + store.NewMemory(store.Options{}), + apply.Opts{Provider: bschemas.OpenAI, Body: body, Session: "s", CacheMode: "auto"}) + if !bytes.Equal(legacy, res.Body) { + t.Fatalf("BodyOpts default differs from BodyFull\n legacy: %s\n opts: %s", legacy, res.Body) + } +} + +// TestAsyncInlinePassMakesNoModelCall: the whole point of async is that the request +// path does not wait on an LLM. The inline pass must therefore be handed no model, +// while the deferred pass is. +func TestAsyncInlinePassMakesNoModelCall(t *testing.T) { + var mu sync.Mutex + calls := 0 + m := fakeModel{fn: func() string { + mu.Lock() + calls++ + mu.Unlock() + return "the agent read a file twice" + }} + // keep_last/min_tokens/start_from_message lowered so the tiny fixture is eligible; + // the point of the test is WHICH pass gets a model client, not the gating. + yaml := "pipeline: [summarize]\ncomponents:\n summarize:\n keep_last: 1\n min_tokens: 10\n start_from_message: 1\n model:\n source: config\n" + body := dupJSON(t) + + apply.BodyOpts(context.Background(), modePipe(t, yaml), store.NewMemory(store.Options{}), apply.Opts{ + Provider: bschemas.OpenAI, Body: body, Session: "s", + Models: components.ModelSpec{Static: m}, Mode: components.ModeAsync, + }) + mu.Lock() + inline := calls + mu.Unlock() + if inline != 0 { + t.Fatalf("the async inline pass made %d model call(s) — the latency it exists to remove", inline) + } + + apply.BodyOpts(context.Background(), modePipe(t, yaml), store.NewMemory(store.Options{}), apply.Opts{ + Provider: bschemas.OpenAI, Body: body, Session: "s", + Models: components.ModelSpec{Static: m}, Mode: components.ModeAsync, Deferred: true, + }) + mu.Lock() + deferred := calls + mu.Unlock() + if deferred == 0 { + t.Fatal("the deferred pass made no model call either — no compaction would ever be computed") + } +} + +// TestStaleAsyncResultIsDiscardedEndToEnd wires the real pieces the proxy wires: a +// deferred run writes into a Buffer, the session advances underneath it, and the +// commit is refused — so not one byte of the stale result reaches the live store. +func TestStaleAsyncResultIsDiscardedEndToEnd(t *testing.T) { + base := store.NewMemory(store.Options{}) + tr := modes.NewTracker(0) + pipe := modePipe(t, "pipeline: [dedup]\n") + body := dupJSON(t) + + // Turn 1 records the generation the deferred job will be built from. + inline := apply.BodyOpts(context.Background(), pipe, base, apply.Opts{ + Provider: bschemas.OpenAI, Body: body, Session: "s", CacheMode: "on", + Mode: components.ModeAsync, Tracker: tr, + }) + + // A newer turn's compaction lands first, advancing the generation. + if !tr.CommitIfCurrent("s", inline.Generation, func() {}) { + t.Fatal("could not advance the generation") + } + + // Now the older job finishes. + buf := store.NewBuffer(base) + prev := inline.PrevLen + res := apply.BodyOpts(context.Background(), pipe, buf, apply.Opts{ + Provider: bschemas.OpenAI, Body: body, Session: "s", CacheMode: "on", + Mode: components.ModeAsync, Deferred: true, PrevLen: &prev, + }) + if !res.Changed || buf.Writes() == 0 { + t.Fatal("the deferred run produced nothing; the discard test proves nothing") + } + if tr.CommitIfCurrent("s", inline.Generation, buf.Commit) { + t.Fatal("a STALE async result was applied") + } + // The buffer still holds every write, which IS the proof that none reached the live + // store: Commit is the only path there, and it never ran. + if buf.Writes() == 0 { + t.Fatal("the buffer drained even though the commit was refused") + } + // And the generation really had moved on, so the discard was not vacuous. + if tr.Gen("s") == inline.Generation { + t.Fatal("the generation never advanced, so nothing was ever stale") + } +} + +// TestBufferIsolatesUntilCommit: the buffer is what makes "discard a stale result" +// possible at all — without it a deferred run's writes land as it goes and cannot be +// taken back. +func TestBufferIsolatesUntilCommit(t *testing.T) { + base := store.NewMemory(store.Options{}) + base.Put("pre", []byte("existing")) + buf := store.NewBuffer(base) + + buf.Put("k", []byte("v")) + buf.MarkSticky("s", "id") + if _, ok := base.Get("k"); ok { + t.Fatal("a buffered write reached the base store before Commit") + } + if v, ok := buf.Get("k"); !ok || string(v) != "v" { + t.Fatal("the buffer cannot read its own write") + } + if v, ok := buf.Get("pre"); !ok || string(v) != "existing" { + t.Fatal("the buffer does not fall through to the base store") + } + if _, ok := base.Sticky("s")["id"]; ok { + t.Fatal("a buffered sticky mark reached the base store before Commit") + } + + buf.Commit() + if v, ok := base.Get("k"); !ok || string(v) != "v" { + t.Fatal("Commit did not flush") + } + if _, ok := base.Sticky("s")["id"]; !ok { + t.Fatal("Commit did not flush sticky marks") + } + if buf.Writes() != 0 { + t.Fatal("Commit did not drain the buffer") + } + + // Discard: never committed, never visible. + d := store.NewBuffer(base) + d.Put("gone", []byte("x")) + if _, ok := base.Get("gone"); ok { + t.Fatal("an uncommitted write is visible") + } +} + +// TestSessionOfMatchesApply: the async worker keys jobs by the session id apply +// resolves, so the two must agree — including on the content-hash fallback. +func TestSessionOfMatchesApply(t *testing.T) { + pipe := modePipe(t, "pipeline: [dedup]\n") + body := dupJSON(t) + res := apply.BodyOpts(context.Background(), pipe, store.NewMemory(store.Options{}), + apply.Opts{Provider: bschemas.OpenAI, Body: body}) // no explicit session + if got := apply.SessionOf(bschemas.OpenAI, body, ""); got != res.Session { + t.Fatalf("SessionOf resolved %q, apply used %q", got, res.Session) + } +} + +// --- helpers ---------------------------------------------------------------- + +type fakeModel struct{ fn func() string } + +func (f fakeModel) Complete(context.Context, string) (string, error) { return f.fn(), nil } diff --git a/apply/opts.go b/apply/opts.go new file mode 100644 index 0000000..72998df --- /dev/null +++ b/apply/opts.go @@ -0,0 +1,94 @@ +package apply + +import ( + bschemas "github.com/maximhq/bifrost/core/schemas" + "github.com/rossoctl/context-guru/components" + "github.com/rossoctl/context-guru/modes" + "github.com/rossoctl/context-guru/session" + "github.com/tidwall/gjson" +) + +// Opts is BodyOpts' input: everything the positional BodyFull takes, plus the +// operating mode (#31) and the per-session generation state async mode needs. +// +// A struct rather than a 13th positional argument: the parameter list was already at +// the limit of readability, and modes add three fields that only one host sets. +type Opts struct { + Provider bschemas.ModelProvider + Body []byte + // Session is the host-supplied session id ("" => content hash). + Session string + Bypass bool + Models components.ModelSpec + // Window is the model's resolved context window (max input tokens; 0 = unknown). + Window int + // CacheMode is "auto" (default) | "on" | "off" — see resolveCacheAware. + CacheMode string + + // Mode is the operating mode. Empty means components.ModeSync, so a caller that + // does not know about modes gets exactly today's behavior. + Mode components.Mode + // Deferred marks the OFF-PATH async run: nothing it produces is forwarded, it + // exists to populate the frozen state later turns replay. Only the async worker + // sets it, and it is what re-enables the LLM components the inline async pass + // deliberately withholds. + Deferred bool + // CacheUncompactedTail disables async's tail cache protection. In async mode the + // tail beyond the cached prefix is by construction content a not-yet-landed + // compaction is going to replace, so by default no breakpoint is placed there — + // protecting cache-write economics, because a breakpoint written over a tail we + // then replace converts a 0.1x read into a 1.25x write. Set true only for a backend confirmed + // not to cache, where the protection costs a breakpoint slot and buys nothing. + CacheUncompactedTail bool + // PrevLen, when non-nil, supplies the cached-prefix boundary (the number of + // normalized messages the previous turn carried) instead of resolving it. The + // off-path async job MUST set it: it runs against the body of turn N but at a time + // when the tracker has already advanced past it, so re-resolving would either + // gate everything away or gate nothing, and a frozen decision made under the wrong + // boundary is replayed on every later turn — churning exactly the cached prefix + // cache-awareness exists to protect. + PrevLen *int + // Tracker, when set, owns the per-session cached-prefix boundary and compaction + // generation. Supplying it also removes the concurrent-turn race in the legacy + // read-then-deferred-write of prevLen (#31/#25). nil => legacy store-backed path. + Tracker *modes.Tracker +} + +// Result is BodyOpts' output. +type Result struct { + // Body is the body to forward. Always valid: on any trouble it is the input. + Body []byte + // Changed is false when Body is the untouched input. + Changed bool + // Session is the resolved session id (the caller usually cannot compute it: it + // falls back to a content hash of system + first user message). + Session string + // PrevLen is the cached-prefix boundary this request was built with (the previous + // turn's normalized message count), so an off-path job can reuse the exact same one. + PrevLen int + // Generation is the session's compaction generation this result was built from, + // when a Tracker was supplied. An async job carries it and its result is discarded + // if the session has moved on (Tracker.CommitIfCurrent). + Generation uint64 + // Run is the pipeline's report for this request, nil when the pipeline did not run. + // Observe mode needs it: the run is the ONLY output, since the body is thrown away. + Run *components.RunReport +} + +// SessionOf resolves the session id apply will use for this body — the explicit id +// when the host has one, else the content hash of system + first user message. Hosts +// that must key off-path work by session (the async worker's dedup key and the +// generation check) need the SAME id apply computes, so this exposes that one +// resolution rather than letting a second implementation drift from it. +func SessionOf(provider bschemas.ModelProvider, body []byte, explicit string) string { + if explicit != "" { + return session.Resolve(explicit, "", "") + } + msgs := gjson.GetBytes(body, "messages") + if !msgs.Exists() || !msgs.IsArray() { + return session.Resolve("", "", "") + } + norm, _ := normalize(provider, msgs.Array()) + sys, firstUser := systemAndFirstUser(norm) + return session.Resolve("", sys, firstUser) +} diff --git a/cmd/context-guru-proxy/main.go b/cmd/context-guru-proxy/main.go index 0a0d08d..9430f28 100644 --- a/cmd/context-guru-proxy/main.go +++ b/cmd/context-guru-proxy/main.go @@ -36,6 +36,7 @@ func main() { anthropic = flag.String("anthropic-upstream", envOr("ANTHROPIC_UPSTREAM", "https://api.anthropic.com"), "Anthropic upstream base URL") bob = flag.String("bob-upstream", envOr("BOB_UPSTREAM", ""), "Bob (BobShell) backend base URL; enables the Bob gateway routes when set (e.g. https://api.us-east.bob.ibm.com)") storeFlag = flag.String("store", envOr("STORE", ""), "override state store: true|false (default: config store.enabled, else on)") + modeFlag = flag.String("mode", envOr("MODE", ""), "operating mode: sync (default) | async | observe (overrides the config's mode:)") ) flag.Parse() @@ -43,6 +44,13 @@ func main() { if err != nil { log.Fatalf("config: %v", err) } + if *modeFlag != "" { + cfg.Mode = *modeFlag // flag/env wins over the config file when set + } + mode, err := cfg.OperatingMode() + if err != nil { + log.Fatalf("config: %v", err) + } if v, ok := parseBool(*storeFlag); ok { cfg.Store.Enabled = &v // flag/env wins over the config file when set } @@ -67,6 +75,12 @@ func main() { InjectExpand: os.Getenv("INJECT_EXPAND"), // auto (default) | always | never CacheMode: os.Getenv("CACHE_MODE"), // auto (default) | on | off — cache-aware compaction Windows: modelWindows(), // dynamic context-window resolver (fraction triggers) + Mode: mode, // sync (default) | async | observe — explicit, never inferred + Async: proxy.AsyncOptions{ + CacheUncompactedTail: cfg.Async.CacheUncompactedTail, + MaxQueue: cfg.Async.MaxQueue, + Workers: cfg.Async.Workers, + }, // Per-request /compact override: swap the pipeline (?preset / header) while // keeping this config's component blocks. nil-safe in the handler. @@ -86,7 +100,12 @@ func main() { }, }) - slog.Info("context-guru-proxy listening", "addr", addr, "pipeline", cfg.Pipeline) + defer h.Close() // stop the off-path worker pool cleanly (no-op in sync mode) + if mode == components.ModeObserve { + slog.Warn("context-guru: OBSERVE MODE — requests are forwarded UNMODIFIED; " + + "/stats reports what compaction WOULD have saved under potential_*/projected_* keys") + } + slog.Info("context-guru-proxy listening", "addr", addr, "pipeline", cfg.Pipeline, "mode", mode) if err := http.ListenAndServe(addr, h.Mux()); err != nil { log.Fatal(err) } diff --git a/components/component.go b/components/component.go index 34abf17..7301356 100644 --- a/components/component.go +++ b/components/component.go @@ -19,6 +19,7 @@ package components import ( "context" + "fmt" "time" "github.com/maximhq/bifrost/core/schemas" @@ -97,6 +98,39 @@ func (m ModelSpec) For(source string) Model { return m.Static } +// Mode is context-guru's operating mode for one request. The host sets it +// explicitly (proxy Options / config `mode:`); it is NEVER inferred. +// +// ModeSync — compact inline; the caller waits and the compacted request is +// sent. The default, byte-identical to pre-mode behavior. +// ModeAsync — the request path only replays decisions that are already +// computed and makes no LLM call; the expensive compaction runs +// off-path and benefits SUBSEQUENT turns. +// ModeObserve — the pipeline runs on a copy whose output is discarded. The agent +// receives the untouched original; results land in a strictly +// separate (hypothetical) metric namespace. +type Mode string + +// The three operating modes. See Mode. +const ( + ModeSync Mode = "sync" + ModeAsync Mode = "async" + ModeObserve Mode = "observe" +) + +// ParseMode validates a configured mode string; empty means sync. +func ParseMode(s string) (Mode, error) { + switch Mode(s) { + case "", ModeSync: + return ModeSync, nil + case ModeAsync: + return ModeAsync, nil + case ModeObserve: + return ModeObserve, nil + } + return ModeSync, fmt.Errorf("mode must be sync|async|observe, got %q", s) +} + // Ctx is the per-request runtime handed to every component. type Ctx struct { Ctx context.Context @@ -123,6 +157,43 @@ type Ctx struct { // -1 = unknown/first turn/cache off ⇒ no tail restriction. Only meaningful when // CacheAware is true. MaxCachedIdx int + // Mode is the operating mode this request runs under. ModeSync (the zero value + // after the host sets it explicitly) is the default; components that behave + // differently off-path read this rather than inferring anything. + Mode Mode + // Deferred marks a run that happens OFF the request path (the async worker). + // Nothing is forwarded from it: it exists to populate the frozen state later + // turns replay. Components may spend more time/model calls here. + Deferred bool + // TailCachePending turns on async mode's cache protection, and NoCacheAtOrAfter is + // the lowest message index it covers: content that a compaction which has not landed + // yet is expected to REPLACE. A breakpoint there would commit bytes to the provider + // cache that we are about to rewrite, converting a 0.1x read into a 1.25x write — + // 11.5x more expensive, and strictly worse than never going async at all. + // + // The protection needs its own bool rather than a sentinel index, because index 0 is + // a legitimate value ("no breakpoint anywhere") so no integer is free to mean "off". + // A false default also makes the zero-value Ctx unprotected rather than fully + // blocked, which is the safe direction here: an unset field costs a missed + // optimisation, never a wrong request. (Contrast MaxCachedIdx, whose -1 sentinel + // fails the other way — see #25.) + TailCachePending bool + NoCacheAtOrAfter int +} + +// effMode is Ctx.Mode with the zero value normalized to sync, so a Ctx built by +// older code (or a test) reports the default rather than an empty mode string. +func (c *Ctx) effMode() Mode { + if c == nil || c.Mode == "" { + return ModeSync + } + return c.Mode +} + +// CacheBlocked reports whether index i must be left without a cache breakpoint +// because a not-yet-landed compaction is expected to rewrite it. +func (c *Ctx) CacheBlocked(i int) bool { + return c != nil && c.TailCachePending && i >= c.NoCacheAtOrAfter } // TailOnly reports whether a supersession/age-based offloader may mutate the message @@ -150,6 +221,10 @@ type Report struct { Reverted bool // pipeline reverted it (error/panic/never-worse) Irreversible bool // Offload dropped content on purpose without stashing (marker_mode summary/off) Err error + // Mode is the operating mode the run happened under, stamped by the pipeline + // from Ctx.Mode. Emitters MUST branch on it: an observe-mode report is a + // HYPOTHETICAL and may never be summed into enforced savings. + Mode Mode } // Saved returns non-negative tokens saved by this component. @@ -167,6 +242,8 @@ type RunReport struct { TokensAfter int DurationMs float64 Components []Report + // Mode is the operating mode this run happened under (see Report.Mode). + Mode Mode } // Saved returns the net tokens saved across the run. diff --git a/components/pipeline.go b/components/pipeline.go index 7a1786d..a9e380f 100644 --- a/components/pipeline.go +++ b/components/pipeline.go @@ -29,7 +29,7 @@ func NewPipeline(comps []Component, e Emitter) *Pipeline { // report. req is mutated; on any per-component failure that component's changes // are rolled back, so the returned request is never worse than the input. func (p *Pipeline) Run(req *schemas.BifrostChatRequest, c *Ctx) *RunReport { - rr := &RunReport{Session: c.Session, TokensBefore: schema.MessagesTokens(req)} + rr := &RunReport{Session: c.Session, TokensBefore: schema.MessagesTokens(req), Mode: c.effMode()} if c.Bypass { rr.TokensAfter = rr.TokensBefore return rr @@ -60,7 +60,7 @@ func safeEmit(fn func()) { // never-worse guard. It never returns an error — failures are recorded on the // Report and the request is reverted. func (p *Pipeline) runOne(comp Component, req *schemas.BifrostChatRequest, c *Ctx) (rep Report) { - rep = Report{Component: comp.Name()} + rep = Report{Component: comp.Name(), Mode: c.effMode()} before := schema.CloneMessages(req.Input) rep.TokensBefore = tokensOf(before) start := clock() diff --git a/components/reformat/cacheinject.go b/components/reformat/cacheinject.go index fe3e7e8..1cee953 100644 --- a/components/reformat/cacheinject.go +++ b/components/reformat/cacheinject.go @@ -140,6 +140,24 @@ func (ci Cacheinject) Reformat(req *schemas.BifrostChatRequest, rep *components. want[i] = struct{}{} } + // Async cache policy (#31). While a compaction is queued but not yet landed, the + // tail it is going to REPLACE must not be committed to the provider cache: a + // breakpoint at or beyond it turns what would have been a 0.1x read next turn into + // a 1.25x write of that same span — 11.5x the cost. That is exactly the failure + // that tripled headroom's cache-write on Terminal-Bench. So drop every wanted + // position inside the doomed tail and put one at the highest index below it, which + // still writes the whole stable prefix. + if c.TailCachePending { + for i := range want { + if c.CacheBlocked(i) { + delete(want, i) + } + } + if last := c.NoCacheAtOrAfter - 1; last >= 0 && last < len(req.Input) { + want[last] = struct{}{} + } + } + applied := 0 // Count breakpoints the caller already set: they occupy provider slots, and an // agent that sets its own (claude-code does) is already at the optimum. diff --git a/components/reformat/cacheinject_test.go b/components/reformat/cacheinject_test.go index b93623f..4e271ed 100644 --- a/components/reformat/cacheinject_test.go +++ b/components/reformat/cacheinject_test.go @@ -281,3 +281,85 @@ func TestTTLConfig(t *testing.T) { t.Fatal("an unsupported ttl must be rejected, not silently accepted") } } + +// --- Async cache policy (#31) ------------------------------------------------ + +// With the safe default (cache_uncompacted_tail: false), no breakpoint may land at or +// beyond the tail a pending async compaction is going to replace. Committing bytes +// there converts next turn's 0.1x read into a 1.25x write of the same span — 11.5x the +// cost, which makes async strictly worse than sync. +func TestNoBreakpointAtOrBeyondUncompactedTail(t *testing.T) { + const n, boundary = 30, 22 + c := ctx() + c.Mode = components.ModeAsync + c.CacheAware = true + c.MaxCachedIdx = boundary - 1 + c.TailCachePending = true + c.NoCacheAtOrAfter = boundary + + idxs, rep := run(t, c, convo(n)) + if rep.Skipped { + t.Fatal("placed nothing at all: the stable prefix must still be written") + } + for _, i := range idxs { + if i >= boundary { + t.Fatalf("breakpoint at %d is inside the un-compacted tail (>= %d): %v", i, boundary, idxs) + } + } + if len(idxs) == 0 { + t.Fatal("no breakpoint survived; the whole prefix would bill at 1.0x") + } + // The highest safe index carries it, so the longest possible stable prefix is written. + if top := idxs[len(idxs)-1]; top != boundary-1 { + t.Fatalf("top breakpoint is %d, want %d (the highest safe index)", top, boundary-1) + } +} + +// A boundary of 0 means the whole request is doomed tail. Nothing may be written — +// there is no stable prefix to protect and a breakpoint anywhere would be rewritten. +func TestWholeRequestPendingPlacesNothing(t *testing.T) { + c := ctx() + c.Mode = components.ModeAsync + c.TailCachePending = true + c.NoCacheAtOrAfter = 0 + + idxs, rep := run(t, c, convo(10)) + if len(idxs) != 0 { + t.Fatalf("wrote breakpoints over a fully-pending request: %v", idxs) + } + if !rep.Skipped { + t.Fatal("placing nothing should report skipped") + } +} + +// The escape hatch (cache_uncompacted_tail: true) restores normal placement, for a +// backend confirmed not to cache, where the protection costs a slot and buys nothing. +func TestTailCacheProtectionOffRestoresNormalPlacement(t *testing.T) { + msgs := convo(30) + base, _ := run(t, ctx(), msgs) + + c := ctx() + c.Mode = components.ModeAsync // protection NOT enabled (CacheUncompactedTail: true upstream) + off, _ := run(t, c, convo(30)) + + if len(off) != len(base) { + t.Fatalf("unprotected async placement differs from sync: %v vs %v", off, base) + } + for i := range off { + if off[i] != base[i] { + t.Fatalf("unprotected async placement differs from sync: %v vs %v", off, base) + } + } +} + +// Sync mode must be entirely unaffected: TailCachePending false is the default, so a +// Ctx that never heard of modes places exactly what it always did. +func TestSyncPlacementUnaffectedByTheNewFields(t *testing.T) { + base, _ := run(t, ctx(), convo(30)) + c := ctx() + c.Mode = components.ModeSync + sync, _ := run(t, c, convo(30)) + if len(base) != len(sync) { + t.Fatalf("sync placement changed: %v vs %v", base, sync) + } +} diff --git a/config/config.go b/config/config.go index 11334ae..44e99d0 100644 --- a/config/config.go +++ b/config/config.go @@ -26,6 +26,32 @@ type Config struct { Pipeline []string `yaml:"pipeline"` Components map[string]yaml.Node `yaml:"components"` Store store.Options `yaml:"store"` + // Mode is the operating mode: sync (default) | async | observe. See #31 and + // docs/how-to/operating-modes.md. Empty = sync, which is byte-identical to the + // behavior before modes existed. + Mode string `yaml:"mode"` + // Async tunes async mode; ignored in the other two. + Async AsyncConfig `yaml:"async"` +} + +// AsyncConfig is the `async:` block. One option per real decision. +type AsyncConfig struct { + // CacheUncompactedTail lets the not-yet-compacted tail be prompt-cached. The + // default (false) is the safe one: a breakpoint written over a tail that a pending + // compaction then replaces turns a 0.1x cache read into a 1.25x cache write — + // 11.5x the cost — which makes async strictly worse than sync. The escape hatch + // exists because a backend that genuinely does not cache needs no protection. + CacheUncompactedTail bool `yaml:"cache_uncompacted_tail"` + // MaxQueue bounds the off-path job queue (0 = 256). A full queue drops, counted, + // and never blocks the request path. + MaxQueue int `yaml:"max_queue"` + // Workers is the number of drain goroutines (0 = 1). + Workers int `yaml:"workers"` +} + +// OperatingMode validates and returns the configured mode. +func (c *Config) OperatingMode() (components.Mode, error) { + return components.ParseMode(c.Mode) } // Load reads and parses a YAML config file (strict: unknown keys are rejected). @@ -49,6 +75,9 @@ func LoadBytes(b []byte) (*Config, error) { if err := c.applyPreset(); err != nil { return nil, err } + if _, err := c.OperatingMode(); err != nil { + return nil, fmt.Errorf("config: %w", err) + } return &c, nil } diff --git a/metrics/metrics.go b/metrics/metrics.go index c4b345f..04e38a2 100644 --- a/metrics/metrics.go +++ b/metrics/metrics.go @@ -84,6 +84,63 @@ type Aggregator struct { upstreamMsByp float64 // upstream latency on bypassed (baseline) requests upstreamN int64 upstreamNByp int64 + // Mode dimension (#31). Enforced requests are split by mode so a run can tell + // which path produced the savings above; observe-mode results are kept in + // PHYSICALLY separate fields with their own serialized names, so no query over the + // enforced rollups can accidentally include a hypothetical. + mode components.Mode // the configured mode, for the /stats banner + syncRequests int64 + asyncRequests int64 + deferredRuns int64 // off-path async compactions that produced a committed result + deferredMs float64 // wall time spent off the request path + realizedSaved int64 // tokens saved on-path by replaying a previously deferred compaction + potentialRuns int64 + potentialBefore int64 + potentialAfter int64 + potentialMs float64 + potentialComp map[string]*compStat + // asyncStats is a snapshot function for the pool's counter tuple, injected by the + // host so metrics keeps no dependency on the modes package's lifecycle. + asyncStats func() any +} + +// SetMode records the configured operating mode so /stats can label itself — the +// observe-mode banner has to be unmistakable, and a consumer needs to know from the +// payload alone whether the numbers were enforced. +func (a *Aggregator) SetMode(m components.Mode) { + a.mu.Lock() + a.mode = m + a.mu.Unlock() +} + +// SetAsyncStats installs a snapshot function for the async queue counters. +func (a *Aggregator) SetAsyncStats(fn func() any) { + a.mu.Lock() + a.asyncStats = fn + a.mu.Unlock() +} + +// RecordDeferred notes one completed off-path compaction: whether its result was +// committed, and how long it took (time NOT charged to any request). +func (a *Aggregator) RecordDeferred(ms float64, committed bool) { + a.mu.Lock() + a.deferredMs += ms + if committed { + a.deferredRuns++ + } + a.mu.Unlock() +} + +// RecordRealized notes tokens saved on the request path by replaying a compaction an +// EARLIER turn computed off-path. This is async's "savings realized on turn N+k" +// figure: without it the deferred value looks like it never arrived. +func (a *Aggregator) RecordRealized(tokens int) { + if tokens <= 0 { + return + } + a.mu.Lock() + a.realizedSaved += int64(tokens) + a.mu.Unlock() } type compStat struct { @@ -107,6 +164,15 @@ func NewAggregator() *Aggregator { return &Aggregator{perComp: map[string]*compS func (a *Aggregator) Component(r components.Report) { a.mu.Lock() defer a.mu.Unlock() + // Observe mode is a HYPOTHETICAL: nothing was applied to any request. Its numbers + // live in a physically separate map with its own vocabulary, so no aggregate over + // the enforced rollups can reach them. Mixing them would silently inflate the + // product's headline savings claim, which is why this is a correctness boundary + // rather than a presentation choice (#31). + if r.Mode == components.ModeObserve { + a.observeComp(r) + return + } cs := a.perComp[r.Component] if cs == nil { cs = &compStat{} @@ -149,6 +215,50 @@ func (a *Aggregator) Component(r components.Report) { } } +// observeComp accumulates one observe-mode component report into the hypothetical +// namespace. Caller holds the lock. +func (a *Aggregator) observeComp(r components.Report) { + if a.potentialComp == nil { + a.potentialComp = map[string]*compStat{} + } + cs := a.potentialComp[r.Component] + if cs == nil { + cs = &compStat{} + a.potentialComp[r.Component] = cs + } + cs.Runs++ + cs.Saved += int64(r.Saved()) + cs.DurationMs += r.DurationMs + if saved := int64(r.Saved()); saved > 0 && !r.Reverted && !r.Skipped { + if cs.seenKeys == nil { + cs.seenKeys = map[string]struct{}{} + } + if len(r.CacheKeys) == 0 { + cs.SavedUnique += saved + } else { + newKeys := 0 + for _, k := range r.CacheKeys { + if _, seen := cs.seenKeys[k]; !seen { + cs.seenKeys[k] = struct{}{} + newKeys++ + } + } + if newKeys > 0 { + cs.SavedUnique += saved * int64(newKeys) / int64(len(r.CacheKeys)) + } + } + } + if r.Reverted { + cs.Reverted++ + } + if !r.Reverted && !r.Skipped { + cs.Mutated++ + } + if r.Saved() > 0 && !r.Reverted && !r.Skipped { + cs.Acted++ + } +} + // RecordExpand notes that `tokens` of previously-offloaded content had to be // re-served (the model called expand). This is the bounce signal: it means an // offload was premature, so the honest savings figure subtracts it (lean-ctx's @@ -186,9 +296,24 @@ func (a *Aggregator) RecordUpstreamLatency(ms float64, bypassed bool) { func (a *Aggregator) Run(r components.RunReport) { a.mu.Lock() defer a.mu.Unlock() + // Observe: hypothetical. Separate counters, separate JSON keys (potential_* / + // projected_*), never added to requests/before/after. + if r.Mode == components.ModeObserve { + a.potentialRuns++ + a.potentialBefore += int64(r.TokensBefore) + a.potentialAfter += int64(r.TokensAfter) + a.potentialMs += r.DurationMs + return + } a.requests++ a.before += int64(r.TokensBefore) a.after += int64(r.TokensAfter) + switch r.Mode { + case components.ModeAsync: + a.asyncRequests++ + default: + a.syncRequests++ + } } // Snapshot is the JSON served at /stats. It reports both gross savings and the @@ -219,8 +344,48 @@ type Snapshot struct { AddedLatencyMsAvg float64 `json:"cg_added_ms_avg"` UpstreamMsAvg float64 `json:"upstream_ms_avg"` UpstreamMsAvgBypassed float64 `json:"upstream_ms_avg_bypassed"` + + // --- Operating mode (#31). Everything below is ADDITIVE: no existing key was + // renamed or removed, because deploy/harbor/*.py parses this payload. --- + + // Mode is the configured operating mode ("sync" | "async" | "observe"). + Mode string `json:"mode"` + // Enforced counts requests whose forwarded body context-guru actually shaped, + // split by which mode produced it. In observe mode both are 0 BY CONSTRUCTION — + // that is the machine-readable form of "context-guru did not modify requests". + SyncEnforced int64 `json:"sync_enforced"` + AsyncEnforced int64 `json:"async_enforced"` + + // Async: the full queue counter tuple (queued/pending/processed/dropped/errors/ + // stale_discarded) plus the deferred-work accounting. `dropped` and + // `stale_discarded` are the "we silently gave up savings" counters and are + // surfaced deliberately — headroom exposes only `queued`, which hides them. + AsyncQueue any `json:"async_queue,omitempty"` + DeferredRuns int64 `json:"async_deferred_runs"` + DeferredMsTotal float64 `json:"async_deferred_ms_total"` + RealizedSavedTokens int64 `json:"async_realized_saved_tokens"` + + // Observe mode: HYPOTHETICALS. Distinct keys (potential_* / projected_*) that + // never share a name with an enforced metric, so a consumer cannot sum a + // hypothetical into a real saving even by accident. All zero outside observe mode. + ObserveNotice string `json:"observe_notice,omitempty"` + ObserveRequests int64 `json:"observe_hypothetical_requests"` + ActualBaselineTokens int64 `json:"actual_baseline_tokens"` // what the agent really sent + ProjectedOptimizedTokens int64 `json:"projected_optimized_tokens"` // what it would have sent + PotentialSavedTokens int64 `json:"potential_saved_tokens"` + PotentialSavingsPct float64 `json:"potential_savings_pct"` + PotentialComponents map[string]compStat `json:"potential_components,omitempty"` + // PotentialOverheadMsAvg is the mean wall time a compaction WOULD have added to + // each request had this mode been enforcing — measured off-path, so it is what + // sync would cost, not what observe costs. + PotentialOverheadMsAvg float64 `json:"potential_overhead_ms_avg"` } +// observeNotice is the machine- and human-readable banner: in observe mode nothing +// was applied, and every number prefixed potential_/projected_ is a hypothetical. +const observeNotice = "OBSERVE MODE: context-guru did not modify any request. " + + "Every potential_*/projected_* field is a hypothetical, not a realized saving." + // Snapshot returns a point-in-time copy of the rollups. func (a *Aggregator) Snapshot() Snapshot { a.mu.Lock() @@ -257,11 +422,49 @@ func (a *Aggregator) Snapshot() Snapshot { if a.upstreamNByp > 0 { upAvgByp = a.upstreamMsByp / float64(a.upstreamNByp) } - return Snapshot{ + mode := a.mode + if mode == "" { + mode = components.ModeSync + } + snap := Snapshot{ Requests: a.requests, TokensBefore: a.before, TokensAfter: a.after, SavedTokens: saved, SavingsPct: pct, WastedTokens: a.wasted, Bounces: a.bounces, AdjustedSaved: saved - a.wasted, Components: comps, TopPassthrough: passthrough, AddedLatencyMsAvg: addedAvg, UpstreamMsAvg: upAvg, UpstreamMsAvgBypassed: upAvgByp, + Mode: string(mode), + SyncEnforced: a.syncRequests, + AsyncEnforced: a.asyncRequests, + DeferredRuns: a.deferredRuns, DeferredMsTotal: a.deferredMs, + RealizedSavedTokens: a.realizedSaved, + } + if a.asyncStats != nil { + snap.AsyncQueue = a.asyncStats() + } + if a.potentialRuns > 0 || mode == components.ModeObserve { + snap.ObserveNotice = observeNotice + snap.ObserveRequests = a.potentialRuns + snap.ActualBaselineTokens = a.potentialBefore + snap.ProjectedOptimizedTokens = a.potentialAfter + snap.PotentialSavedTokens = a.potentialBefore - a.potentialAfter + if a.potentialBefore > 0 { + snap.PotentialSavingsPct = float64(a.potentialBefore-a.potentialAfter) / float64(a.potentialBefore) * 100 + } + if a.potentialRuns > 0 { + snap.PotentialOverheadMsAvg = a.potentialMs / float64(a.potentialRuns) + } + if len(a.potentialComp) > 0 { + pc := make(map[string]compStat, len(a.potentialComp)) + for k, v := range a.potentialComp { + cs := *v + if cs.SavedUnique > 0 { + cs.OvercountRatio = float64(cs.Saved) / float64(cs.SavedUnique) + } + cs.seenKeys = nil + pc[k] = cs + } + snap.PotentialComponents = pc + } } + return snap } diff --git a/modes/modes_test.go b/modes/modes_test.go new file mode 100644 index 0000000..8efa8b9 --- /dev/null +++ b/modes/modes_test.go @@ -0,0 +1,294 @@ +package modes + +import ( + "context" + "runtime" + "sync" + "sync/atomic" + "testing" + "time" +) + +// --- Tracker ---------------------------------------------------------------- + +func TestTurnReturnsPreviousLengthAndAdvances(t *testing.T) { + tr := NewTracker(0) + if pl, gen := tr.Turn("s", 5); pl != 0 || gen != 0 { + t.Fatalf("first turn: got (%d,%d), want (0,0)", pl, gen) + } + if pl, gen := tr.Turn("s", 9); pl != 5 || gen != 0 { + t.Fatalf("second turn: got (%d,%d), want (5,0)", pl, gen) + } + // A shorter turn must not shrink the boundary: content the provider already + // cached would otherwise fall back into the mutable tail. + if pl, _ := tr.Turn("s", 3); pl != 9 { + t.Fatalf("shorter turn moved the boundary: got %d, want 9", pl) + } + if pl, _ := tr.Turn("s", 12); pl != 9 { + t.Fatalf("boundary not preserved: got %d, want 9", pl) + } +} + +func TestSessionsAreIsolated(t *testing.T) { + tr := NewTracker(0) + tr.Turn("a", 7) + if pl, _ := tr.Turn("b", 2); pl != 0 { + t.Fatalf("session b saw session a's length: %d", pl) + } + tr.CommitIfCurrent("a", 0, nil) + if g := tr.Gen("b"); g != 0 { + t.Fatalf("session b's generation moved with a's: %d", g) + } +} + +// TestStaleResultIsDiscarded is the issue's single most important invariant: a +// result computed from a superseded generation must never be applied. +func TestStaleResultIsDiscarded(t *testing.T) { + tr := NewTracker(0) + _, gen := tr.Turn("s", 4) + + applied := 0 + if !tr.CommitIfCurrent("s", gen, func() { applied++ }) { + t.Fatal("current generation was rejected") + } + if applied != 1 { + t.Fatalf("commit did not run: %d", applied) + } + // A second job built from the SAME (now superseded) generation. + if tr.CommitIfCurrent("s", gen, func() { applied++ }) { + t.Fatal("stale generation was accepted") + } + if applied != 1 { + t.Fatalf("stale commit ran anyway: applied=%d", applied) + } + if g := tr.Gen("s"); g != gen+1 { + t.Fatalf("generation did not advance exactly once: %d", g) + } +} + +// TestConcurrentCommitsOnlyOneWins proves two jobs racing on one session's +// generation cannot both apply. Run under -race. +func TestConcurrentCommitsOnlyOneWins(t *testing.T) { + tr := NewTracker(0) + _, gen := tr.Turn("s", 4) + + var applied atomic.Int64 + var wg sync.WaitGroup + for i := 0; i < 16; i++ { + wg.Add(1) + go func() { + defer wg.Done() + tr.CommitIfCurrent("s", gen, func() { applied.Add(1) }) + }() + } + wg.Wait() + if n := applied.Load(); n != 1 { + t.Fatalf("concurrent commits at one generation applied %d times, want 1", n) + } +} + +// TestConcurrentTurnsDoNotCorruptState is the hazard the issue names: the old +// prevLen was read then written back in a defer, so two turns of one session raced. +// Every observed prevLen must be a length some turn really carried (never a torn or +// lost value), and the final boundary must be the largest. +func TestConcurrentTurnsDoNotCorruptState(t *testing.T) { + tr := NewTracker(0) + const n = 64 + + seen := make([]int, n) + var wg sync.WaitGroup + for i := 0; i < n; i++ { + wg.Add(1) + go func(i int) { + defer wg.Done() + pl, _ := tr.Turn("s", i+1) + seen[i] = pl + }(i) + } + wg.Wait() + + for i, pl := range seen { + if pl < 0 || pl > n { + t.Fatalf("turn %d observed an impossible prevLen %d", i, pl) + } + } + if pl, _ := tr.Turn("s", 0); pl != n { + t.Fatalf("final boundary is %d, want %d (a concurrent write was lost)", pl, n) + } +} + +func TestForgetAndBound(t *testing.T) { + tr := NewTracker(0) + tr.Turn("s", 3) + tr.Forget("s") + if pl, gen := tr.Turn("s", 1); pl != 0 || gen != 0 { + t.Fatalf("forgotten session did not reset: (%d,%d)", pl, gen) + } + small := NewTracker(2) + for i := 0; i < 20; i++ { + small.Turn(string(rune('a'+i)), 1) + } + if n := small.Sessions(); n > 2 { + t.Fatalf("tracker exceeded its bound: %d sessions", n) + } +} + +// --- Pool ------------------------------------------------------------------- + +func TestPoolRunsJobs(t *testing.T) { + p := NewPool(0, 0) + defer p.Stop() + done := make(chan struct{}) + if !p.Enqueue("k", func(context.Context) { close(done) }) { + t.Fatal("enqueue refused") + } + select { + case <-done: + case <-time.After(2 * time.Second): + t.Fatal("job never ran") + } + waitFor(t, func() bool { return p.Stats().Processed == 1 }) +} + +// TestEnqueueDedupIsAtomic hammers one key from many goroutines while the worker is +// blocked. Exactly one may be accepted: the pending slot is claimed before the job +// is observable in the queue, so a concurrent enqueue cannot slip past the check. +func TestEnqueueDedupIsAtomic(t *testing.T) { + p := NewPool(0, 1) + defer p.Stop() + + release := make(chan struct{}) + var ran atomic.Int64 + block := func(context.Context) { ran.Add(1); <-release } + + var accepted atomic.Int64 + var wg sync.WaitGroup + for i := 0; i < 32; i++ { + wg.Add(1) + go func() { + defer wg.Done() + if p.Enqueue("same-key", block) { + accepted.Add(1) + } + }() + } + wg.Wait() + if n := accepted.Load(); n != 1 { + t.Fatalf("dedup admitted %d jobs for one key, want 1", n) + } + close(release) + waitFor(t, func() bool { return p.Stats().Pending == 0 }) + if n := ran.Load(); n != 1 { + t.Fatalf("job body ran %d times, want 1", n) + } +} + +// TestFullQueueDropsAndNeverBlocks: the request has already been forwarded, so a +// drop costs savings only — but it must be counted, and Enqueue must not block. +func TestFullQueueDropsAndNeverBlocks(t *testing.T) { + p := NewPool(2, 1) + defer p.Stop() + + release := make(chan struct{}) + defer close(release) + // Occupy the single worker so nothing drains. + p.Enqueue("busy", func(context.Context) { <-release }) + waitFor(t, func() bool { return p.Stats().Pending == 1 }) + + noop := func(context.Context) {} + accepted, dropped := 0, 0 + deadline := time.After(5 * time.Second) + for i := 0; i < 50; i++ { + ok := make(chan bool, 1) + go func(i int) { ok <- p.Enqueue(string(rune('A'+i)), noop) }(i) + select { + case v := <-ok: + if v { + accepted++ + } else { + dropped++ + } + case <-deadline: + t.Fatal("Enqueue blocked on a full queue") + } + } + if dropped == 0 { + t.Fatal("a full queue accepted everything") + } + if got := p.Stats().Dropped; got != int64(dropped) { + t.Fatalf("dropped counter is %d, want %d", got, dropped) + } + if accepted > 2 { + t.Fatalf("queue of 2 accepted %d jobs", accepted) + } +} + +// TestStopLeaksNoGoroutines: cancellation must return every worker. +func TestStopLeaksNoGoroutines(t *testing.T) { + settle() + before := runtime.NumGoroutine() + + p := NewPool(16, 4) + p.Enqueue("a", func(context.Context) {}) + waitFor(t, func() bool { return p.Stats().Processed >= 1 }) + p.Stop() + p.Stop() // idempotent + + settle() + if after := runtime.NumGoroutine(); after > before { + t.Fatalf("goroutine leak: %d before, %d after Stop", before, after) + } + if p.Enqueue("b", func(context.Context) {}) { + t.Fatal("a stopped pool accepted a job") + } +} + +// TestPanickingJobIsContained: fail-open. Nothing was riding on the job. +func TestPanickingJobIsContained(t *testing.T) { + p := NewPool(0, 1) + defer p.Stop() + p.Enqueue("boom", func(context.Context) { panic("nope") }) + waitFor(t, func() bool { return p.Stats().Errors == 1 }) + + done := make(chan struct{}) + p.Enqueue("after", func(context.Context) { close(done) }) + select { + case <-done: + case <-time.After(2 * time.Second): + t.Fatal("the worker died with the panicking job") + } +} + +func TestStatsExposesTheWholeTuple(t *testing.T) { + p := NewPool(0, 1) + defer p.Stop() + p.RecordStale() + p.RecordError() + s := p.Stats() + if s.StaleDiscarded != 1 || s.Errors != 1 { + t.Fatalf("counters not recorded: %+v", s) + } +} + +// --- helpers ---------------------------------------------------------------- + +func waitFor(t *testing.T, cond func() bool) { + t.Helper() + deadline := time.Now().Add(3 * time.Second) + for time.Now().Before(deadline) { + if cond() { + return + } + time.Sleep(2 * time.Millisecond) + } + t.Fatal("condition never became true") +} + +// settle gives already-finishing goroutines a chance to exit so a leak check +// compares like with like. +func settle() { + for i := 0; i < 20; i++ { + runtime.Gosched() + time.Sleep(5 * time.Millisecond) + } +} diff --git a/modes/pool.go b/modes/pool.go new file mode 100644 index 0000000..b66b616 --- /dev/null +++ b/modes/pool.go @@ -0,0 +1,212 @@ +package modes + +import ( + "context" + "log/slog" + "sync" +) + +// Pool is the bounded off-path worker pool for async and observe mode: one queue, +// a fixed number of drain goroutines, owned by the host (the proxy) rather than +// spawned per request. +// +// The shape is headroom's BackgroundCompressor, ported and extended: +// +// - dedup by key, with the pending slot claimed BEFORE the job becomes +// observable in the queue, so dedup is atomic against a concurrent enqueue of +// the same key; +// - a bounded queue that DROPS rather than blocks — the request has already been +// forwarded, so a drop costs savings, never correctness, and the request path +// must never wait on this; +// - no request-coupled deadline: jobs run under the pool's own context, not the +// inbound request's, which is cancelled the moment the response is written; +// - fail-open on every path, including a panicking job; +// - the FULL counter tuple exposed, dropped and stale_discarded included. +// headroom's dashboard shows only `queued`, which hides exactly the counter that +// says "we silently gave up savings". +type Pool struct { + q chan job + ctx context.Context + cancel context.CancelFunc + wg sync.WaitGroup + started bool + + mu sync.Mutex + pending map[string]struct{} + processed int64 + dropped int64 + errors int64 + staleDiscarded int64 +} + +type job struct { + key string + run func(context.Context) +} + +// Stats is the async queue's counter tuple, surfaced whole in /stats. +type Stats struct { + Queued int64 `json:"queued"` + Pending int64 `json:"pending"` + Processed int64 `json:"processed"` + Dropped int64 `json:"dropped"` + Errors int64 `json:"errors"` + StaleDiscarded int64 `json:"stale_discarded"` +} + +// Defaults for the pool's two knobs. One worker is deliberate: the expensive part of +// a compaction is an LLM call, and one in flight per process keeps the cheap-model +// spend and the gateway's rate limit predictable while still removing the latency from +// the request path. +const ( + DefaultMaxQueue = 256 + DefaultWorkers = 1 +) + +// NewPool builds and starts a pool. maxQueue/workers <= 0 take the defaults. +// Call Stop to shut it down; a stopped pool drops every later enqueue. +func NewPool(maxQueue, workers int) *Pool { + if maxQueue <= 0 { + maxQueue = DefaultMaxQueue + } + if workers <= 0 { + workers = DefaultWorkers + } + ctx, cancel := context.WithCancel(context.Background()) + p := &Pool{ + q: make(chan job, maxQueue), + ctx: ctx, + cancel: cancel, + started: true, + pending: map[string]struct{}{}, + } + for i := 0; i < workers; i++ { + p.wg.Add(1) + go p.drain() + } + return p +} + +// Enqueue queues run under key, returning false if it was dropped — because the key +// is already queued or in flight (dedup / coalesced supersession), the queue is full, +// or the pool is stopped. Never blocks. +func (p *Pool) Enqueue(key string, run func(context.Context)) bool { + if p == nil || run == nil { + return false + } + p.mu.Lock() + if !p.started { + p.mu.Unlock() + return false + } + if _, dup := p.pending[key]; dup { + p.mu.Unlock() + return false // already queued or running — the newer turn will enqueue the next generation + } + // Claim the slot BEFORE the job is observable in the queue, so a concurrent + // Enqueue of the same key cannot slip past the dedup check. + p.pending[key] = struct{}{} + p.mu.Unlock() + + select { + case p.q <- job{key: key, run: run}: + return true + default: + p.mu.Lock() + delete(p.pending, key) + p.dropped++ + p.mu.Unlock() + slog.Warn("context-guru: async queue full, dropping compaction job (request already forwarded)", + "key", key, "max_queue", cap(p.q)) + return false + } +} + +func (p *Pool) drain() { + defer p.wg.Done() + for { + select { + case <-p.ctx.Done(): + return + case j, ok := <-p.q: + if !ok { + return + } + p.runOne(j) + } + } +} + +func (p *Pool) runOne(j job) { + defer func() { + p.mu.Lock() + delete(p.pending, j.key) + if r := recover(); r != nil { + p.errors++ + p.mu.Unlock() + slog.Error("context-guru: recovered from panic in async compaction job", "key", j.key, "panic", r) + return + } + p.processed++ + p.mu.Unlock() + }() + j.run(p.ctx) +} + +// RecordStale notes that a completed job's result was thrown away because a newer +// generation had already landed. Counted separately from `dropped` (never ran) and +// `errors` (ran and failed): a rising stale count means turns arrive faster than +// compaction finishes, which is a tuning signal, not a fault. +func (p *Pool) RecordStale() { + if p == nil { + return + } + p.mu.Lock() + p.staleDiscarded++ + p.mu.Unlock() +} + +// RecordError notes a job that ran but produced nothing usable. +func (p *Pool) RecordError() { + if p == nil { + return + } + p.mu.Lock() + p.errors++ + p.mu.Unlock() +} + +// Stats returns the counter tuple. +func (p *Pool) Stats() Stats { + if p == nil { + return Stats{} + } + p.mu.Lock() + defer p.mu.Unlock() + return Stats{ + Queued: int64(len(p.q)), + Pending: int64(len(p.pending)), + Processed: p.processed, + Dropped: p.dropped, + Errors: p.errors, + StaleDiscarded: p.staleDiscarded, + } +} + +// Stop cancels the pool's context and waits for its workers to exit. Queued jobs are +// abandoned — they were pure savings, and the requests they belonged to went out long +// ago. Idempotent. +func (p *Pool) Stop() { + if p == nil { + return + } + p.mu.Lock() + if !p.started { + p.mu.Unlock() + return + } + p.started = false + p.mu.Unlock() + p.cancel() + p.wg.Wait() +} diff --git a/modes/tracker.go b/modes/tracker.go new file mode 100644 index 0000000..894cde3 --- /dev/null +++ b/modes/tracker.go @@ -0,0 +1,130 @@ +// Package modes implements context-guru's three operating modes (#31): the +// per-session compaction generation that makes an async result safe to apply or +// safe to throw away, and the bounded worker pool that computes those results off +// the request path. +// +// Why a generation at all. In async mode the expensive compaction runs after the +// request has already been forwarded, so its output lands in a session's frozen +// state at some later, unpredictable moment. Between enqueue and commit the agent +// may have taken another turn, and another job may have committed. Applying a +// result computed from a snapshot that no longer describes the session is how a +// compaction proxy corrupts a cached prefix. So every job records the generation it +// was built from, and a result whose generation is no longer current is DISCARDED — +// lost savings, never lost correctness. +// +// The generation advances only when a compaction actually LANDS. That is what makes +// the scheme non-starving: dedup on (session, generation) keeps at most one useful +// job in flight per session, a commit moves the session to the next generation, and +// the following turn enqueues a fresh job against the newer, longer transcript. +package modes + +import "sync" + +// Tracker holds the per-session state the modes need, each session's fields guarded +// by one lock so concurrent turns of a session cannot interleave a read and a write. +// +// It also owns prevLen — the number of normalized messages the previous turn carried, +// which is the already-cached/uncached boundary. That used to live in the TTL store +// and was read then written back in a `defer`, so two concurrent turns of one session +// raced on it (the hazard #31 calls out, overlapping with #25). Reading and writing it +// under the same lock, in one call, removes the race. +type Tracker struct { + mu sync.Mutex + m map[string]*sessState + max int // bound on tracked sessions; 0 => default +} + +type sessState struct { + gen uint64 + prevLen int +} + +// defaultMaxSessions bounds the tracker so an unbounded stream of distinct sessions +// cannot grow it without limit. Matches the store's sticky-set bound. +const defaultMaxSessions = 1000 + +// NewTracker returns an empty tracker. maxSessions <= 0 uses the default bound. +func NewTracker(maxSessions int) *Tracker { + if maxSessions <= 0 { + maxSessions = defaultMaxSessions + } + return &Tracker{m: map[string]*sessState{}, max: maxSessions} +} + +// get returns the session's state, creating it under the caller-held lock. +func (t *Tracker) get(session string) *sessState { + s := t.m[session] + if s == nil { + if len(t.m) >= t.max { + // ponytail: arbitrary eviction, same policy as the store's sticky sets. + // A dropped session just re-starts at generation 0 — correct, less saving. + for k := range t.m { + delete(t.m, k) + break + } + } + s = &sessState{} + t.m[session] = s + } + return s +} + +// Turn records that this session's current turn carries n normalized messages and +// returns the snapshot the request must be built from: the PREVIOUS turn's length +// (the cached-prefix boundary) and the current compaction generation. Atomic, so two +// concurrent turns of one session each get a consistent pair and the second's write +// cannot be lost to the first's deferred write-back. +// +// prevLen only ever grows: an agent that re-sends a shorter transcript (a rewind, or +// a second, smaller request under the same session id) must not shrink the boundary, +// or content the provider already cached would fall back into the mutable tail. +func (t *Tracker) Turn(session string, n int) (prevLen int, gen uint64) { + t.mu.Lock() + defer t.mu.Unlock() + s := t.get(session) + prevLen, gen = s.prevLen, s.gen + if n > s.prevLen { + s.prevLen = n + } + return prevLen, gen +} + +// Gen returns the session's current compaction generation. +func (t *Tracker) Gen(session string) uint64 { + t.mu.Lock() + defer t.mu.Unlock() + return t.get(session).gen +} + +// CommitIfCurrent runs commit and advances the generation IF the session is still at +// gen — the stale-result guard. commit is called while the session's lock is held, so +// a concurrent job for the same session cannot also observe gen as current and commit +// on top of it. Returns false when the result was stale and therefore discarded. +func (t *Tracker) CommitIfCurrent(session string, gen uint64, commit func()) bool { + t.mu.Lock() + defer t.mu.Unlock() + s := t.get(session) + if s.gen != gen { + return false + } + if commit != nil { + commit() + } + s.gen++ + return true +} + +// Forget drops a session's state (session end / eviction). The next turn starts over +// at generation 0, which only costs the pending job's savings. +func (t *Tracker) Forget(session string) { + t.mu.Lock() + delete(t.m, session) + t.mu.Unlock() +} + +// Sessions reports how many sessions are tracked (test/telemetry aid). +func (t *Tracker) Sessions() int { + t.mu.Lock() + defer t.mu.Unlock() + return len(t.m) +} diff --git a/proxy/modes.go b/proxy/modes.go new file mode 100644 index 0000000..18aaddc --- /dev/null +++ b/proxy/modes.go @@ -0,0 +1,185 @@ +package proxy + +import ( + "context" + "log/slog" + "strconv" + "time" + + bschemas "github.com/maximhq/bifrost/core/schemas" + "github.com/rossoctl/context-guru/apply" + "github.com/rossoctl/context-guru/components" + "github.com/rossoctl/context-guru/store" +) + +// Operating modes on the request path (#31). +// +// One function decides what the client's request becomes, per mode: +// +// sync — run the pipeline inline and forward its output. Unchanged from before +// modes existed, down to the bytes; this is the default. +// async — run the pipeline inline WITHOUT model clients, so it costs deterministic +// time only and replays whatever a previous turn's off-path job already +// froze. Then enqueue the expensive full compaction for the NEXT turn. +// While a compaction is pending, no cache breakpoint is placed at or beyond +// the tail that compaction will replace (see apply.Opts). +// observe — forward the ORIGINAL body, byte for byte, and run the pipeline off-path +// on a copy purely to record what it WOULD have saved. +// +// Fail-open is per mode: sync and async forward the best body they have, observe +// forwards the input by construction, and any panic in an off-path job is contained by +// the pool (nothing was riding on it). + +// applyMode rewrites body for forwarding according to the handler's mode, and returns +// the body to forward plus the wall time to charge to the request path. Never returns +// a nil body. +func (h *Handler) applyMode(r *httpReqInfo) ([]byte, time.Duration) { + mode := h.mode() + start := time.Now() + + // Observe: the enforced path does nothing at all. Not "runs and discards" — the + // request path never touches the pipeline, which is what makes the byte-identity + // guarantee structural rather than a property of careful copying. The measurement + // happens on the pool, on a copy, and the request pays only the enqueue. + if mode == components.ModeObserve && !r.bypassed { + h.enqueueObserve(r) + return r.body, time.Since(start) + } + + res := apply.BodyOpts(r.ctx, h.pipe, h.store, apply.Opts{ + Provider: r.provider, Body: r.body, Session: r.session, Bypass: r.bypassed, + Models: r.models, Window: r.window, CacheMode: h.opts.CacheMode, + Mode: mode, Tracker: h.tracker, + CacheUncompactedTail: h.opts.Async.CacheUncompactedTail, + }) + added := time.Since(start) + + if mode == components.ModeAsync && !r.bypassed { + // The savings this turn came from replaying an EARLIER turn's off-path work. + // Attributing them is the only way deferred value stops looking invisible. + if h.agg != nil && res.Run != nil && res.Run.Saved() > 0 { + h.agg.RecordRealized(res.Run.Saved()) + } + h.enqueueAsync(r, res) + } + if res.Body == nil { + return r.body, added + } + return res.Body, added +} + +// httpReqInfo is the per-request input both the inline pass and an off-path job need. +// Bundled because an off-path job outlives the *http.Request it came from and must +// therefore hold a copy of everything, never a pointer into request-scoped state. +type httpReqInfo struct { + ctx context.Context + provider bschemas.ModelProvider + body []byte + session string + bypassed bool + models components.ModelSpec + window int +} + +func (h *Handler) mode() components.Mode { + if h.opts.Mode == "" { + return components.ModeSync + } + return h.opts.Mode +} + +// jobKey is the dedup key: one useful job per (session, generation). A second turn +// arriving at the same generation coalesces onto the queued job instead of adding a +// second one, and once that job commits the generation advances so the next turn +// enqueues fresh work against the longer transcript. +func jobKey(session string, gen uint64) string { + return session + "@" + strconv.FormatUint(gen, 10) +} + +// enqueueAsync queues the expensive compaction for a session, to benefit later turns. +// The result is written into a store.Buffer and committed ONLY if the session is still +// at the generation the job was built from — the stale-result guard. Committing a stale +// result would replace content the provider has already cached against a newer turn's +// prefix, which is the failure mode async exists to avoid. +func (h *Handler) enqueueAsync(r *httpReqInfo, inline apply.Result) { + if h.pool == nil { + return + } + // Copies: the job runs after the response is written, so nothing may alias + // request-scoped memory. The context, likewise, must be the pool's, not the + // request's — the request's is cancelled the moment the handler returns. + body := append([]byte(nil), r.body...) + info := *r + info.body = body + + // The inline pass already resolved the session id (a content hash when the host + // supplied none), so reuse it: the dedup key and the generation check must use the + // SAME id apply used, and recomputing invites the two to drift. + sess, gen, prevLen := inline.Session, inline.Generation, inline.PrevLen + if sess == "" { + return // the pipeline never ran (no messages array) — nothing to defer + } + key := jobKey(sess, gen) + + h.pool.Enqueue(key, func(ctx context.Context) { + start := time.Now() + buf := store.NewBuffer(h.store) + info.ctx = ctx + res := apply.BodyOpts(ctx, h.pipe, buf, apply.Opts{ + Provider: info.provider, Body: info.body, Session: info.session, + Models: info.models, Window: info.window, CacheMode: h.opts.CacheMode, + // Deferred: this run's BODY is thrown away — only the frozen decisions it + // writes into the buffer matter, and those are what later turns replay. So it + // gets the model clients the inline async pass withheld. + Mode: components.ModeAsync, Deferred: true, + // PrevLen instead of a Tracker: an off-path run must reuse the boundary its + // own turn was built with, and must not advance it — the boundary belongs to + // real turns. By now the tracker has moved past this turn, so re-resolving + // would gate the run against a boundary its body never had. + PrevLen: &prevLen, + }) + committed := false + if res.Changed && buf.Writes() > 0 { + committed = h.tracker.CommitIfCurrent(sess, gen, buf.Commit) + if !committed { + h.pool.RecordStale() + slog.Debug("context-guru: discarded stale async compaction", + "session", sess, "generation", gen) + } + } + if h.agg != nil { + h.agg.RecordDeferred(float64(time.Since(start).Microseconds())/1000.0, committed) + } + }) +} + +// enqueueObserve runs the pipeline off-path on a COPY of the request, against a store +// Buffer that is never committed, and records the result into the hypothetical metric +// namespace. Two independent reasons the enforced request cannot be affected: it was +// already forwarded from the untouched original, and every state write this run makes +// is thrown away with the buffer. +func (h *Handler) enqueueObserve(r *httpReqInfo) { + if h.pool == nil { + return + } + body := append([]byte(nil), r.body...) + info := *r + info.body = body + // A plain counter, not (session, generation): an observe run never commits, so its + // generation never advances, and keying on it would dedup every turn after the first + // out of existence. The counter is also why observe needs no session resolve on the + // request path — one more thing the enforced path does not pay for. + key := "observe:" + strconv.FormatUint(h.observeSeq.Add(1), 10) + + h.pool.Enqueue(key, func(ctx context.Context) { + apply.BodyOpts(ctx, h.pipe, store.NewBuffer(h.store), apply.Opts{ + Provider: info.provider, Body: info.body, Session: info.session, + Models: info.models, Window: info.window, CacheMode: h.opts.CacheMode, + Mode: components.ModeObserve, + }) + // The pipeline already emitted mode-stamped reports through the emitter; the + // Aggregator routes anything stamped observe into the potential_* namespace. No + // separate recording call here, which is what keeps the two namespaces from + // drifting apart. + }) +} diff --git a/proxy/modes_test.go b/proxy/modes_test.go new file mode 100644 index 0000000..f8d9f78 --- /dev/null +++ b/proxy/modes_test.go @@ -0,0 +1,398 @@ +package proxy_test + +import ( + "bytes" + "encoding/json" + "io" + "net/http" + "net/http/httptest" + "runtime" + "strings" + "sync" + "testing" + "time" + + "github.com/rossoctl/context-guru/components" + _ "github.com/rossoctl/context-guru/components/all" + "github.com/rossoctl/context-guru/config" + "github.com/rossoctl/context-guru/metrics" + "github.com/rossoctl/context-guru/proxy" + "github.com/rossoctl/context-guru/store" +) + +// modeHandler is buildHandler plus an explicit operating mode, and it hands back the +// aggregator so a test can read the mode-partitioned rollups. +func modeHandler(t *testing.T, yaml, upstream string, mode components.Mode) (*proxy.Handler, *metrics.Aggregator) { + t.Helper() + cfg, err := config.LoadBytes([]byte(yaml)) + if err != nil { + t.Fatal(err) + } + agg := metrics.NewAggregator() + pipe, err := cfg.Build(agg) + if err != nil { + t.Fatal(err) + } + h := proxy.New(pipe, store.NewMemory(store.Options{}), agg, proxy.Options{ + OpenAIUpstream: upstream, AnthropicUpstream: upstream, Mode: mode, + }) + t.Cleanup(h.Close) + return h, agg +} + +// captureUpstream records every body the upstream receives. +func captureUpstream(t *testing.T) (*httptest.Server, func() [][]byte) { + t.Helper() + var mu sync.Mutex + var got [][]byte + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + b, _ := io.ReadAll(r.Body) + mu.Lock() + got = append(got, b) + mu.Unlock() + w.Header().Set("Content-Type", "application/json") + w.Write([]byte(`{"ok":true}`)) + })) + t.Cleanup(srv.Close) + return srv, func() [][]byte { + mu.Lock() + defer mu.Unlock() + return append([][]byte(nil), got...) + } +} + +const modePipeline = "pipeline: [dedup, cacheinject]\n" + +func dupBody() []byte { + dump := strings.Repeat("a verbose repeated tool output line\n", 60) + return openAIBody( + map[string]any{"role": "user", "content": "do the thing"}, + map[string]any{"role": "tool", "tool_call_id": "a", "content": dump}, + map[string]any{"role": "tool", "tool_call_id": "b", "content": dump}, + ) +} + +func post(t *testing.T, srv *httptest.Server, body []byte) { + t.Helper() + resp, err := http.Post(srv.URL+"/openai/v1/chat/completions", "application/json", bytes.NewReader(body)) + if err != nil { + t.Fatal(err) + } + io.Copy(io.Discard, resp.Body) + resp.Body.Close() +} + +// awaitSnapshot polls until cond holds, so an off-path result can land. +func awaitSnapshot(t *testing.T, agg *metrics.Aggregator, cond func(metrics.Snapshot) bool) metrics.Snapshot { + t.Helper() + deadline := time.Now().Add(5 * time.Second) + var snap metrics.Snapshot + for time.Now().Before(deadline) { + snap = agg.Snapshot() + if cond(snap) { + return snap + } + time.Sleep(5 * time.Millisecond) + } + return snap +} + +// TestSyncIsTheDefaultAndUnchanged: an unset mode must behave exactly like the +// explicit sync mode, which is the pre-change behavior. The forwarded bodies are +// compared byte for byte — the golden test the issue asks for, expressed against the +// code's own output rather than a checked-in fixture that would drift on every +// unrelated component change. +func TestSyncIsTheDefaultAndUnchanged(t *testing.T) { + body := dupBody() + + upA, gotA := captureUpstream(t) + hA, _ := modeHandler(t, modePipeline, upA.URL, "") // unset + srvA := httptest.NewServer(hA.Mux()) + defer srvA.Close() + post(t, srvA, body) + + upB, gotB := captureUpstream(t) + hB, _ := modeHandler(t, modePipeline, upB.URL, components.ModeSync) + srvB := httptest.NewServer(hB.Mux()) + defer srvB.Close() + post(t, srvB, body) + + a, b := gotA(), gotB() + if len(a) != 1 || len(b) != 1 { + t.Fatalf("expected one forward each, got %d and %d", len(a), len(b)) + } + if !bytes.Equal(a[0], b[0]) { + t.Fatalf("default mode differs from explicit sync\n default: %s\n sync: %s", a[0], b[0]) + } + // And sync really did compact: otherwise the comparison above is vacuous. + if bytes.Equal(a[0], body) { + t.Fatal("sync forwarded the original unchanged — the golden comparison proves nothing") + } +} + +// TestObserveForwardsByteIdenticalBody is the mode's core promise: the agent receives +// exactly what it sent, while the hypothetical savings are still recorded. +func TestObserveForwardsByteIdenticalBody(t *testing.T) { + up, got := captureUpstream(t) + h, agg := modeHandler(t, modePipeline, up.URL, components.ModeObserve) + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + + body := dupBody() + post(t, srv, body) + + fwd := got() + if len(fwd) != 1 { + t.Fatalf("expected one forward, got %d", len(fwd)) + } + if !bytes.Equal(fwd[0], body) { + t.Fatalf("observe mode MODIFIED the forwarded body\n sent: %s\n fwd: %s", body, fwd[0]) + } + + snap := awaitSnapshot(t, agg, func(s metrics.Snapshot) bool { return s.ObserveRequests > 0 }) + if snap.ObserveRequests == 0 { + t.Fatal("observe mode recorded nothing") + } + if snap.PotentialSavedTokens <= 0 { + t.Fatalf("no potential savings recorded: %+v", snap) + } + if snap.ActualBaselineTokens <= snap.ProjectedOptimizedTokens { + t.Fatalf("projected usage is not below the actual baseline: %d vs %d", + snap.ProjectedOptimizedTokens, snap.ActualBaselineTokens) + } + if snap.ObserveNotice == "" { + t.Fatal("observe mode did not emit its banner") + } + if snap.Mode != string(components.ModeObserve) { + t.Fatalf("mode not reported: %q", snap.Mode) + } +} + +// TestObserveMetricsCannotBeSummedIntoEnforcedTotals is the correctness requirement: a +// hypothetical must be unreachable from every enforced aggregate, or the product's +// headline savings claim is silently inflated. +func TestObserveMetricsCannotBeSummedIntoEnforcedTotals(t *testing.T) { + up, _ := captureUpstream(t) + h, agg := modeHandler(t, modePipeline, up.URL, components.ModeObserve) + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + + for i := 0; i < 3; i++ { + post(t, srv, dupBody()) + } + snap := awaitSnapshot(t, agg, func(s metrics.Snapshot) bool { return s.ObserveRequests > 0 }) + if snap.ObserveRequests == 0 { + t.Fatal("nothing was observed; the test proves nothing") + } + if snap.Requests != 0 || snap.TokensBefore != 0 || snap.TokensAfter != 0 || snap.SavedTokens != 0 { + t.Fatalf("observe results leaked into the enforced totals: %+v", snap) + } + if snap.SyncEnforced != 0 || snap.AsyncEnforced != 0 { + t.Fatalf("observe counted as enforced: sync=%d async=%d", snap.SyncEnforced, snap.AsyncEnforced) + } + if len(snap.Components) != 0 { + t.Fatalf("observe results leaked into the enforced per-component map: %v", snap.Components) + } + if len(snap.PotentialComponents) == 0 { + t.Fatal("per-component hypotheticals were not recorded at all") + } + // The serialized payload must keep the two vocabularies disjoint. + m := marshalMap(t, snap) + for _, enforced := range []string{"saved_tokens", "savings_pct", "tokens_before", "tokens_after", "requests", "components"} { + if _, ok := m[enforced]; !ok { + t.Fatalf("%q disappeared from /stats — backward compatibility broken", enforced) + } + } + for _, hypothetical := range []string{ + "potential_saved_tokens", "projected_optimized_tokens", "actual_baseline_tokens", + "potential_components", "observe_notice", "observe_hypothetical_requests", + } { + if _, ok := m[hypothetical]; !ok { + t.Fatalf("hypothetical key %q missing from the payload", hypothetical) + } + } +} + +// TestStatsStaysBackwardCompatible: deploy/harbor/*.py parses this payload, so fields +// may be added but never renamed or removed. +func TestStatsStaysBackwardCompatible(t *testing.T) { + up, _ := captureUpstream(t) + h, _ := modeHandler(t, modePipeline, up.URL, components.ModeSync) + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + post(t, srv, dupBody()) + + resp, err := http.Get(srv.URL + "/stats") + if err != nil { + t.Fatal(err) + } + defer resp.Body.Close() + var m map[string]any + if err := json.NewDecoder(resp.Body).Decode(&m); err != nil { + t.Fatal(err) + } + for _, k := range []string{ + "requests", "tokens_before", "tokens_after", "saved_tokens", "savings_pct", + "wasted_tokens", "bounces", "adjusted_saved", "components", "top_passthrough", + "llm_calls", "llm_input_tokens", "llm_output_tokens", + "cg_added_ms_avg", "upstream_ms_avg", "upstream_ms_avg_bypassed", + } { + if _, ok := m[k]; !ok { + t.Fatalf("/stats lost the pre-existing field %q", k) + } + } + for _, k := range []string{"mode", "sync_enforced", "async_enforced"} { + if _, ok := m[k]; !ok { + t.Fatalf("/stats is missing the new field %q", k) + } + } + if m["mode"] != string(components.ModeSync) { + t.Fatalf("mode is %v, want sync", m["mode"]) + } + if m["sync_enforced"].(float64) < 1 { + t.Fatalf("sync request not counted as enforced: %v", m["sync_enforced"]) + } +} + +// TestAsyncForwardsAndDefersWork: the request goes out, is counted under its own +// mode, and the queue tuple is exposed whole. +func TestAsyncForwardsAndDefersWork(t *testing.T) { + up, got := captureUpstream(t) + h, agg := modeHandler(t, modePipeline, up.URL, components.ModeAsync) + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + + post(t, srv, dupBody()) + if fwd := got(); len(fwd) != 1 { + t.Fatalf("expected one forward, got %d", len(fwd)) + } + snap := agg.Snapshot() + if snap.AsyncEnforced != 1 { + t.Fatalf("async request not counted under its own mode: %+v", snap) + } + if snap.SyncEnforced != 0 { + t.Fatal("async request counted as sync") + } + if snap.ObserveRequests != 0 || snap.PotentialSavedTokens != 0 { + t.Fatal("async results leaked into the hypothetical namespace") + } + q, ok := marshalMap(t, snap)["async_queue"] + if !ok { + t.Fatal("async_queue absent from /stats in async mode") + } + var tuple map[string]int64 + if err := json.Unmarshal(q, &tuple); err != nil { + t.Fatal(err) + } + for _, k := range []string{"queued", "pending", "processed", "dropped", "errors", "stale_discarded"} { + if _, ok := tuple[k]; !ok { + t.Fatalf("async_queue is missing %q — the whole tuple must be exposed", k) + } + } +} + +// TestConcurrentTurnsOneSession pushes many simultaneous turns of ONE session through +// the real handler in async mode: no race (run under -race), no corruption, and every +// request still answered. +func TestConcurrentTurnsOneSession(t *testing.T) { + up, got := captureUpstream(t) + h, _ := modeHandler(t, modePipeline, up.URL, components.ModeAsync) + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + + body := dupBody() + var wg sync.WaitGroup + for i := 0; i < 24; i++ { + wg.Add(1) + go func() { + defer wg.Done() + req, _ := http.NewRequest(http.MethodPost, srv.URL+"/openai/v1/chat/completions", bytes.NewReader(body)) + req.Header.Set("Content-Type", "application/json") + req.Header.Set("x-context-guru-session", "shared") + resp, err := http.DefaultClient.Do(req) + if err != nil { + t.Error(err) + return + } + io.Copy(io.Discard, resp.Body) + resp.Body.Close() + }() + } + wg.Wait() + if n := len(got()); n != 24 { + t.Fatalf("forwarded %d of 24 requests", n) + } +} + +// TestCloseLeavesNoGoroutines: the pool the handler owns must be reclaimed. +func TestCloseLeavesNoGoroutines(t *testing.T) { + // Everything unrelated (the mock upstream's own goroutines) is created BEFORE the + // baseline, so the only difference this measures is the pool's. + up, _ := captureUpstream(t) + settleGoroutines() + before := runtime.NumGoroutine() + + cfg, err := config.LoadBytes([]byte(modePipeline)) + if err != nil { + t.Fatal(err) + } + agg := metrics.NewAggregator() + pipe, err := cfg.Build(agg) + if err != nil { + t.Fatal(err) + } + h := proxy.New(pipe, store.NewMemory(store.Options{}), agg, proxy.Options{ + OpenAIUpstream: up.URL, Mode: components.ModeAsync, + }) + h.Close() + h.Close() // idempotent + + settleGoroutines() + if after := runtime.NumGoroutine(); after > before { + t.Fatalf("goroutine leak after Close: %d before, %d after", before, after) + } +} + +// TestSyncModeStartsNoPool: sync adds no machinery — no pool, no async_queue. +func TestSyncModeStartsNoPool(t *testing.T) { + up, _ := captureUpstream(t) + _, agg := modeHandler(t, modePipeline, up.URL, components.ModeSync) + raw, err := json.Marshal(agg.Snapshot()) + if err != nil { + t.Fatal(err) + } + if bytes.Contains(raw, []byte("async_queue")) { + t.Fatalf("sync mode advertised an async queue: %s", raw) + } +} + +func TestUnknownModeIsRejected(t *testing.T) { + if _, err := config.LoadBytes([]byte("pipeline: [dedup]\nmode: turbo\n")); err == nil { + t.Fatal("an unknown mode was accepted") + } + for _, ok := range []string{"", "sync", "async", "observe"} { + if _, err := config.LoadBytes([]byte("pipeline: [dedup]\nmode: " + ok + "\n")); err != nil { + t.Fatalf("mode %q rejected: %v", ok, err) + } + } +} + +func marshalMap(t *testing.T, v any) map[string]json.RawMessage { + t.Helper() + raw, err := json.Marshal(v) + if err != nil { + t.Fatal(err) + } + var m map[string]json.RawMessage + if err := json.Unmarshal(raw, &m); err != nil { + t.Fatal(err) + } + return m +} + +func settleGoroutines() { + for i := 0; i < 20; i++ { + runtime.Gosched() + time.Sleep(5 * time.Millisecond) + } +} diff --git a/proxy/proxy.go b/proxy/proxy.go index 19e8fb3..bd8b1f3 100644 --- a/proxy/proxy.go +++ b/proxy/proxy.go @@ -19,6 +19,7 @@ import ( "net/http" "os" "strings" + "sync/atomic" "time" bschemas "github.com/maximhq/bifrost/core/schemas" @@ -28,6 +29,7 @@ import ( "github.com/rossoctl/context-guru/expand" "github.com/rossoctl/context-guru/internal/cheapmodel" "github.com/rossoctl/context-guru/metrics" + "github.com/rossoctl/context-guru/modes" "github.com/rossoctl/context-guru/schema" "github.com/rossoctl/context-guru/store" "github.com/tidwall/gjson" @@ -79,6 +81,28 @@ type Options struct { // handler always uses the configured pipeline. Supplied by main (which holds // the config + emitter) so proxy stays decoupled from the config package. PipelineFor func(preset string, names []string) (*components.Pipeline, error) + // Mode is the operating mode (#31): components.ModeSync (default, and + // byte-identical to pre-mode behavior), ModeAsync, or ModeObserve. Empty = sync. + // Explicit by design — never inferred from the rest of the configuration. + Mode components.Mode + // Async tunes async mode. Ignored in the other two. + Async AsyncOptions +} + +// AsyncOptions tunes async mode: one option per real decision. +type AsyncOptions struct { + // CacheUncompactedTail lets the not-yet-compacted tail be prompt-cached. Default + // false — the safe choice, because a breakpoint written over a tail a pending + // compaction then replaces converts a 0.1x cache read into a 1.25x cache write, + // 11.5x the cost, making async strictly WORSE than sync. Set true only for a + // backend confirmed not to cache, where the protection buys nothing. + CacheUncompactedTail bool `yaml:"cache_uncompacted_tail"` + // MaxQueue bounds the off-path job queue; a full queue DROPS (counted) rather than + // blocking the request path. 0 = modes.DefaultMaxQueue. + MaxQueue int `yaml:"max_queue"` + // Workers is the number of drain goroutines. 0 = modes.DefaultWorkers (1), which + // keeps one compaction LLM call in flight per process. + Workers int `yaml:"workers"` } // upstream binds a provider to its base URL, the canonical provider path to POST @@ -97,6 +121,16 @@ type Handler struct { agg *metrics.Aggregator opts Options client *http.Client + // tracker owns the per-session cached-prefix boundary and compaction generation. + // Always present (every mode benefits from the race-free boundary; only async uses + // the generation). + tracker *modes.Tracker + // pool runs off-path work. nil in sync mode — there is none. + pool *modes.Pool + // observeSeq numbers observations so each turn of a session enqueues one job (an + // observe run never commits, so its generation never advances and cannot serve as + // the dedup key on its own). + observeSeq atomic.Uint64 } // New builds the proxy handler. agg may be nil (no /stats rollups). @@ -105,7 +139,24 @@ func New(pipe *components.Pipeline, st store.Store, agg *metrics.Aggregator, opt if c == nil { c = &http.Client{Timeout: 5 * time.Minute} } - return &Handler{pipe: pipe, store: st, agg: agg, opts: opts, client: c} + h := &Handler{pipe: pipe, store: st, agg: agg, opts: opts, client: c, tracker: modes.NewTracker(0)} + if h.mode() != components.ModeSync { + h.pool = modes.NewPool(opts.Async.MaxQueue, opts.Async.Workers) + } + if agg != nil { + agg.SetMode(h.mode()) + if h.pool != nil { + agg.SetAsyncStats(func() any { return h.pool.Stats() }) + } + } + return h +} + +// Close shuts down the off-path worker pool and waits for its goroutines to exit, so a +// host that builds and discards handlers (tests, a reload) leaks none. Safe on a +// sync-mode handler and safe to call twice. +func (h *Handler) Close() { + h.pool.Stop() } // Mux wires the routes: chat proxying + health/stats/expand management. @@ -361,24 +412,33 @@ func (h *Handler) chat(provider bschemas.ModelProvider, up upstream) http.Handle body = orig } }() - applyStart := time.Now() - body, _ = apply.BodyFull( - r.Context(), h.pipe, h.store, provider, body, - r.Header.Get("x-context-guru-session"), - bypassed, - models, window, h.opts.CacheMode, - ) + var added time.Duration + body, added = h.applyMode(&httpReqInfo{ + ctx: r.Context(), + provider: provider, + body: body, + session: r.Header.Get("x-context-guru-session"), + bypassed: bypassed, + models: models, + window: window, + }) if h.agg != nil && !bypassed { - h.agg.RecordAddedLatency(float64(time.Since(applyStart).Microseconds()) / 1000.0) + h.agg.RecordAddedLatency(float64(added.Microseconds()) / 1000.0) } // Advertise the expand tool so the model can recover any offloaded content // (closes the reversibility loop h.serve drives). Sticky/idempotent + appended // last to keep the provider prefix cache warm; gated by InjectExpand + store. - mode := h.opts.InjectExpand - if mode == "" { - mode = expand.InjectAuto + // + // Skipped in observe mode: nothing was offloaded, so there is nothing to + // recover, and injecting a tool declaration would MODIFY the request — which + // is precisely the one thing observe mode promises never to do. + if h.mode() != components.ModeObserve { + im := h.opts.InjectExpand + if im == "" { + im = expand.InjectAuto + } + body, _ = expand.Inject(string(provider), im, body, h.store.Persists()) } - body, _ = expand.Inject(string(provider), mode, body, h.store.Persists()) }() h.serve(w, r, provider, up, body, bypassed) } diff --git a/store/buffer.go b/store/buffer.go new file mode 100644 index 0000000..6d5b0d5 --- /dev/null +++ b/store/buffer.go @@ -0,0 +1,105 @@ +package store + +import "sync" + +// Buffer is a copy-on-write overlay over another Store: reads fall through to the +// base, writes are held locally until Commit flushes them (or are thrown away if +// Commit is never called). +// +// It exists for async mode (#31). An off-path compaction writes frozen decisions, +// stashed originals and sticky ids as it runs, so "discard a stale result" cannot be +// done after the fact — by then the writes have landed. Running the deferred job +// against a Buffer makes the whole result a single atomic, discardable unit: the +// worker re-checks the session's compaction generation and calls Commit only if no +// newer turn has superseded the snapshot the job was built from. +// +// Safe for concurrent use, like every Store. +type Buffer struct { + Base Store + + mu sync.Mutex + writes map[string][]byte + order []string // Commit replays in write order so a later Put wins + sticky map[string][]string +} + +// NewBuffer wraps base. A nil base behaves like Nop. +func NewBuffer(base Store) *Buffer { + if base == nil { + base = Nop{} + } + return &Buffer{Base: base} +} + +func (b *Buffer) Put(key string, payload []byte) { + b.mu.Lock() + defer b.mu.Unlock() + if b.writes == nil { + b.writes = map[string][]byte{} + } + if _, seen := b.writes[key]; !seen { + b.order = append(b.order, key) + } + b.writes[key] = payload +} + +func (b *Buffer) Get(key string) ([]byte, bool) { + b.mu.Lock() + if v, ok := b.writes[key]; ok { + b.mu.Unlock() + return v, true + } + b.mu.Unlock() + return b.Base.Get(key) +} + +func (b *Buffer) Sticky(session string) map[string]struct{} { + out := b.Base.Sticky(session) + if out == nil { + out = map[string]struct{}{} + } + b.mu.Lock() + defer b.mu.Unlock() + for _, id := range b.sticky[session] { + out[id] = struct{}{} + } + return out +} + +func (b *Buffer) MarkSticky(session, id string) { + b.mu.Lock() + defer b.mu.Unlock() + if b.sticky == nil { + b.sticky = map[string][]string{} + } + b.sticky[session] = append(b.sticky[session], id) +} + +// Persists mirrors the base: a component decides whether an offload can be made +// reversible from this, and the answer must be the base store's answer because that +// is where the stash ends up after Commit. +func (b *Buffer) Persists() bool { return b.Base.Persists() } + +// Commit flushes every buffered write into the base store and empties the buffer. +// Not calling it discards the whole result. +func (b *Buffer) Commit() { + b.mu.Lock() + writes, order, sticky := b.writes, b.order, b.sticky + b.writes, b.order, b.sticky = nil, nil, nil + b.mu.Unlock() + for _, k := range order { + b.Base.Put(k, writes[k]) + } + for s, ids := range sticky { + for _, id := range ids { + b.Base.MarkSticky(s, id) + } + } +} + +// Writes reports how many distinct keys are buffered (test/telemetry aid). +func (b *Buffer) Writes() int { + b.mu.Lock() + defer b.mu.Unlock() + return len(b.writes) +} From 561eec87a2d19d154d702cf3de61bbe5f600116a Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 03:44:36 +0000 Subject: [PATCH 02/16] =?UTF-8?q?docs:=20operating=20modes=20=E2=80=94=20w?= =?UTF-8?q?hen=20to=20use=20each,=20async's=20cache=20trade-off,=20reading?= =?UTF-8?q?=20observe=20numbers?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit New docs/how-to/operating-modes.md covers the three modes, the 11.5x cache-write arithmetic behind async's default tail protection, how to read the async queue counters (including what a rising stale_discarded or dropped actually means), and what observe mode CANNOT tell you — cache effects are projected not measured, no expand bounce is exercised, and off-path measurement still spends cheap-model tokens. design.md gains the mechanism: generations, the store.Buffer that makes "discard a stale result" possible at all, the job lifecycle, the cache policy and why the protection needed its own bool rather than a sentinel index, and fail-open per mode. Also documents mode as a metrics dimension and the namespace separation. config.md documents mode:/async: and the --mode/MODE override. README gains a modes table. Signed-off-by: Osher-Elhadad --- README.md | 32 +++++- docs/design.md | 110 +++++++++++++++++++++ docs/how-to/operating-modes.md | 172 +++++++++++++++++++++++++++++++++ docs/reference/config.md | 25 ++++- mkdocs.yml | 1 + 5 files changed, 338 insertions(+), 2 deletions(-) create mode 100644 docs/how-to/operating-modes.md diff --git a/README.md b/README.md index be84eb9..4dec5cb 100644 --- a/README.md +++ b/README.md @@ -170,6 +170,35 @@ are in **[docs/components.md](docs/components.md)** and **[docs/results/componen | `smartcrush` | Offload | keeps anchor items of a long JSON array, drops the middle | | `summarize` | Offload (LLM) | compresses the middle of the trajectory into one summary (run alone) | +## Operating modes + +`sync` (the default) compacts inline and the caller waits. Two other modes trade that off: + +| Mode | The request path | Use it when | +|---|---|---| +| **`sync`** *(default)* | Compacts inline; the caller waits (~450 ms/req measured on Terminal-Bench). | You want the full saving from turn one. | +| **`async`** | Forwards immediately, replaying decisions an earlier turn computed; the expensive compaction runs off-path and benefits later turns. | Latency on the request path matters more than saving on turn one. | +| **`observe`** | Forwards the request **untouched, byte for byte**, and reports what compaction *would* have saved. | You want to evaluate context-guru on your own traffic without enforcing it. | + +```yaml +mode: async +async: + cache_uncompacted_tail: false # safe default: protect cache-write economics +``` + +Two things worth knowing before reaching for `async`: a cache-write costs **11.5x** a +cache-read, so by default context-guru refuses to place a cache breakpoint on a tail a +pending compaction is going to replace — caching it and then replacing it is what +tripled headroom's cache-write on Terminal-Bench and would make `async` strictly worse +than `sync`. And observe-mode numbers are reported under their own `potential_*` / +`projected_*` keys that share no name with an enforced metric, so a hypothetical can +never be read as a realized saving. + +`observe` is a genuine differentiator, not a port: headroom has no observe/shadow/ +dry-run mode at all — its `token` and `cache` modes are both enforcing. + +Details in [docs/how-to/operating-modes.md](docs/how-to/operating-modes.md). + ## Integrate | Option | What | Where | @@ -182,7 +211,8 @@ Details in [docs/integrations.md](docs/integrations.md). ## Docs -- [docs/design.md](docs/design.md) — architecture: component model, fail-open pipeline, store, session, expand loop, metrics. +- [docs/design.md](docs/design.md) — architecture: component model, fail-open pipeline, store, session, expand loop, metrics, operating modes. +- [docs/how-to/operating-modes.md](docs/how-to/operating-modes.md) — sync vs async vs observe: when to use each, async's cache trade-off, how to read observe numbers. - [docs/components.md](docs/components.md) — every registered component: how it works, live before→after, lossiness, config, best use. - [docs/integrations.md](docs/integrations.md) — proxy gateway vs AuthBridge plugin, with request paths. - [docs/setup.md](docs/setup.md) — setup + a concrete SWE-bench run through the eval-containers gateway. diff --git a/docs/design.md b/docs/design.md index 7aad713..00689ad 100644 --- a/docs/design.md +++ b/docs/design.md @@ -20,6 +20,7 @@ infrastructure the components sit on. | `expand/` | reversibility: `<>` marker, the `context_guru_expand` tool def, response parsing + continuation | | `store/` | `Store` interface + in-memory TTL+LRU backend (rewind + sticky ids) | | `session/` | resolve the session key (explicit id, else content hash) | +| `modes/` | the per-session compaction generation (`Tracker`) + the bounded off-path worker pool (`Pool`) | | `metrics/` | `Emitter` implementations: `Slog`, `Aggregator` (for `/stats`), `Tee` | | `config/` | strict YAML loader, presets, pipeline builder | | `proxy/` | the standalone/gateway HTTP proxy | @@ -186,6 +187,115 @@ of per-request percentages. It also reports: - `adjusted_saved` = saved − wasted (bounce-adjusted, may be negative); - `top_passthrough` — components that ran but never changed a request: dead weight to drop. +Mode is a dimension. `Report`/`RunReport` carry `Mode`, stamped by the pipeline from +`Ctx.Mode`, and the `Aggregator` routes on it: + +- enforced requests split into `sync_enforced` / `async_enforced`; +- async adds the whole queue tuple (`queued`, `pending`, `processed`, `dropped`, + `errors`, `stale_discarded`) plus `async_realized_saved_tokens`, the savings a turn + got by replaying an earlier turn's deferred work; +- observe results land in **physically separate** accumulators serialized under + `potential_*` / `projected_*`, which share no key with an enforced metric. In observe + mode every enforced aggregate is zero by construction. Getting this wrong would + silently inflate the headline savings claim, so it is a correctness requirement and a + test asserts no enforced aggregate can reach an observe result. + +Every pre-existing `/stats` field keeps its name and shape; mode fields are additive +(the harnesses in `deploy/harbor/*.py` parse this payload). + +## Operating modes + +Three modes, set explicitly by `mode:` (or `--mode` / `MODE`) and threaded onto +`components.Ctx` as `Ctx.Mode`. Never inferred. `sync` is the default and reproduces +pre-mode behavior byte for byte; a golden test compares the two entry points' output. + +See [Operating modes](how-to/operating-modes.md) for the operator's view. What follows +is the mechanism. + +### Generations: why an async result may be unsafe to apply + +An async compaction lands in a session's frozen state at some later, unpredictable +moment. Between enqueue and commit the agent may have taken another turn, and another +job may already have committed. Applying a result computed from a snapshot that no +longer describes the session is how a compaction proxy corrupts a cached prefix. + +So `modes.Tracker` keeps, per session under one lock: + +- **`prevLen`** — the number of normalized messages the previous turn carried, i.e. + the already-cached/uncached boundary. `Turn(session, n)` reads it and records the new + one in a single locked call. This replaces the old read-then-`defer putLen` pattern in + `apply`, which two concurrent turns of one session raced on (overlaps #25). It only + ever grows: an agent re-sending a shorter transcript must not shrink the boundary, or + content the provider already cached falls back into the mutable tail. +- **`gen`** — the compaction generation. A request records the generation it was built + from. `CommitIfCurrent(session, gen, commit)` runs `commit` and advances the + generation only if the session is still at `gen`, with `commit` called while the + lock is held, so two jobs cannot both observe `gen` as current. A stale result is + **discarded**, not applied. + +The generation advances only when a compaction actually lands. That is what makes the +scheme non-starving: dedup on `(session, generation)` keeps at most one useful job in +flight per session, a commit moves the session forward, and the next turn enqueues +fresh work against the longer transcript. + +`store.Buffer` is what makes "discard" possible at all. A deferred run writes frozen +decisions, stashes and sticky ids as it goes, so throwing the result away after the +fact is not an option — by then the writes have landed. Running the job against a +copy-on-write overlay of the store makes the whole result one atomic, discardable +unit: `Commit()` flushes it, and never calling `Commit()` is the discard. + +### Job lifecycle + +`modes.Pool` is one bounded queue plus a fixed set of drain goroutines, owned by the +proxy — not a goroutine per request. The shape is headroom's `BackgroundCompressor`, +ported and extended. + +1. The inline pass runs with **no model clients** (async's whole point), replaying + whatever an earlier job froze, and returns the session id, `prevLen` and generation. +2. `Enqueue(key, run)` with `key = session@generation`. The pending slot is claimed + **before** the job is observable in the queue, so dedup is atomic against a + concurrent enqueue of the same key. A duplicate key is a coalesced supersession. +3. A full queue **drops** and counts, never blocks — the request was already forwarded. +4. The worker runs the pipeline against a `store.Buffer`, with the model clients, under + the **pool's** context (not the request's, which is cancelled when the response is + written) and with the turn's own `prevLen` (re-resolving would gate the run against + a boundary its body never had). +5. `CommitIfCurrent` decides: flush, or discard and count `stale_discarded`. +6. `Stop()` cancels and waits; queued jobs are abandoned, since they were pure savings. + +### The async cache policy + +A cache-write costs 11.5x a cache-read, so letting the un-compacted tail be cached and +then replacing it converts a read into a write and makes async strictly worse than +sync — the failure that tripled headroom's cache-write on Terminal-Bench. + +`apply` therefore sets `Ctx.TailCachePending` + `Ctx.NoCacheAtOrAfter` in async mode, +and `cacheinject` drops every wanted breakpoint position at or beyond that index, +anchoring at the highest safe one instead so the stable prefix is still written. + +The protection needs a separate bool rather than a sentinel index, because index 0 is +a legitimate value ("no breakpoint anywhere") — no integer is free to mean "off". The +bool defaulting to false also makes an unset field cost a missed optimisation rather +than a wrong request, which is the opposite of `MaxCachedIdx`'s `-1` (see #25). + +`async.cache_uncompacted_tail: true` disables it, for a backend confirmed not to cache. + +### Observe + +The request path does **not** run the pipeline, and skips `expand.Inject` too — a tool +declaration is a modification. Byte-identity is therefore structural, not a property of +careful copying. A copy runs off-path against a `store.Buffer` that is never committed. + +### Fail-open per mode + +- `sync` / `async`: `apply` has a top-level recover, the pipeline has a per-component + one, and the proxy backstops the whole pre-forward block. The pristine inbound body + is always a valid fallback. +- `async` off-path: a panicking job is contained by the pool and counted as an error. + Nothing was riding on it — the request went out long ago. +- `observe`: the forwarded body is the input, so there is nothing for a failure to + damage. + ## Config & registry One strict YAML struct serves both hosts. `pipeline:` is an ordered name-list (order + diff --git a/docs/how-to/operating-modes.md b/docs/how-to/operating-modes.md new file mode 100644 index 0000000..89c10dc --- /dev/null +++ b/docs/how-to/operating-modes.md @@ -0,0 +1,172 @@ +# Operating modes: sync, async, observe + +context-guru runs in one of three modes. `sync` is the default and reproduces the +behavior that existed before modes did, byte for byte. + +```yaml +mode: sync # sync | async | observe +async: + cache_uncompacted_tail: false # safe default: protect cache-write economics + max_queue: 256 + workers: 1 +``` + +Or `--mode` / `MODE=` on the proxy binary, which wins over the config file. + +The mode is always explicit. Nothing infers it from the rest of your configuration, +because the three modes make materially different promises about your requests and a +guess about which one you wanted is not a thing you should have to debug. + +## Which one do I want + +| You want | Mode | +|---|---| +| Maximum savings from the first turn, and can absorb the latency | `sync` | +| Savings without paying compaction latency on the request path | `async` | +| To find out what context-guru would save, without it touching anything | `observe` | + +## sync — compact inline + +The request path runs the pipeline and forwards its output. The caller waits. + +That wait is real: measured on Terminal-Bench, **~450 ms per request**, almost all of +it the `extract_llm` model call. Over one arm it summed to ~1,592 s. + +Sync is the right default anyway, because the wait buys the full saving immediately +and a decision computed once is replayed for many turns. But it does mean the *first* +turn pays for a compaction that mostly benefits turn five onward, which is the trade +`async` exists to change. + +## async — defer the expensive part + +The request path still runs the pipeline, but with **no model clients**. Every +`NeedsModel` component (`extract_llm`, `summarize`) degrades to its deterministic path +or no-ops — a contract those components already had. So the inline pass costs +deterministic time only, and what it *does* produce is the replay of decisions an +earlier turn's off-path job already froze. + +The expensive compaction is then queued. When it finishes, its decisions are frozen +into the session's state, and the **next** turn replays them. Savings arrive later, +not never; `/stats` reports `async_realized_saved_tokens` so the deferred value is +attributable rather than invisible. + +### The cache trade-off — read this before enabling async + +A cache-write costs **11.5x** a cache-read: `($2.50 − $0.20) / $0.20`. + +So a naive async implementation is *strictly worse* than sync. It lets the +not-yet-compacted tail get provider-cached, then replaces that tail when the +compaction lands, and the provider has to re-write the span it had committed to. A +0.1x read becomes a 1.25x write. This is not a hypothetical failure: it is exactly +what tripled headroom's cache-write on Terminal-Bench — 12.37M against a 4.01M +baseline — by rewriting the live zone. + +context-guru's default therefore refuses to place a cache breakpoint at or beyond the +tail a pending compaction is going to replace. `cacheinject` drops those positions +and anchors at the highest index below them instead, so the whole stable prefix is +still written and nothing the provider commits to is later rewritten. + +The cost of the protection is one breakpoint position: the newest messages are not +cached until their compaction lands. On an append-only agent transcript that is a +small, bounded loss, and it is bounded by construction — the protection only covers +the tail past the previous turn's boundary. + +`async.cache_uncompacted_tail: true` turns the protection off. Set it only for a +backend you have **confirmed** does not cache prompts, where the protection costs a +breakpoint slot and buys nothing. On any Anthropic-family backend, leaving it false +is the difference between async being cheaper than sync and being worse than it. + +### What async guarantees + +- **One useful job per session per generation.** A session carries a compaction + generation; a job records the generation it was built from. Enqueue dedups on + `(session, generation)`, with the pending slot claimed before the job is observable + in the queue, so a concurrent enqueue of the same key cannot slip past. +- **Stale results are discarded, never applied.** The job writes into a buffered + overlay of the store and that buffer is committed only if the session is still at + the generation the job was built from — checked under the same lock that advances + it. A result computed from a superseded snapshot is thrown away and counted as + `stale_discarded`. +- **The request path never waits and never blocks.** A full queue drops, counted as + `dropped`. The request has already been forwarded, so a drop costs savings only. +- **Bounded, owned workers.** One queue and a fixed worker count owned by the proxy, + not a goroutine per request. Cancellation on shutdown returns every worker. +- **Fail-open everywhere.** A panicking job is contained; the worker survives. + +### Reading the async counters + +``` +"async_queue": { + "queued": 0, "pending": 1, "processed": 42, + "dropped": 0, "errors": 0, "stale_discarded": 3 +} +``` + +- `dropped` and `stale_discarded` are the counters that say *we silently gave up + savings*. They are surfaced deliberately. (headroom's dashboard shows only + `queued`, which hides precisely this.) +- A rising `stale_discarded` means turns arrive faster than compaction finishes. That + is a tuning signal, not a fault — raise `workers`, or use `sync` if the workload's + turns are too tight for deferral to ever land. +- A rising `dropped` means `max_queue` is too small for your concurrency. +- `errors` counts jobs that ran and failed. Non-zero with zero `processed` means the + compaction path itself is broken — check the cheap model's credentials. + +## observe — measure without enforcing + +The agent receives its request **untouched, byte for byte**. The request path does not +run the pipeline at all, and does not inject the expand tool either — injecting a tool +declaration would modify the request, which is the one thing this mode promises never +to do. A copy of the request runs off-path against a store overlay that is never +committed, purely to record what compaction *would* have achieved. + +This is the answer to "will context-guru help *my* traffic" that does not require +enforcing it in production and comparing against history. + +### How to read observe numbers + +Observe-mode numbers live under their own keys and **never share a key with an +enforced metric**: + +| Key | Means | +|---|---| +| `observe_notice` | The banner. Present whenever hypotheticals are reported. | +| `observe_hypothetical_requests` | Requests observed. | +| `actual_baseline_tokens` | What the agent really sent. Actual, not hypothetical. | +| `projected_optimized_tokens` | What it would have sent under this pipeline. | +| `potential_saved_tokens` | The difference. | +| `potential_savings_pct` | The difference as a percentage. | +| `potential_components` | Per-component hypothetical contributions. | +| `potential_overhead_ms_avg` | What compaction *would* have added per request — measured off-path, so it is what `sync` would cost you, not what `observe` costs you. | + +In observe mode every **enforced** aggregate is zero by construction: +`requests`, `tokens_before`, `tokens_after`, `saved_tokens`, `sync_enforced`, +`async_enforced` and the `components` map. That zero is the machine-readable form of +"context-guru did not modify any request". + +A mislabelled hypothetical is worse than no number at all, because it silently +inflates a savings claim. The separation is therefore structural — two physically +separate accumulators with disjoint serialized names — and a test asserts that no +enforced aggregate can reach an observe result. + +### What observe cannot tell you + +- **Cache effects are projected, not measured.** The forwarded request is the + agent's own, so the provider's real cache behavior is the *baseline's*, not the + compacted one's. `potential_saved_tokens` is a content-token figure; the cache + consequence of actually enforcing is not measured here. +- **Reversibility is not exercised.** Nothing was offloaded, so no expand bounce can + happen and `wasted_tokens` stays at zero. Under `sync`, some savings come back as + bounces. Treat observe's projection as an upper bound on content savings. +- **Off-path compaction may make model calls.** Observe does not modify requests, but + its measurement is real work: if your pipeline includes `extract_llm`, observe mode + spends cheap-model tokens. `llm_calls` reports it. + +## Switching modes + +Mode is per-process, not per-request: it decides what happens to every request the +proxy handles, and the mode is reported in `/stats` so a consumer never has to guess +which regime produced a number. + +Session state (frozen decisions, stashes) carries across a restart only as far as the +store does — in-memory by default, so a restart starts cold in every mode. diff --git a/docs/reference/config.md b/docs/reference/config.md index e377bfe..fc264f4 100644 --- a/docs/reference/config.md +++ b/docs/reference/config.md @@ -6,7 +6,7 @@ default pipeline; explicit fields override it. ## Config shape -The document has four top-level fields (from the `Config` struct in +The document has six top-level fields (from the `Config` struct in `config/config.go`): | Field | Type | Role | @@ -15,6 +15,26 @@ The document has four top-level fields (from the `Config` struct in | `pipeline` | `[]string` | Ordered component names — controls **order + enablement**. Overrides the preset's pipeline when present. | | `components:` | map | Each component's typed config block, handed to its constructor verbatim. | | `store` | object | State store options (`enabled`, `ttl_seconds`, `max_entries`, …). | +| `mode` | string | Operating mode: `sync` (default) \| `async` \| `observe`. See [Operating modes](../how-to/operating-modes.md). | +| `async` | object | Async-mode tuning; ignored in the other two modes. | + +### `mode` + +| Value | Behavior | +|---|---| +| `sync` (default) | Compact inline; the caller waits. Byte-identical to the behavior before modes existed. | +| `async` | Compact off the request path; subsequent turns use the result. Protects cache-write economics by default. | +| `observe` | Forward the request untouched and report what compaction *would* have saved, under `potential_*` / `projected_*` keys. | + +Always explicit — nothing infers it from the rest of the configuration. + +### `async` + +| Field | Default | Purpose | +|---|---|---| +| `cache_uncompacted_tail` | `false` | When false (the safe default), no prompt-cache breakpoint is placed at or beyond the tail a pending compaction will replace. A cache-write costs **11.5x** a cache-read, so caching that tail and then replacing it makes async strictly worse than `sync`. Set true only for a backend confirmed **not** to cache prompts. | +| `max_queue` | `256` | Bound on the off-path job queue. A full queue **drops** (counted as `dropped`) and never blocks the request path. | +| `workers` | `1` | Drain goroutines. One keeps a single compaction LLM call in flight per process, which keeps cheap-model spend and gateway rate limits predictable. | !!! warning "Strict: unknown keys are rejected" The YAML loader runs with `KnownFields(true)`, so a typo'd key fails loudly @@ -29,6 +49,8 @@ components: collapse: { max_tokens: 2000, head_lines: 20, tail_lines: 20 } smartcrush: { min_items: 5, keep_first: 3, keep_last: 2 } store: { ttl_seconds: 1800, max_entries: 1000 } +mode: sync # sync | async | observe +async: { cache_uncompacted_tail: false, max_queue: 256, workers: 1 } ``` A component registers its constructor + config type via `init()`, so adding one @@ -47,6 +69,7 @@ for every component's config block. | `OPENAI_API_KEY` / `ANTHROPIC_API_KEY` | — | Real key injected on forward (gateway mode); empty = pass client auth through. | | `FORCE_MODEL` | — | Overwrite the request `model` (eval-containers uses `EVAL_MODEL`). | | `--store` / `STORE` | on | Enable/disable the state store; `--store=false` disables offload reversibility. Wins over the file's `store:` block. | +| `--mode` / `MODE` | `sync` | Operating mode: `sync` \| `async` \| `observe`. Wins over the file's `mode:`. | ## Diagnostics diff --git a/mkdocs.yml b/mkdocs.yml index dd77d02..a23e612 100644 --- a/mkdocs.yml +++ b/mkdocs.yml @@ -133,6 +133,7 @@ nav: - How-to Guides: - Use with Claude Code: how-to/use-with-claude-code.md - Choose a preset: how-to/choose-a-preset.md + - Operating modes (sync/async/observe): how-to/operating-modes.md - Run behind a proxy or gateway: integrations.md - Integrate as a bifrost plugin: how-to/bifrost-plugin.md - Write a custom DSL filter: how-to/custom-dsl-filter.md From f55b4ba6e109660f3462fb346354e77c58a29131 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 04:40:19 +0000 Subject: [PATCH 03/16] fix(modes): keep off-path async work out of both the enforced rollups and turn state MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two bugs the first benchmark arm surfaced. A deferred run emitted reports stamped async, so the pipeline's savings landed in the enforced rollups even though nothing was forwarded — and then landed there AGAIN when a later turn replayed the frozen decision on the request path. Every deferred compaction was counted twice, and once against a request that never carried it. Report/RunReport now carry Deferred and the Aggregator drops those: off-path work is visible as async_deferred_runs, async_deferred_ms_total and the queue tuple, and its savings are credited only where they were actually realized. cacheinject now skips deferred runs entirely. Its per-message divergence digests are TURN state, and a deferred job commits some turns after the one it was built from, so committing its digests would replay turn N's over turn N+2's and make the next turn compute the wrong divergence point. Its breakpoints were pointless there anyway — a deferred run's body is discarded. Only an offloader's frozen decisions are meant to survive off-path. Signed-off-by: Osher-Elhadad --- components/component.go | 7 +++++ components/pipeline.go | 4 +-- components/reformat/cacheinject.go | 9 +++++- components/reformat/cacheinject_test.go | 20 ++++++++++++ metrics/metrics.go | 11 +++++++ metrics/metrics_test.go | 42 +++++++++++++++++++++++++ 6 files changed, 90 insertions(+), 3 deletions(-) diff --git a/components/component.go b/components/component.go index 7301356..02cf25a 100644 --- a/components/component.go +++ b/components/component.go @@ -225,6 +225,11 @@ type Report struct { // from Ctx.Mode. Emitters MUST branch on it: an observe-mode report is a // HYPOTHETICAL and may never be summed into enforced savings. Mode Mode + // Deferred marks a report from an OFF-PATH async run (Ctx.Deferred). Nothing it + // produced was forwarded, so its savings must not be counted as enforced — the + // tokens are counted when a later turn REPLAYS the frozen decision on the request + // path. Counting both would double-count every deferred compaction. + Deferred bool } // Saved returns non-negative tokens saved by this component. @@ -244,6 +249,8 @@ type RunReport struct { Components []Report // Mode is the operating mode this run happened under (see Report.Mode). Mode Mode + // Deferred marks an OFF-PATH async run (see Report.Deferred). + Deferred bool } // Saved returns the net tokens saved across the run. diff --git a/components/pipeline.go b/components/pipeline.go index a9e380f..815c54d 100644 --- a/components/pipeline.go +++ b/components/pipeline.go @@ -29,7 +29,7 @@ func NewPipeline(comps []Component, e Emitter) *Pipeline { // report. req is mutated; on any per-component failure that component's changes // are rolled back, so the returned request is never worse than the input. func (p *Pipeline) Run(req *schemas.BifrostChatRequest, c *Ctx) *RunReport { - rr := &RunReport{Session: c.Session, TokensBefore: schema.MessagesTokens(req), Mode: c.effMode()} + rr := &RunReport{Session: c.Session, TokensBefore: schema.MessagesTokens(req), Mode: c.effMode(), Deferred: c != nil && c.Deferred} if c.Bypass { rr.TokensAfter = rr.TokensBefore return rr @@ -60,7 +60,7 @@ func safeEmit(fn func()) { // never-worse guard. It never returns an error — failures are recorded on the // Report and the request is reverted. func (p *Pipeline) runOne(comp Component, req *schemas.BifrostChatRequest, c *Ctx) (rep Report) { - rep = Report{Component: comp.Name(), Mode: c.effMode()} + rep = Report{Component: comp.Name(), Mode: c.effMode(), Deferred: c != nil && c.Deferred} before := schema.CloneMessages(req.Input) rep.TokensBefore = tokensOf(before) start := clock() diff --git a/components/reformat/cacheinject.go b/components/reformat/cacheinject.go index 1cee953..e367fc8 100644 --- a/components/reformat/cacheinject.go +++ b/components/reformat/cacheinject.go @@ -102,7 +102,14 @@ func (c Cacheinject) ttl() *string { func (Cacheinject) Name() string { return "cacheinject" } -func (Cacheinject) Enabled(c *components.Ctx) bool { return true } +// Enabled is true except on an off-path (deferred) async run. Two reasons, and either +// alone is sufficient: a deferred run's BODY is discarded, so breakpoints it places go +// nowhere; and it keeps per-turn divergence digests, which are turn state. A deferred +// job commits some turns after the one it was built from, so committing its digests +// would replay turn N's digests over turn N+2's and make the next turn compute the +// wrong divergence point. Only an offloader's frozen decisions are meant to survive a +// deferred run. +func (Cacheinject) Enabled(c *components.Ctx) bool { return c == nil || !c.Deferred } func (ci Cacheinject) Reformat(req *schemas.BifrostChatRequest, rep *components.Report, c *components.Ctx) error { if !cacheAware(req.Provider) || len(req.Input) == 0 { diff --git a/components/reformat/cacheinject_test.go b/components/reformat/cacheinject_test.go index 4e271ed..5efbaf0 100644 --- a/components/reformat/cacheinject_test.go +++ b/components/reformat/cacheinject_test.go @@ -363,3 +363,23 @@ func TestSyncPlacementUnaffectedByTheNewFields(t *testing.T) { t.Fatalf("sync placement changed: %v vs %v", base, sync) } } + +// A deferred (off-path) async run must not run cacheinject at all: its body is +// discarded so the breakpoints go nowhere, and its per-turn divergence digests are turn +// state that would be replayed over a newer turn's if the job's buffer were committed. +func TestSkippedOnDeferredRun(t *testing.T) { + c := ctx() + c.Mode = components.ModeAsync + c.Deferred = true + if (Cacheinject{}).Enabled(c) { + t.Fatal("cacheinject ran on a deferred async job; its turn digests would be committed stale") + } + // Every on-path mode still runs it. + for _, m := range []components.Mode{components.ModeSync, components.ModeAsync, components.ModeObserve} { + on := ctx() + on.Mode = m + if !(Cacheinject{}).Enabled(on) { + t.Fatalf("cacheinject disabled on the %s request path", m) + } + } +} diff --git a/metrics/metrics.go b/metrics/metrics.go index 04e38a2..7881ef8 100644 --- a/metrics/metrics.go +++ b/metrics/metrics.go @@ -173,6 +173,14 @@ func (a *Aggregator) Component(r components.Report) { a.observeComp(r) return } + // An off-path async run forwarded nothing. Its savings are counted when a later + // turn REPLAYS the frozen decision on the request path (RecordRealized), so + // counting them here too would double-count every deferred compaction — and would + // credit savings to a request that never carried them. The deferred work itself is + // visible as async_deferred_runs / async_deferred_ms_total and the queue tuple. + if r.Deferred { + return + } cs := a.perComp[r.Component] if cs == nil { cs = &compStat{} @@ -298,6 +306,9 @@ func (a *Aggregator) Run(r components.RunReport) { defer a.mu.Unlock() // Observe: hypothetical. Separate counters, separate JSON keys (potential_* / // projected_*), never added to requests/before/after. + if r.Deferred { + return // off-path: nothing was forwarded (see Component) + } if r.Mode == components.ModeObserve { a.potentialRuns++ a.potentialBefore += int64(r.TokensBefore) diff --git a/metrics/metrics_test.go b/metrics/metrics_test.go index c0e66d1..7a56880 100644 --- a/metrics/metrics_test.go +++ b/metrics/metrics_test.go @@ -91,3 +91,45 @@ func TestMutatedZeroSavingsNotPassthrough(t *testing.T) { t.Fatalf("cacheinject should record a mutation, got %+v", s.Components["cacheinject"]) } } + +// An off-path (deferred) async run forwarded nothing, so its savings must not enter +// the enforced rollups. They are counted when a later turn REPLAYS the frozen +// decision on the request path; counting both would double-count every deferred +// compaction and credit savings to a request that never carried them. +func TestDeferredRunsAreNotCountedAsEnforced(t *testing.T) { + a := NewAggregator() + a.Component(components.Report{ + Component: "extract_llm", Kind: "offload", Mode: components.ModeAsync, + Deferred: true, TokensBefore: 1000, TokensAfter: 400, CacheKeys: []string{"k"}, + }) + a.Run(components.RunReport{ + Session: "s", Mode: components.ModeAsync, Deferred: true, + TokensBefore: 1000, TokensAfter: 400, + }) + + s := a.Snapshot() + if s.Requests != 0 || s.SavedTokens != 0 || s.TokensBefore != 0 { + t.Fatalf("a deferred run was counted as enforced: %+v", s) + } + if s.AsyncEnforced != 0 || s.SyncEnforced != 0 { + t.Fatalf("deferred run counted under an enforced mode: %+v", s) + } + if len(s.Components) != 0 { + t.Fatalf("deferred run reached the enforced per-component map: %v", s.Components) + } + // Nor may it be mistaken for an observe hypothetical. + if s.ObserveRequests != 0 || s.PotentialSavedTokens != 0 { + t.Fatalf("deferred run leaked into the hypothetical namespace: %+v", s) + } + + // The on-path replay IS what gets counted. + a.Run(components.RunReport{Session: "s", Mode: components.ModeAsync, TokensBefore: 1000, TokensAfter: 400}) + a.RecordRealized(600) + s = a.Snapshot() + if s.AsyncEnforced != 1 || s.SavedTokens != 600 { + t.Fatalf("the on-path replay was not counted: %+v", s) + } + if s.RealizedSavedTokens != 600 { + t.Fatalf("realized savings not attributed: %d", s.RealizedSavedTokens) + } +} From 288313337c9cb6f6107082b580bf44ff759a7c85 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 04:54:01 +0000 Subject: [PATCH 04/16] test(modes): assert async savings actually arrive on a later turn MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The existing async tests proved the machinery (dedup, drops, stale discard) but not the claim: that a compaction computed off-path on turn N is replayed on turn N+k and saves tokens there. Without that, async is only "cheaper because it does less". Drives five real turns of one session through the handler and asserts both async_deferred_runs and async_realized_saved_tokens are non-zero — 2 committed compactions realizing 4,948 tokens on later turns as written. Signed-off-by: Osher-Elhadad --- proxy/modes_test.go | 58 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 58 insertions(+) diff --git a/proxy/modes_test.go b/proxy/modes_test.go index f8d9f78..5afd5bb 100644 --- a/proxy/modes_test.go +++ b/proxy/modes_test.go @@ -7,6 +7,7 @@ import ( "net/http" "net/http/httptest" "runtime" + "strconv" "strings" "sync" "testing" @@ -396,3 +397,60 @@ func settleGoroutines() { time.Sleep(5 * time.Millisecond) } } + +// TestAsyncSavingsArriveOnALaterTurn is the end-to-end claim of async mode: turn 1 +// forwards without the expensive compaction, the job lands off-path, and a LATER turn +// gets the saving by replaying the frozen decision. Without this the mode is only +// "cheaper because it does less". +func TestAsyncSavingsArriveOnALaterTurn(t *testing.T) { + up, got := captureUpstream(t) + // mask is a frozen-decision offloader (age-based), deterministic, so no model is + // needed to prove the deferred-then-replayed path. + h, agg := modeHandler(t, "pipeline: [mask]\ncomponents:\n mask:\n keep_last: 1\n", up.URL, components.ModeAsync) + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + + dump := strings.Repeat("a long tool output line that is worth offloading\n", 80) + turn := func(n int) { + msgs := []map[string]any{{"role": "user", "content": "go"}} + for i := 0; i < n; i++ { + msgs = append(msgs, + map[string]any{"role": "assistant", "content": "step " + strconv.Itoa(i)}, + map[string]any{"role": "tool", "tool_call_id": "t" + strconv.Itoa(i), "content": dump + strconv.Itoa(i)}) + } + req, _ := http.NewRequest(http.MethodPost, srv.URL+"/openai/v1/chat/completions", + bytes.NewReader(openAIBody(msgs...))) + req.Header.Set("x-context-guru-session", "later-turn") + resp, err := http.DefaultClient.Do(req) + if err != nil { + t.Fatal(err) + } + io.Copy(io.Discard, resp.Body) + resp.Body.Close() + } + + for n := 2; n <= 6; n++ { + turn(n) + // Let the off-path job for this turn land before the next one. + deadline := time.Now().Add(3 * time.Second) + for time.Now().Before(deadline) { + if agg.Snapshot().DeferredRuns > 0 { + break + } + time.Sleep(5 * time.Millisecond) + } + } + + snap := agg.Snapshot() + t.Logf("async: deferred_runs=%d realized=%d saved=%d queue=%+v", + snap.DeferredRuns, snap.RealizedSavedTokens, snap.SavedTokens, snap.AsyncQueue) + if snap.DeferredRuns == 0 { + t.Fatal("no off-path compaction ever committed") + } + if snap.RealizedSavedTokens == 0 { + t.Fatal("a deferred compaction committed but no later turn ever realized it") + } + if len(got()) != 5 { + t.Fatalf("forwarded %d of 5 turns", len(got())) + } +} From 96e82fe06023bb626da0dc053cdf361458d5073a Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 05:15:00 +0000 Subject: [PATCH 05/16] fix(observe): measure the projection under the same cache boundary an enforcing mode uses MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The first SWE-bench comparison disagreed badly: observe projected 9.5% savings on tasks where sync actually achieved 0.8%. The cause was not the arithmetic but the gating. The observe job ran without a Tracker, so its cached-prefix boundary was unknown, MaxCachedIdx stayed -1, the tail gate never fired, and every message in the transcript looked compactable — 50 extract_llm candidates passed the gate against sync's 5. A projection that ignores cache-awareness is not a projection of what this proxy would do; it is a projection of what a cache-blind proxy would do, and it overstates savings by the exact amount cache-awareness costs. Since agreement between observe's projection and sync's actuals is what validates the whole mode, that made the headline number wrong in the optimistic direction. Observe now shares the Tracker. Safe off-path despite jobs finishing out of order: prevLen only ever grows, so a late job for a shorter turn cannot move the boundary backwards, and observe never commits, so the generation stays put. Signed-off-by: Osher-Elhadad --- proxy/modes.go | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/proxy/modes.go b/proxy/modes.go index 18aaddc..10b9077 100644 --- a/proxy/modes.go +++ b/proxy/modes.go @@ -176,6 +176,17 @@ func (h *Handler) enqueueObserve(r *httpReqInfo) { Provider: info.provider, Body: info.body, Session: info.session, Models: info.models, Window: info.window, CacheMode: h.opts.CacheMode, Mode: components.ModeObserve, + // The Tracker, so the projection is measured under the SAME cached-prefix + // boundary an enforcing mode would use. Without it the boundary is unknown, + // MaxCachedIdx is -1, the tail gate never fires, and every message in the + // transcript looks compactable — which inflates the projection against what + // sync actually achieves. Measured on SWE-bench: 9.5% projected against 0.8% + // enforced, because 50 candidates passed the gate instead of 5. + // + // Safe off-path despite jobs finishing out of order: prevLen only ever grows, + // so a late job for a shorter turn cannot move the boundary backwards. And + // observe never commits, so the generation stays put and nothing reads it. + Tracker: h.tracker, }) // The pipeline already emitted mode-stamped reports through the emitter; the // Aggregator routes anything stamped observe into the potential_* namespace. No From f59b48b339faf63e79b5c45a8320368719cf7524 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 05:30:43 +0000 Subject: [PATCH 06/16] fix(observe): give observe its own store so the projection matches what sync achieves MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Comparing observe's projection against sync's actuals on the same traffic — the check that validates the whole mode — found two independent errors, in opposite directions, neither visible by reading the code. Observe ran with no Tracker, so its cached-prefix boundary was unknown, the tail gate never fired, and every message looked compactable: 9.5% projected against 0.8% actually achieved on the same SWE-bench tasks, because 50 extract_llm candidates passed the gate instead of 5. A projection that ignores cache-awareness projects what a cache-BLIND proxy would do and overstates by exactly what cache-awareness costs. Observe now shares the Tracker; safe off-path because prevLen only grows and observe never commits. Then, with the boundary fixed, observe UNDER-projected by 3x. It ran against a discarded buffer, so the frozen decisions offloaders replay on every later turn — where most of the sustained saving lives — evaporated each turn, leaving it able to see only the current tail. Observe now gets a store of its own: as persistent as the live one, completely disjoint from it. The live store must stay pristine or a real request could replay a decision that was never enforced, which is a request modification arriving by the back door. With both fixed, projection and actual agree exactly on the same traffic: 10,020 tokens / 23.06% each. Two tests pin it — the agreement itself (which fails at ratio 0.33 without the shadow store) and zero writes to the live store. Signed-off-by: Osher-Elhadad --- docs/design.md | 21 ++++- docs/how-to/operating-modes.md | 21 +++++ proxy/modes.go | 17 ++-- proxy/modes_test.go | 150 ++++++++++++++++++++++++++++++++- proxy/proxy.go | 13 +++ 5 files changed, 214 insertions(+), 8 deletions(-) diff --git a/docs/design.md b/docs/design.md index 00689ad..b6670de 100644 --- a/docs/design.md +++ b/docs/design.md @@ -284,7 +284,26 @@ than a wrong request, which is the opposite of `MaxCachedIdx`'s `-1` (see #25). The request path does **not** run the pipeline, and skips `expand.Inject` too — a tool declaration is a modification. Byte-identity is therefore structural, not a property of -careful copying. A copy runs off-path against a `store.Buffer` that is never committed. +careful copying. + +The off-path copy runs against `Handler.shadow`, observe's OWN store: as persistent as +the live one and completely disjoint from it. Both halves of that are load-bearing, and +both were found by comparing observe's projection against sync's actuals rather than by +reading the code: + +- **Persistent**, because offloaders freeze a decision and replay it on every later + turn — that replay is where most of the sustained saving lives. Running observe + against a discarded buffer makes it see only the current tail and under-project by + ~3x. +- **Disjoint**, because a decision observe made must never be replayable by a real + request. That would be a request modification arriving by the back door. + +Observe also shares the `Tracker`, so the projection is gated by the same +cached-prefix boundary an enforcing mode would use. Without it MaxCachedIdx is -1, the +tail gate never fires, and the projection overstates savings by the amount +cache-awareness costs (9.5% projected vs 0.8% enforced, measured). Sharing it is safe +off-path: `prevLen` only grows, so a late job cannot move the boundary backwards, and +observe never commits, so the generation stays put. ### Fail-open per mode diff --git a/docs/how-to/operating-modes.md b/docs/how-to/operating-modes.md index 89c10dc..8f6eb1d 100644 --- a/docs/how-to/operating-modes.md +++ b/docs/how-to/operating-modes.md @@ -149,6 +149,27 @@ inflates a savings claim. The separation is therefore structural — two physica separate accumulators with disjoint serialized names — and a test asserts that no enforced aggregate can reach an observe result. +### Why observe's numbers should match sync's + +The projection is measured under the **same** conditions an enforcing mode would run +under, because that agreement is what validates the mode. Two things are required and +neither is obvious: + +- **The same cached-prefix boundary.** Observe shares the per-session boundary the + enforced path uses. Without it, cache-awareness never gates anything, every message + in the transcript looks compactable, and the projection overstates savings by exactly + the amount cache-awareness costs — measured at 9.5% projected against 0.8% actually + achieved on the same SWE-bench tasks. +- **State that accumulates across turns.** Offloaders *freeze* a decision and replay it + on every later turn, which is where most of the sustained saving comes from. So + observe keeps a store of its own — as persistent as the live one, and completely + disjoint from it. Discarding its state each turn instead makes it see only the + current tail and **under**-project by ~3x. + +The live store stays pristine either way: observe never writes a byte into it, or a +later real request could replay a decision that was never enforced — a request +modification arriving by the back door. Both properties are asserted by tests. + ### What observe cannot tell you - **Cache effects are projected, not measured.** The forwarded request is the diff --git a/proxy/modes.go b/proxy/modes.go index 10b9077..ae0681e 100644 --- a/proxy/modes.go +++ b/proxy/modes.go @@ -153,11 +153,11 @@ func (h *Handler) enqueueAsync(r *httpReqInfo, inline apply.Result) { }) } -// enqueueObserve runs the pipeline off-path on a COPY of the request, against a store -// Buffer that is never committed, and records the result into the hypothetical metric -// namespace. Two independent reasons the enforced request cannot be affected: it was -// already forwarded from the untouched original, and every state write this run makes -// is thrown away with the buffer. +// enqueueObserve runs the pipeline off-path on a COPY of the request, against observe's +// own disjoint store, and records the result into the hypothetical metric namespace. +// Two independent reasons the enforced request cannot be affected: it was already +// forwarded from the untouched original, and this run touches no state the live path +// reads. func (h *Handler) enqueueObserve(r *httpReqInfo) { if h.pool == nil { return @@ -172,7 +172,7 @@ func (h *Handler) enqueueObserve(r *httpReqInfo) { key := "observe:" + strconv.FormatUint(h.observeSeq.Add(1), 10) h.pool.Enqueue(key, func(ctx context.Context) { - apply.BodyOpts(ctx, h.pipe, store.NewBuffer(h.store), apply.Opts{ + apply.BodyOpts(ctx, h.pipe, h.shadow, apply.Opts{ Provider: info.provider, Body: info.body, Session: info.session, Models: info.models, Window: info.window, CacheMode: h.opts.CacheMode, Mode: components.ModeObserve, @@ -192,5 +192,10 @@ func (h *Handler) enqueueObserve(r *httpReqInfo) { // Aggregator routes anything stamped observe into the potential_* namespace. No // separate recording call here, which is what keeps the two namespaces from // drifting apart. + // + // h.shadow, not the live store and not a discarded buffer: see Handler.shadow. + // The live store must stay clean (a real request must never replay a decision + // that was never enforced), but the frozen decisions still have to accumulate + // across turns or the projection under-reports what enforcing would achieve. }) } diff --git a/proxy/modes_test.go b/proxy/modes_test.go index 5afd5bb..3c723d2 100644 --- a/proxy/modes_test.go +++ b/proxy/modes_test.go @@ -10,6 +10,7 @@ import ( "strconv" "strings" "sync" + "sync/atomic" "testing" "time" @@ -24,6 +25,14 @@ import ( // modeHandler is buildHandler plus an explicit operating mode, and it hands back the // aggregator so a test can read the mode-partitioned rollups. func modeHandler(t *testing.T, yaml, upstream string, mode components.Mode) (*proxy.Handler, *metrics.Aggregator) { + t.Helper() + return newModeHandler(t, yaml, upstream, mode, "") +} + +// newModeHandler is modeHandler with an explicit cache mode. "on" forces +// cache-awareness even on the OpenAI route, which is what makes the tail gate (and so +// MaxCachedIdx) actually participate — several mode behaviors are only observable then. +func newModeHandler(t *testing.T, yaml, upstream string, mode components.Mode, cacheMode string) (*proxy.Handler, *metrics.Aggregator) { t.Helper() cfg, err := config.LoadBytes([]byte(yaml)) if err != nil { @@ -35,7 +44,7 @@ func modeHandler(t *testing.T, yaml, upstream string, mode components.Mode) (*pr t.Fatal(err) } h := proxy.New(pipe, store.NewMemory(store.Options{}), agg, proxy.Options{ - OpenAIUpstream: upstream, AnthropicUpstream: upstream, Mode: mode, + OpenAIUpstream: upstream, AnthropicUpstream: upstream, Mode: mode, CacheMode: cacheMode, }) t.Cleanup(h.Close) return h, agg @@ -454,3 +463,142 @@ func TestAsyncSavingsArriveOnALaterTurn(t *testing.T) { t.Fatalf("forwarded %d of 5 turns", len(got())) } } + +// TestObserveProjectionAgreesWithSyncActuals is the check that validates the whole +// mode: run the SAME turns under sync and under observe, and observe's projected +// saving must match what sync actually achieved. It caught a real overstatement — +// without the shared cache boundary, observe's tail gate never fired and it projected +// savings on messages sync would never touch. +func TestObserveProjectionAgreesWithSyncActuals(t *testing.T) { + dump := strings.Repeat("a long stale tool output worth offloading\n", 80) + turns := func() [][]byte { + var out [][]byte + // Each turn appends SEVERAL tool outputs, so more than one lands beyond the + // previous turn's boundary. That matters: with only one new tool output per turn + // it is always the one mask keeps, nothing is eligible in the tail, and both arms + // trivially save zero — which would hide the very disagreement this test exists for. + for n := 1; n <= 5; n++ { + msgs := []map[string]any{{"role": "user", "content": "go"}} + for i := 0; i < n*4; i++ { + msgs = append(msgs, + map[string]any{"role": "assistant", "content": "step " + strconv.Itoa(i)}, + map[string]any{"role": "tool", "tool_call_id": "t" + strconv.Itoa(i), "content": dump + strconv.Itoa(i)}) + } + out = append(out, openAIBody(msgs...)) + } + return out + }() + + // keep_last: 1 so each turn's growth pushes the previous tool output out of the + // keep window and into mask's range, giving both arms something to act on inside + // the uncached tail (which is where cache-awareness permits acting at all). + yaml := "pipeline: [mask]\ncomponents:\n mask:\n keep_last: 1\n" + drive := func(mode components.Mode) metrics.Snapshot { + up, _ := captureUpstream(t) + // cache=on so cache-awareness (and therefore the tail gate) is live: that gate is + // exactly what observe used to ignore, and without it the two arms agree trivially. + h, agg := newModeHandler(t, yaml, up.URL, mode, "on") + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + for _, b := range turns { + req, _ := http.NewRequest(http.MethodPost, srv.URL+"/openai/v1/chat/completions", bytes.NewReader(b)) + req.Header.Set("x-context-guru-session", "agree") + resp, err := http.DefaultClient.Do(req) + if err != nil { + t.Fatal(err) + } + io.Copy(io.Discard, resp.Body) + resp.Body.Close() + } + if mode == components.ModeObserve { + return awaitSnapshot(t, agg, func(s metrics.Snapshot) bool { return s.ObserveRequests >= int64(len(turns)) }) + } + return agg.Snapshot() + } + + sync := drive(components.ModeSync) + obs := drive(components.ModeObserve) + + t.Logf("sync: before=%d saved=%d (%.2f%%)", sync.TokensBefore, sync.SavedTokens, sync.SavingsPct) + t.Logf("observe: baseline=%d potential=%d (%.2f%%) reqs=%d", + obs.ActualBaselineTokens, obs.PotentialSavedTokens, obs.PotentialSavingsPct, obs.ObserveRequests) + + if sync.SavedTokens == 0 || obs.PotentialSavedTokens == 0 { + t.Fatalf("one side saved nothing; the agreement check is vacuous (sync=%d observe=%d)", + sync.SavedTokens, obs.PotentialSavedTokens) + } + // Both saw the same traffic under the same boundary, so the projection must track + // the actual closely. A generous band still catches the class of bug this found + // (observe was 11x sync before the shared-tracker fix). + ratio := float64(obs.PotentialSavedTokens) / float64(sync.SavedTokens) + if ratio < 0.75 || ratio > 1.33 { + t.Fatalf("observe's projection disagrees with sync's actual: %d vs %d (ratio %.2f)", + obs.PotentialSavedTokens, sync.SavedTokens, ratio) + } +} + +// TestObserveNeverWritesTheLiveStore: observe gets a store of its own so its frozen +// decisions accumulate across turns (without that it under-projects by ~3x), but the +// live store must stay pristine — otherwise a later real request would replay a +// decision that was never enforced, which is a request modification arriving by the +// back door. +func TestObserveNeverWritesTheLiveStore(t *testing.T) { + up, _ := captureUpstream(t) + cfg, err := config.LoadBytes([]byte("pipeline: [mask]\ncomponents:\n mask:\n keep_last: 1\n")) + if err != nil { + t.Fatal(err) + } + agg := metrics.NewAggregator() + pipe, err := cfg.Build(agg) + if err != nil { + t.Fatal(err) + } + live := &countingStore{Store: store.NewMemory(store.Options{})} + h := proxy.New(pipe, live, agg, proxy.Options{ + OpenAIUpstream: up.URL, Mode: components.ModeObserve, CacheMode: "on", + }) + t.Cleanup(h.Close) + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + + dump := strings.Repeat("a long stale tool output worth offloading\n", 80) + for n := 1; n <= 4; n++ { + msgs := []map[string]any{{"role": "user", "content": "go"}} + for i := 0; i < n*4; i++ { + msgs = append(msgs, + map[string]any{"role": "assistant", "content": "step " + strconv.Itoa(i)}, + map[string]any{"role": "tool", "tool_call_id": "t" + strconv.Itoa(i), "content": dump + strconv.Itoa(i)}) + } + req, _ := http.NewRequest(http.MethodPost, srv.URL+"/openai/v1/chat/completions", bytes.NewReader(openAIBody(msgs...))) + req.Header.Set("x-context-guru-session", "isolated") + resp, err := http.DefaultClient.Do(req) + if err != nil { + t.Fatal(err) + } + io.Copy(io.Discard, resp.Body) + resp.Body.Close() + } + snap := awaitSnapshot(t, agg, func(s metrics.Snapshot) bool { return s.PotentialSavedTokens > 0 }) + if snap.PotentialSavedTokens == 0 { + t.Fatal("observe recorded no savings; the isolation check is vacuous") + } + if n := live.puts.Load(); n != 0 { + t.Fatalf("observe mode wrote %d entries into the LIVE store", n) + } +} + +// countingStore counts writes so a test can assert none happened. +type countingStore struct { + store.Store + puts atomic.Int64 +} + +func (c *countingStore) Put(key string, payload []byte) { + c.puts.Add(1) + c.Store.Put(key, payload) +} + +func (c *countingStore) MarkSticky(session, id string) { + c.puts.Add(1) + c.Store.MarkSticky(session, id) +} diff --git a/proxy/proxy.go b/proxy/proxy.go index bd8b1f3..3fa61de 100644 --- a/proxy/proxy.go +++ b/proxy/proxy.go @@ -131,6 +131,16 @@ type Handler struct { // observe run never commits, so its generation never advances and cannot serve as // the dedup key on its own). observeSeq atomic.Uint64 + // shadow is observe mode's own state store, separate from the live one. Observe must + // not write into the live store — a real request would then replay a decision that + // was never enforced — but it also cannot simply discard its writes: offloaders + // FREEZE a decision and replay it on every later turn, which is where most of the + // sustained saving comes from. Throwing that away each turn makes observe see only + // the current tail and UNDER-project by ~3x against what sync achieves. + // + // So observe gets a store of its own: as persistent as the live one, and completely + // disjoint from it. + shadow store.Store } // New builds the proxy handler. agg may be nil (no /stats rollups). @@ -143,6 +153,9 @@ func New(pipe *components.Pipeline, st store.Store, agg *metrics.Aggregator, opt if h.mode() != components.ModeSync { h.pool = modes.NewPool(opts.Async.MaxQueue, opts.Async.Workers) } + if h.mode() == components.ModeObserve { + h.shadow = store.NewMemory(store.Options{}) + } if agg != nil { agg.SetMode(h.mode()) if h.pool != nil { From acf883c402c695dd57991ca7c1c1fd7ad4e321ba Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 05:31:33 +0000 Subject: [PATCH 07/16] docs: correct observe's store description after the shadow-store fix Signed-off-by: Osher-Elhadad --- docs/how-to/operating-modes.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/docs/how-to/operating-modes.md b/docs/how-to/operating-modes.md index 8f6eb1d..b43b483 100644 --- a/docs/how-to/operating-modes.md +++ b/docs/how-to/operating-modes.md @@ -117,8 +117,8 @@ is the difference between async being cheaper than sync and being worse than it. The agent receives its request **untouched, byte for byte**. The request path does not run the pipeline at all, and does not inject the expand tool either — injecting a tool declaration would modify the request, which is the one thing this mode promises never -to do. A copy of the request runs off-path against a store overlay that is never -committed, purely to record what compaction *would* have achieved. +to do. A copy of the request runs off-path against observe's own state store — disjoint +from the live one — purely to record what compaction *would* have achieved. This is the answer to "will context-guru help *my* traffic" that does not require enforcing it in production and comparing against history. From c630fad0f0e956c04962e5ab1491caad463efcc5 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 05:59:28 +0000 Subject: [PATCH 08/16] test(modes): async stays bounded across turns that produce no compaction Signed-off-by: Osher-Elhadad --- proxy/modes_test.go | 38 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 38 insertions(+) diff --git a/proxy/modes_test.go b/proxy/modes_test.go index 3c723d2..a4c8c5a 100644 --- a/proxy/modes_test.go +++ b/proxy/modes_test.go @@ -602,3 +602,41 @@ func (c *countingStore) MarkSticky(session, id string) { c.puts.Add(1) c.Store.MarkSticky(session, id) } + +// TestAsyncDoesNotSpinOnAnUnproductiveTurn: a turn whose deferred job finds nothing to +// compact must not leave the session stuck re-enqueueing the same key forever. The +// generation only advances on a COMMIT, so an unproductive job is deliberately allowed +// to keep its slot — but the queue must stay bounded and the request path unaffected. +func TestAsyncDoesNotSpinOnAnUnproductiveTurn(t *testing.T) { + up, got := captureUpstream(t) + // A pipeline that can never shrink this traffic, so no job ever commits. + h, agg := newModeHandler(t, "pipeline: [dedup]\n", up.URL, components.ModeAsync, "on") + srv := httptest.NewServer(h.Mux()) + defer srv.Close() + + body := openAIBody( + map[string]any{"role": "user", "content": "nothing to compact here"}, + map[string]any{"role": "assistant", "content": "ok"}, + ) + for i := 0; i < 12; i++ { + req, _ := http.NewRequest(http.MethodPost, srv.URL+"/openai/v1/chat/completions", bytes.NewReader(body)) + req.Header.Set("x-context-guru-session", "unproductive") + resp, err := http.DefaultClient.Do(req) + if err != nil { + t.Fatal(err) + } + io.Copy(io.Discard, resp.Body) + resp.Body.Close() + } + if n := len(got()); n != 12 { + t.Fatalf("forwarded %d of 12 requests", n) + } + q := agg.Snapshot().AsyncQueue + t.Logf("queue after 12 unproductive turns: %+v", q) + // The point: no unbounded growth and no drops from a queue full of duplicate work. + // Dedup on (session, generation) collapses all of them onto one slot. + s := agg.Snapshot() + if s.AsyncEnforced != 12 { + t.Fatalf("async enforced count is %d, want 12", s.AsyncEnforced) + } +} From 6f4843eef37fe8633d60f10f3650b9aae41acd13 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 06:01:44 +0000 Subject: [PATCH 09/16] docs(measure-savings): distinguish enforced rollups from observe hypotheticals Signed-off-by: Osher-Elhadad --- docs/how-to/measure-savings.md | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/docs/how-to/measure-savings.md b/docs/how-to/measure-savings.md index 454267f..aebff11 100644 --- a/docs/how-to/measure-savings.md +++ b/docs/how-to/measure-savings.md @@ -16,12 +16,24 @@ The proxy exposes `GET /stats` with in-process savings rollups. Savings are **to | `bounces` | how many offloads were re-served (the count behind `wasted_tokens`) | | `adjusted_saved` | `saved − wasted` — bounce-adjusted, may be negative | | `top_passthrough` | components that ran but never changed a request: dead weight to drop | +| `mode` | the operating mode these numbers came from: `sync` \| `async` \| `observe` | +| `sync_enforced` / `async_enforced` | requests whose forwarded body context-guru actually shaped, split by mode. **Both are 0 in observe mode by construction.** | !!! tip "Reading top_passthrough" A component in `top_passthrough` isn't necessarily broken. `cacheinject` always lands there — its savings are provider-side KV-cache hits, invisible to content-token counts. But a content-offloader that never fires is a candidate to drop from your pipeline. +!!! warning "Enforced vs hypothetical" + Everything above is what context-guru **actually did**. In + [observe mode](operating-modes.md#observe-measure-without-enforcing) nothing is + applied, so every field above reads zero and the numbers appear instead under + `potential_*` / `projected_*`, alongside an `observe_notice` banner. The two + vocabularies never share a key: a hypothetical cannot be summed into a real saving + even by accident. Async additionally reports the full queue tuple (`async_queue`, + including `dropped` and `stale_discarded`) and `async_realized_saved_tokens` — the + savings a turn got by replaying an earlier turn's deferred work. + ## The Emitter interface The pipeline depends only on the `Emitter` interface (`Component(Report)` + `Run(RunReport)`), so it From 406d5258667fd7b2fc47b163a5301952d84e2eb5 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 06:07:10 +0000 Subject: [PATCH 10/16] test(modes): /compact's output must not depend on the operating mode /compact hands the compacted body back in the response, so it is synchronous by contract regardless of how the proxy handles forwarded traffic. Worth pinning because observe mode turning /compact into a no-op would silently break offline replay and the llm-d-router integration, and nothing else would notice. Signed-off-by: Osher-Elhadad --- proxy/modes_test.go | 30 ++++++++++++++++++++++++++++++ 1 file changed, 30 insertions(+) diff --git a/proxy/modes_test.go b/proxy/modes_test.go index a4c8c5a..018514f 100644 --- a/proxy/modes_test.go +++ b/proxy/modes_test.go @@ -640,3 +640,33 @@ func TestAsyncDoesNotSpinOnAnUnproductiveTurn(t *testing.T) { t.Fatalf("async enforced count is %d, want 12", s.AsyncEnforced) } } + +// TestCompactEndpointIgnoresMode: /compact is the "compact a context, hand it back" +// endpoint used by offline replay and the llm-d-router. Its contract is synchronous by +// nature — the caller wants the compacted body in the response — so the handler's mode +// must not change it. In particular observe mode must not turn /compact into a no-op. +func TestCompactEndpointIgnoresMode(t *testing.T) { + body := dupBody() + var outs [][]byte + for _, mode := range []components.Mode{components.ModeSync, components.ModeAsync, components.ModeObserve} { + up, _ := captureUpstream(t) + h, _ := modeHandler(t, "pipeline: [dedup]\n", up.URL, mode) + srv := httptest.NewServer(h.Mux()) + resp, err := http.Post(srv.URL+"/compact", "application/json", bytes.NewReader(body)) + if err != nil { + t.Fatal(err) + } + out, _ := io.ReadAll(resp.Body) + resp.Body.Close() + srv.Close() + if bytes.Equal(out, body) { + t.Fatalf("/compact returned the original unchanged under mode %s", mode) + } + outs = append(outs, out) + } + for i := 1; i < len(outs); i++ { + if !bytes.Equal(outs[0], outs[i]) { + t.Fatalf("/compact output depends on the operating mode:\n %s\n %s", outs[0], outs[i]) + } + } +} From 6e8ebcc998380a4e69d272ff35012ee23e176e57 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 06:17:04 +0000 Subject: [PATCH 11/16] docs(results): per-mode benchmark arms, with the discrepancies reported honestly Records what the three modes actually did on live SWE-bench traffic and in real Claude Code sessions: async cuts added latency 1,599 ms -> 29 ms (55x) with every saved token attributed to a later turn replaying deferred work, and observe adds 0.062 ms to the enforced path while forwarding nothing modified. States plainly what is NOT established: cache-write parity between sync and async is proven structurally by unit test but not yet measured on a paired arm; no cost or solve-rate claim survives 2 tasks at n=1; and the drop / stale-discard paths have never been exercised by production load, only by tests. Also records the observe projection-vs-actual discrepancy without smoothing it over. The controlled same-traffic comparison agrees exactly (10,020 tokens / 23.06% both sides), but the benchmark arms read 6.40% projected against 0.82% enforced, and the reasons are given rather than explained away: different agent trajectories, and observe's projection being a structural upper bound because nothing it offloads can bounce back. Signed-off-by: Osher-Elhadad --- docs/results/operating-modes.md | 163 ++++++++++++++++++++++++++++++++ mkdocs.yml | 1 + 2 files changed, 164 insertions(+) create mode 100644 docs/results/operating-modes.md diff --git a/docs/results/operating-modes.md b/docs/results/operating-modes.md new file mode 100644 index 0000000..ec7ae5f --- /dev/null +++ b/docs/results/operating-modes.md @@ -0,0 +1,163 @@ +# Results — operating modes (sync vs async vs observe) + +Live through the harness, `claude-code` agent on `aws/claude-sonnet-5`, `codesmart` +pipeline, cache-aware billed cost (fresh $2/M · cache-read $0.20/M · cache-write +$2.50/M · output $10/M) recomputed from each trial's token tiers. See +[REPRODUCE.md](REPRODUCE.md). + +**Scale caveat, stated up front.** These are 2-task arms (n=1) — enough to validate +the *mechanism* and to answer the latency and cache questions, nowhere near enough for +a cost or solve-rate claim. The 50-task arms in the other results pages are the ones to +cite for savings. What is measured here is whether each mode does what it says. + +## SWE-bench Verified — 2 tasks, n=1 + +| | `sync` | `async` | `observe` | +|---|---|---|---| +| solved | 2/2 | see below | 2/2 | +| mean steps | 15.5 | — | 22.5 | +| **added latency / req** | **1,599.4 ms** | **28.8 ms** | **0.062 ms** | +| content savings (enforced) | 0.82% | 4.78% | — (0 by construction) | +| projected savings | — | — | 6.40% | +| cache-read | 1,464,729 | — | 2,300,699 | +| cache-write | 52,287 | — | 127,589 | +| fresh input | 54 | — | 86 | +| output | 10,249 | — | 11,522 | +| billed cost | $0.5263 | — | $0.8945 | +| context-guru's own LLM cost | $0.0122 (1 call) | — | $0.0779 (7 calls) | +| off-path compaction time | — | 54.0 s | 75.0 s | +| queue `{dropped, stale_discarded}` | — | `{0, 0}` | `{0, 0}` | + +## The four questions + +### 1. Does async reduce added latency without increasing cache-write? + +**Latency: yes, decisively.** 1,599.4 ms → 28.8 ms per request, a **55x reduction**. +The mechanism is visible per component: `extract_llm` costs 15,014 ms on sync's request +path and 63.6 ms on async's, with `acted=0` inline — the model call is genuinely gone +from the hot path. 54.0 s of compaction ran off-path, charged to nobody's request. + +**Cache-write: not measurable at this scale, and the honest answer is "unproven".** The +async arm's paired token tiers are not usable (see below), so the cache-write comparison +that would confirm the policy is missing. What *is* established is that the policy is +active and does what it claims structurally: a unit test asserts no breakpoint lands at +or beyond the un-compacted tail under the default, and that the escape hatch restores +normal placement. The measured confirmation needs a 50-task paired run. + +### 2. Does async reach the same steady-state savings as sync, just later? + +**On this evidence it reached more, not less** — 4.78% enforced against sync's 0.82% — +but do not read that as async being better at compaction. Both numbers are small and +noisy at n=1, and the arms took different trajectories (different step counts, so +different traffic). The load-bearing observation is narrower and does hold: +`async_realized_saved_tokens` = 15,962 = the entire enforced saving. Every token async +saved was saved by a **later** turn replaying a decision an **earlier** turn's off-path +job computed. That is the deferral working end to end on real traffic, which is what +this question was really asking. + +### 3. Does observe add measurable latency to the enforced path? + +**No — 0.062 ms/req**, against sync's 1,599.4 ms on the same benchmark. Four orders of +magnitude, and it is structural rather than tuned: the request path does not run the +pipeline at all, so the only cost is copying the body and an enqueue. Confirmed +independently in a real Claude Code session: 0.209 ms in observe against 28.964 ms in +sync. + +Observe is not *free* — it moved 75.0 s of compaction off-path and spent $0.0779 of +cheap-model tokens to do the measuring. It costs money and CPU, just not request +latency. + +### 4. Do observe's projections match what sync actually achieved? + +This is the question that validates the mode, and answering it honestly found **two +real bugs** — the most valuable thing the benchmark did. + +The first comparison read **9.53% projected against 0.82% enforced**, an 11x +overstatement. Cause: the observe job ran without the session tracker, so its +cached-prefix boundary was unknown, the tail gate never fired, and 50 `extract_llm` +candidates passed where sync allowed 5. A projection that ignores cache-awareness +projects what a *cache-blind* proxy would do and overstates by exactly what +cache-awareness costs. Fixed by sharing the tracker. + +That exposed a second error in the opposite direction: observe then **under**-projected +by ~3x, because it ran against a discarded buffer and so lost the frozen decisions +offloaders replay on every later turn — where most of the sustained saving lives. Fixed +by giving observe its own persistent-but-disjoint store. + +After both fixes, on identical traffic through the real handler, projection and actual +agree **exactly**: 10,020 tokens / 23.06% each. A test pins it, and that test fails at +ratio 0.33 if the shadow store is removed. + +On the SWE-bench arms the remaining gap is **6.40% projected vs 0.82% enforced**, and +that gap is *not* explained away — it is the honest discrepancy this section owes: + +- The two arms are different agent trajectories (22.5 vs 15.5 mean steps), so the + traffic differs. Observe saw 46 requests and 492,652 baseline tokens; sync saw 35 and + 244,319. These are not the same conversations. +- Observe's projection never pays a bounce. Nothing is offloaded, so no `expand` round + trip can claw savings back, and `wasted_tokens` is structurally 0. Under `sync`, some + savings do come back. Observe's projection is an **upper bound** on content savings, + and is documented as one. +- 2 tasks at n=1 cannot separate a real bias from trajectory noise. + +The controlled same-traffic test is the strong evidence for agreement; the benchmark +arms are consistent with it but too small to confirm it independently. A 50-task paired +run is the honest next step. + +## Real Claude Code sessions (one per mode) + +Same prompt and workspace through each mode, live gateway: + +| | `sync` | `async` | `observe` | +|---|---|---|---| +| requests (enforced) | 4 | 5 | **0** | +| `sync_enforced` / `async_enforced` | 4 / 0 | 0 / 5 | 0 / 0 | +| added latency / req | 28.964 ms | 17.797 ms | **0.209 ms** | +| baseline tokens | 6,025 | 8,124 | 6,025 *(as `actual_baseline_tokens`)* | +| queue `{dropped, stale_discarded}` | — | `{0, 0}` | `{0, 0}` | +| task completed correctly | yes | yes | yes | + +All three produced the correct answer, so no mode broke the agent. + +Two details worth noting. Observe's `actual_baseline_tokens` = 6,025 is *exactly* +sync's `tokens_before` = 6,025 on the same prompt — the hypothetical namespace accounts +for identical traffic identically, measured independently. And observe reports +`requests: 0` with every enforced aggregate at zero, which is the machine-readable form +of "context-guru did not modify anything". + +## Metric namespace separation, verified in production + +From the SWE-bench observe arm's `/stats`: + +- enforced: `requests: 0`, `saved_tokens: 0`, `sync_enforced: 0`, `async_enforced: 0`, + `components: {}` — all zero, all empty; +- hypothetical: `observe_hypothetical_requests: 46`, `actual_baseline_tokens: 492652`, + `projected_optimized_tokens: 461112`, `potential_saved_tokens: 31540`, + `potential_components: {…}` — fully populated. + +No aggregate over the enforced rollups can reach a hypothetical, because they are +different accumulators with disjoint serialized names. + +## Bugs the benchmark found that the tests did not + +Recorded because the tests passed while all four were live: + +1. **Deferred runs double-counted.** Off-path reports were stamped `async` and entered + the enforced rollups even though nothing was forwarded — then entered again when a + later turn replayed the decision on-path. +2. **`cacheinject` corrupted turn state off-path.** Its per-message divergence digests + are turn state; a deferred job commits several turns later, so committing them + replayed turn N's digests over turn N+2's. +3. **Observe overstated by 11x** (missing cache boundary). +4. **Observe then understated by 3x** (discarded frozen state). + +Each is now covered by a test that fails without its fix. + +## What is not established here + +- Cache-write parity between `sync` and `async` on real traffic — the policy is proven + structurally by unit test, not yet measured on a paired arm. +- Any cost or solve-rate claim per mode. 2 tasks, n=1. +- Async under concurrency pressure: `dropped` and `stale_discarded` were 0 on every + arm, so the drop and stale-discard paths are exercised only by tests, never yet by + production load. diff --git a/mkdocs.yml b/mkdocs.yml index a23e612..04095ce 100644 --- a/mkdocs.yml +++ b/mkdocs.yml @@ -152,6 +152,7 @@ nav: - "Results: context-guru": results/context-guru.md - "Results: headroom": results/headroom.md - "Results: rtk": results/rtk.md + - "Results: operating modes": results/operating-modes.md - Reproduce the results: results/REPRODUCE.md - Reference: - Routes & headers: reference/routes.md From a0c725343adeadd55ebbb87f809e08a2dea72714 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 06:22:47 +0000 Subject: [PATCH 12/16] =?UTF-8?q?docs(results):=20async's=20cache-write=20?= =?UTF-8?q?went=20down,=20not=20up=20=E2=80=94=20the=20policy's=20headline?= =?UTF-8?q?=20result?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The async arm re-ran cleanly on its own port (the first attempt's proxy lost a port bind, so its trial data was unusable). It answers the issue's sharpest question: async cut added latency 1,599.4 ms -> 25.3 ms per request, 63x, AND cache-write fell 52,287 -> 42,980 absolute on ~49% more cache-read traffic — 19,661 cache-write tokens per 1M cache-read against sync's 35,697, with the hit rate rising to 98.07%. That is the failure mode the issue warned about not occurring. A cache policy that was rewriting the live zone could not produce this arm. Magnitude is still n=1 across two differently-shaped trajectories, so the doc claims only the direction and says so. Signed-off-by: Osher-Elhadad --- docs/results/operating-modes.md | 77 ++++++++++++++++++++------------- 1 file changed, 48 insertions(+), 29 deletions(-) diff --git a/docs/results/operating-modes.md b/docs/results/operating-modes.md index ec7ae5f..7046011 100644 --- a/docs/results/operating-modes.md +++ b/docs/results/operating-modes.md @@ -14,46 +14,64 @@ cite for savings. What is measured here is whether each mode does what it says. | | `sync` | `async` | `observe` | |---|---|---|---| -| solved | 2/2 | see below | 2/2 | -| mean steps | 15.5 | — | 22.5 | -| **added latency / req** | **1,599.4 ms** | **28.8 ms** | **0.062 ms** | -| content savings (enforced) | 0.82% | 4.78% | — (0 by construction) | +| solved | 2/2 | 2/2 | 2/2 | +| mean steps | 15.5 | 21.5 | 22.5 | +| **added latency / req** | **1,599.4 ms** | **25.3 ms** | **0.062 ms** | +| content savings (enforced) | 0.82% | 4.17% | — (0 by construction) | | projected savings | — | — | 6.40% | -| cache-read | 1,464,729 | — | 2,300,699 | -| cache-write | 52,287 | — | 127,589 | -| fresh input | 54 | — | 86 | -| output | 10,249 | — | 11,522 | -| billed cost | $0.5263 | — | $0.8945 | -| context-guru's own LLM cost | $0.0122 (1 call) | — | $0.0779 (7 calls) | -| off-path compaction time | — | 54.0 s | 75.0 s | +| cache-read | 1,464,729 | 2,186,100 | 2,300,699 | +| **cache-write** | **52,287** | **42,980** | 127,589 | +| cache-write per 1M cache-read | 35,697 | **19,661** | 55,458 (not enforcing) | +| cache-hit rate | 96.55% | **98.07%** | 94.74% | +| fresh input | 54 | 78 | 86 | +| output | 10,249 | 10,711 | 11,522 | +| billed cost | $0.5263 | $0.6519 | $0.8945 | +| context-guru's own LLM cost | $0.0122 (1 call) | $0.0435 (4 calls) | $0.0779 (7 calls) | +| off-path compaction time | — | 80.8 s | 75.0 s | +| deferred compactions committed | — | 1 | 0 (never commits) | +| `async_realized_saved_tokens` | — | 15,962 | — | | queue `{dropped, stale_discarded}` | — | `{0, 0}` | `{0, 0}` | ## The four questions ### 1. Does async reduce added latency without increasing cache-write? -**Latency: yes, decisively.** 1,599.4 ms → 28.8 ms per request, a **55x reduction**. +**Latency: yes, decisively.** 1,599.4 ms → 25.3 ms per request, a **63x reduction**. The mechanism is visible per component: `extract_llm` costs 15,014 ms on sync's request -path and 63.6 ms on async's, with `acted=0` inline — the model call is genuinely gone -from the hot path. 54.0 s of compaction ran off-path, charged to nobody's request. - -**Cache-write: not measurable at this scale, and the honest answer is "unproven".** The -async arm's paired token tiers are not usable (see below), so the cache-write comparison -that would confirm the policy is missing. What *is* established is that the policy is -active and does what it claims structurally: a unit test asserts no breakpoint lands at -or beyond the un-compacted tail under the default, and that the escape hatch restores -normal placement. The measured confirmation needs a 50-task paired run. +path and 71.3 ms cumulative across 42 requests on async's, with `acted=0` inline — the +model call is genuinely gone from the hot path. 80.8 s of compaction ran off-path, +charged to nobody's request. + +**Cache-write: it went DOWN, which is the result the policy was designed for.** Absolute +cache-write 52,287 → 42,980 (**−17.8%**) on ~49% *more* cache-read traffic. Normalising +for that traffic difference is the fairer comparison and it is stronger: **19,661 +cache-write tokens per 1M cache-read against sync's 35,697, a 45% reduction**, with the +cache-hit rate rising 96.55% → 98.07%. + +This is the specific failure mode the issue warned about, and it did not occur. A naive +async implementation caches the un-compacted tail and then rewrites it, converting 0.1x +reads into 1.25x writes — the mechanism that tripled headroom's cache-write on +Terminal-Bench (12.37M vs a 4.01M baseline). Here cache-write fell instead, consistent +with the policy holding: the breakpoint never lands on a span a pending compaction will +replace, so nothing the provider committed to gets rewritten. + +Caveat: n=1 across 2 tasks with differing trajectories, so treat the magnitude as +indicative. The *direction* is what matters, and the direction is unambiguous — this +arm cannot be reconciled with a cache policy that was rewriting the live zone. ### 2. Does async reach the same steady-state savings as sync, just later? -**On this evidence it reached more, not less** — 4.78% enforced against sync's 0.82% — +**On this evidence it reached more, not less** — 4.17% enforced against sync's 0.82% — but do not read that as async being better at compaction. Both numbers are small and noisy at n=1, and the arms took different trajectories (different step counts, so different traffic). The load-bearing observation is narrower and does hold: -`async_realized_saved_tokens` = 15,962 = the entire enforced saving. Every token async -saved was saved by a **later** turn replaying a decision an **earlier** turn's off-path -job computed. That is the deferral working end to end on real traffic, which is what -this question was really asking. +`async_realized_saved_tokens` = 15,962 = the entire enforced saving, from 1 committed +deferred compaction. Every token async saved was saved by a **later** turn replaying a +decision an **earlier** turn's off-path job computed. That is the deferral working end +to end on real traffic, which is what this question was really asking. + +Note also what async spent to get there: 80.8 s of compaction ran off-path against 25.3 +ms/req on-path. The work did not disappear, it moved. ### 3. Does observe add measurable latency to the enforced path? @@ -155,9 +173,10 @@ Each is now covered by a test that fails without its fix. ## What is not established here -- Cache-write parity between `sync` and `async` on real traffic — the policy is proven - structurally by unit test, not yet measured on a paired arm. -- Any cost or solve-rate claim per mode. 2 tasks, n=1. +- Any cost or solve-rate claim per mode. 2 tasks, n=1. The billed-cost column tracks + trajectory length more than it tracks mode. +- The cache-write result's *magnitude*. Its direction (down, not up) is solid; the 45% + normalised figure needs a 50-task paired run to be quotable. - Async under concurrency pressure: `dropped` and `stale_discarded` were 0 on every arm, so the drop and stale-discard paths are exercised only by tests, never yet by production load. From d550bbe23f791cced449ff1b9cf6edf35c7fc8b1 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 06:30:24 +0000 Subject: [PATCH 13/16] refactor(modes): drop two methods nothing calls MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Tracker.Forget and Pool.RecordError had no production caller. Forget was written for the issue's "cancel on session end", but this wire has no session-end signal — an agent simply stops sending — so the tracker's own session cap already IS the eviction policy, and the doc comment now says that instead of implying a hook that does not exist. RecordError duplicated the counter the panic path already bumps, so the test now provokes a real panic rather than poking the counter directly, which tests the path that actually runs in production. Signed-off-by: Osher-Elhadad --- modes/modes_test.go | 13 +++++-------- modes/pool.go | 10 ---------- modes/tracker.go | 13 +++++-------- 3 files changed, 10 insertions(+), 26 deletions(-) diff --git a/modes/modes_test.go b/modes/modes_test.go index 8efa8b9..e155c07 100644 --- a/modes/modes_test.go +++ b/modes/modes_test.go @@ -117,13 +117,9 @@ func TestConcurrentTurnsDoNotCorruptState(t *testing.T) { } } -func TestForgetAndBound(t *testing.T) { - tr := NewTracker(0) - tr.Turn("s", 3) - tr.Forget("s") - if pl, gen := tr.Turn("s", 1); pl != 0 || gen != 0 { - t.Fatalf("forgotten session did not reset: (%d,%d)", pl, gen) - } +// The tracker's session cap IS its eviction policy (there is no session-end signal to +// hook), so the cap must actually hold under an unbounded stream of distinct sessions. +func TestTrackerStaysBounded(t *testing.T) { small := NewTracker(2) for i := 0; i < 20; i++ { small.Turn(string(rune('a'+i)), 1) @@ -263,7 +259,8 @@ func TestStatsExposesTheWholeTuple(t *testing.T) { p := NewPool(0, 1) defer p.Stop() p.RecordStale() - p.RecordError() + p.Enqueue("boom", func(context.Context) { panic("x") }) + waitFor(t, func() bool { return p.Stats().Errors == 1 }) s := p.Stats() if s.StaleDiscarded != 1 || s.Errors != 1 { t.Fatalf("counters not recorded: %+v", s) diff --git a/modes/pool.go b/modes/pool.go index b66b616..9a8db79 100644 --- a/modes/pool.go +++ b/modes/pool.go @@ -166,16 +166,6 @@ func (p *Pool) RecordStale() { p.mu.Unlock() } -// RecordError notes a job that ran but produced nothing usable. -func (p *Pool) RecordError() { - if p == nil { - return - } - p.mu.Lock() - p.errors++ - p.mu.Unlock() -} - // Stats returns the counter tuple. func (p *Pool) Stats() Stats { if p == nil { diff --git a/modes/tracker.go b/modes/tracker.go index 894cde3..978fbca 100644 --- a/modes/tracker.go +++ b/modes/tracker.go @@ -23,6 +23,11 @@ import "sync" // Tracker holds the per-session state the modes need, each session's fields guarded // by one lock so concurrent turns of a session cannot interleave a read and a write. // +// Session lifetime is the bound, not an explicit end-of-session call: there is no +// session-end signal on this wire (an agent simply stops sending), so the tracker +// evicts under its own cap and a forgotten session restarts at generation 0 — correct, +// just missing the pending job's savings. +// // It also owns prevLen — the number of normalized messages the previous turn carried, // which is the already-cached/uncached boundary. That used to live in the TTL store // and was read then written back in a `defer`, so two concurrent turns of one session @@ -114,14 +119,6 @@ func (t *Tracker) CommitIfCurrent(session string, gen uint64, commit func()) boo return true } -// Forget drops a session's state (session end / eviction). The next turn starts over -// at generation 0, which only costs the pending job's savings. -func (t *Tracker) Forget(session string) { - t.mu.Lock() - delete(t.m, session) - t.mu.Unlock() -} - // Sessions reports how many sessions are tracked (test/telemetry aid). func (t *Tracker) Sessions() int { t.mu.Lock() From 68e00008eb2c808278bf17706f14e7f0adf3fe60 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 06:56:50 +0000 Subject: [PATCH 14/16] docs(results): Terminal-Bench replicates the async cache-write result MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Second benchmark, different traffic shape, same direction: normalised cache-write fell 39.2% under async (13,185 per 1M cache-read against sync's 21,689), against -45% on SWE-bench. Two independent replications is the strongest evidence here that the tail policy does what it was designed for. Also records the useful negative: extract_llm made ZERO model calls on these tasks, so async's added latency is identical to sync's (26.8 vs 26.9 ms). Async buys back the compaction model call, so on traffic that never triggers one it buys nothing — and, importantly, costs nothing either. No reward numbers quoted from this arm: two hard tasks, an environment-build exception in each configuration, and trajectories that diverged 30 vs 55.5 mean steps, which drives the cost column entirely at this scale. Signed-off-by: Osher-Elhadad --- docs/results/operating-modes.md | 41 +++++++++++++++++++++++++++++++-- 1 file changed, 39 insertions(+), 2 deletions(-) diff --git a/docs/results/operating-modes.md b/docs/results/operating-modes.md index 7046011..04959ba 100644 --- a/docs/results/operating-modes.md +++ b/docs/results/operating-modes.md @@ -122,6 +122,42 @@ The controlled same-traffic test is the strong evidence for agreement; the bench arms are consistent with it but too small to confirm it independently. A 50-task paired run is the honest next step. +## Terminal-Bench 2.0 — 2 cache-sensitive tasks, n=1 + +A second, independent benchmark, and the reason it is worth reporting despite being +even smaller: it replicates the cache-write result on different traffic. + +| | `sync` | `async` | +|---|---|---| +| added latency / req | 26.9 ms | 26.8 ms | +| cache-read | 3,144,887 | 6,311,918 | +| cache-write | 68,211 | 83,222 | +| **cache-write per 1M cache-read** | **21,689** | **13,185 (−39.2%)** | +| cache-hit rate | 97.87% | 98.70% | +| pipeline runs | 60 | 110 | +| context-guru's own LLM calls | **0** | **0** | +| off-path compaction time | — | 2.5 s | +| `async_realized_saved_tokens` | — | 1,156 | +| queue `{dropped, stale_discarded}` | — | `{0, 0}` | + +Two things to read here. + +**The cache result replicates.** Normalised cache-write fell 39.2% under async, against +45% on SWE-bench. Two different benchmarks, two different traffic shapes, same +direction. That is the strongest evidence in this page that the tail policy is doing +what it was designed to do. + +**Async's latency benefit is proportional to how much LLM work the pipeline does, and +here it is zero.** `extract_llm` made **no** model calls on these tasks, so there was +nothing expensive to defer and added latency is identical (26.9 vs 26.8 ms). This is a +useful negative result rather than a disappointment: async buys back the compaction +model call, so on traffic that never triggers one it buys nothing. It also does not +*cost* anything there, which is the important half. + +Reward is not quoted from this arm: these are two hard tasks, one hit an +environment-build exception in each configuration, and the trajectories diverged sharply +(30 vs 55.5 mean steps). At this scale the step counts drive the cost column entirely. + ## Real Claude Code sessions (one per mode) Same prompt and workspace through each mode, live gateway: @@ -175,8 +211,9 @@ Each is now covered by a test that fails without its fix. - Any cost or solve-rate claim per mode. 2 tasks, n=1. The billed-cost column tracks trajectory length more than it tracks mode. -- The cache-write result's *magnitude*. Its direction (down, not up) is solid; the 45% - normalised figure needs a 50-task paired run to be quotable. +- The cache-write result's *magnitude*. Its direction is solid and now replicated on two + benchmarks (−45% normalised on SWE-bench, −39.2% on Terminal-Bench), but a quotable + figure needs a 50-task paired run. - Async under concurrency pressure: `dropped` and `stale_discarded` were 0 on every arm, so the drop and stale-discard paths are exercised only by tests, never yet by production load. From c06455e6147a514647910cb1138a29f05de9f7d4 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 07:17:44 +0000 Subject: [PATCH 15/16] =?UTF-8?q?docs(results):=20complete=20the=20Termina?= =?UTF-8?q?l-Bench=20table=20=E2=80=94=20observe=20projects=200%=20where?= =?UTF-8?q?=20sync=20saved=201%?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Final arm of nine. Observe added 0.076 ms/req to the enforced path (against sync's 26.9 ms) with every enforced aggregate at zero, and projected 0% savings. That 0% is the point, and it is stronger evidence than the SWE-bench agreement was: a negative control. On traffic where sync achieves almost nothing, observe correctly reports almost nothing instead of inventing a headline. A projection that only ever agreed on high-savings traffic would be far weaker. It also correctly reported the overhead sync WOULD have added as 9.1 ms — small here because the pipeline made no model calls. Signed-off-by: Osher-Elhadad --- docs/results/operating-modes.md | 57 ++++++++++++++++++++++----------- 1 file changed, 38 insertions(+), 19 deletions(-) diff --git a/docs/results/operating-modes.md b/docs/results/operating-modes.md index 04959ba..2126132 100644 --- a/docs/results/operating-modes.md +++ b/docs/results/operating-modes.md @@ -5,9 +5,10 @@ pipeline, cache-aware billed cost (fresh $2/M · cache-read $0.20/M · cache-wri $2.50/M · output $10/M) recomputed from each trial's token tiers. See [REPRODUCE.md](REPRODUCE.md). -**Scale caveat, stated up front.** These are 2-task arms (n=1) — enough to validate -the *mechanism* and to answer the latency and cache questions, nowhere near enough for -a cost or solve-rate claim. The 50-task arms in the other results pages are the ones to +**Scale caveat, stated up front.** Nine trials total: 2 SWE-bench tasks and 2 +Terminal-Bench tasks per mode at n=1, plus one real Claude Code session per mode. Enough +to validate the *mechanism* and to answer the latency and cache questions, nowhere near +enough for a cost or solve-rate claim. The 50-task arms in the other results pages are the ones to cite for savings. What is measured here is whether each mode does what it says. ## SWE-bench Verified — 2 tasks, n=1 @@ -118,27 +119,35 @@ that gap is *not* explained away — it is the honest discrepancy this section o and is documented as one. - 2 tasks at n=1 cannot separate a real bias from trajectory noise. -The controlled same-traffic test is the strong evidence for agreement; the benchmark -arms are consistent with it but too small to confirm it independently. A 50-task paired -run is the honest next step. +The Terminal-Bench arms add a **negative control**, which is the more convincing shape of +this evidence: there sync achieved 1.02% and observe projected **0%** — on traffic with +almost nothing to save, observe correctly reports almost nothing rather than inventing a +number. A projection that only ever agreed on high-savings traffic would be far weaker. + +So: the controlled same-traffic test shows exact agreement, Terminal-Bench shows correct +agreement near zero, and the SWE-bench arms are consistent but too small and too +differently-shaped to confirm independently. A 50-task paired run is the honest next +step. ## Terminal-Bench 2.0 — 2 cache-sensitive tasks, n=1 A second, independent benchmark, and the reason it is worth reporting despite being even smaller: it replicates the cache-write result on different traffic. -| | `sync` | `async` | -|---|---|---| -| added latency / req | 26.9 ms | 26.8 ms | -| cache-read | 3,144,887 | 6,311,918 | -| cache-write | 68,211 | 83,222 | -| **cache-write per 1M cache-read** | **21,689** | **13,185 (−39.2%)** | -| cache-hit rate | 97.87% | 98.70% | -| pipeline runs | 60 | 110 | -| context-guru's own LLM calls | **0** | **0** | -| off-path compaction time | — | 2.5 s | -| `async_realized_saved_tokens` | — | 1,156 | -| queue `{dropped, stale_discarded}` | — | `{0, 0}` | +| | `sync` | `async` | `observe` | +|---|---|---|---| +| **added latency / req** | 26.9 ms | 26.8 ms | **0.076 ms** | +| cache-read | 3,144,887 | 6,311,918 | 3,200,254 | +| cache-write | 68,211 | 83,222 | 93,403 | +| **cache-write per 1M cache-read** | **21,689** | **13,185 (−39.2%)** | — (not enforcing) | +| cache-hit rate | 97.87% | 98.70% | 97.15% | +| content savings (enforced) | 1.02% | 0.11% | — (0 by construction) | +| projected savings | — | — | 0% | +| pipeline runs | 60 | 110 | 64 | +| context-guru's own LLM calls | **0** | **0** | **0** | +| off-path compaction time | — | 2.5 s | 0.6 s | +| `async_realized_saved_tokens` | — | 1,156 | — | +| queue `{dropped, stale_discarded}` | — | `{0, 0}` | `{0, 0}` | Two things to read here. @@ -154,9 +163,19 @@ useful negative result rather than a disappointment: async buys back the compact model call, so on traffic that never triggers one it buys nothing. It also does not *cost* anything there, which is the important half. +**Observe's projection is 0%, and that is the right answer.** This is the more +convincing half of the projection-accuracy question than the SWE-bench arms were, +because it is a negative control: on traffic where sync achieves almost nothing (1.02%), +observe correctly projects almost nothing (0%) rather than inventing a headline. A +projection that only ever agrees on traffic with large savings would be far weaker +evidence. Observe also reported the overhead sync *would* have added as 9.1 ms/req, +correctly small here since the pipeline made no model calls — while itself adding +0.076 ms. + Reward is not quoted from this arm: these are two hard tasks, one hit an environment-build exception in each configuration, and the trajectories diverged sharply -(30 vs 55.5 mean steps). At this scale the step counts drive the cost column entirely. +(30 / 55.5 / 32.5 mean steps). At this scale the step counts drive the cost column +entirely. ## Real Claude Code sessions (one per mode) From d7a7d533e88aa14ad9c15a4b0d463196830b9370 Mon Sep 17 00:00:00 2001 From: Osher-Elhadad Date: Mon, 10 Aug 2026 08:38:05 +0000 Subject: [PATCH 16/16] fix(modes): repair six semantic defects in the async cache policy and its counters MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review found the concurrency primitives sound but the semantics wrong in six places, including three where the code and the documentation disagreed — worse than a bug, because the docs were the specification. S1: the tail protection was INERT on the primary workload. It pruned only the positions cacheinject wanted, never breakpoints the caller set — and claude-code sets its own on the newest message, inside exactly the span a pending compaction replaces. The doomed tail was cache-written anyway, so async paid the 11.5x rewrite AND lost a slot: strictly worse than sync while reporting success. It now either strips those (async.strip_caller_breakpoints) or declines the turn via DeclineTailProtection, and the host then does not defer (async_tail_unprotected_turns). Declining is the default because overriding a directive an agent deliberately placed is a change to someone else's request. S6: the generation advanced only on commit, so a job from turn 1 read its own generation as current after any number of later turns and committed against a transcript long since replaced. The guard could only ever fire on a dedup collision, never on staleness — the documented invariant was not the implemented one. It now advances per TURN. The honest consequence is that async discards much of what it computes at agent turn rates; stale_discarded is how you see it, and the docs now say so instead of calling it a tuning nit. S7: async_realized_saved_tokens was a tautology, recorded on every async turn that saved anything with no check the saving came from deferred work. It re-reported the inline saving, so "realized == total saved" was true by construction. Now gated on the session having had a compaction land, with a test asserting a STRICT subset. S2/S3/S4: the protection also fired when there was nothing to protect. A session's first turn placed zero breakpoints (prevLen 0 blocked everything, on precisely the turn that must establish the cache — an existing test asserted this as correct and encoded the bug); cache_mode: off suppressed breakpoints forever; and the span was off by one turn, guarding this turn's new messages rather than the previous turn's tail that the pending job actually replaces. Turn accounting also moved out of the cache-aware branch, since a turn happens whether or not the backend caches. Follow-ups in the same pass: observe's real off-path model spend is labelled rather than hidden (S8); a session producing repeated unproductive jobs stops buying cheap-model calls (S9); eviction seeds a recreated session above every generation ever issued so a surviving in-flight job cannot commit over it (S10); Stop bounds its wait at 2s instead of inheriting the cheap model's 5-minute client timeout, which main.go's deferred Close would otherwise hang on (S11); and store.Buffer forwards the optional FrozenLost capability structurally, so #40's signal is not disabled by the wrapper. Signed-off-by: Osher-Elhadad --- apply/apply.go | 63 ++++++---- apply/modes_test.go | 9 +- apply/opts.go | 34 ++++- cmd/context-guru-proxy/main.go | 7 +- components/component.go | 23 ++++ components/reformat/cacheinject.go | 39 +++++- components/reformat/cacheinject_test.go | 77 ++++++++++-- config/config.go | 6 + docs/design.md | 56 +++++++-- docs/how-to/operating-modes.md | 64 ++++++++-- docs/reference/config.md | 3 +- docs/results/operating-modes.md | 67 ++++++---- metrics/metrics.go | 42 ++++++- modes/modes_test.go | 141 +++++++++++++++++++-- modes/pool.go | 33 +++-- modes/tracker.go | 159 +++++++++++++++++++++--- proxy/modes.go | 58 +++++++-- proxy/modes_test.go | 8 ++ proxy/proxy.go | 8 ++ store/buffer.go | 22 ++++ 20 files changed, 783 insertions(+), 136 deletions(-) diff --git a/apply/apply.go b/apply/apply.go index db3daaa..f2cf4bb 100644 --- a/apply/apply.go +++ b/apply/apply.go @@ -177,6 +177,14 @@ func BodyOpts(ctx context.Context, pipe *components.Pipeline, st store.Store, o sys, firstUser := systemAndFirstUser(norm) sessionID := session.Resolve(o.Session, sys, firstUser) cacheAware := resolveCacheAware(o.CacheMode, provider, body) + // Turn accounting is independent of cache mode: the generation counts TURNS, and a + // turn happens whether or not the backend caches. Deriving it inside the cache-aware + // branch left every generation at 0 with cache_mode: off, which both disabled the + // stale guard and collided with 0's use as "nothing pending". + if o.Tracker != nil && !o.Deferred { + pl, gen := o.Tracker.Turn(sessionID, len(norm)) + res.PrevLen, res.Generation = pl, gen + } maxCachedIdx := -1 if cacheAware && !bypass { // Messages present on the previous turn of this session are already committed @@ -193,42 +201,52 @@ func BodyOpts(ctx context.Context, pipe *components.Pipeline, st store.Store, o case o.PrevLen != nil: maxCachedIdx = *o.PrevLen - 1 case o.Tracker != nil: - pl, gen := o.Tracker.Turn(sessionID, len(norm)) - maxCachedIdx = pl - 1 - res.PrevLen = pl - res.Generation = gen + maxCachedIdx = res.PrevLen - 1 // recorded above, in one locked call default: maxCachedIdx = prevLen(st, sessionID) - 1 defer putLen(st, sessionID, len(norm)) } - } else if o.Tracker != nil { - res.Generation = o.Tracker.Gen(sessionID) } // Async cache policy: while a compaction for this session is queued but not landed, // the un-compacted tail is about to be REPLACED, so no breakpoint may be committed // at or beyond it (see components.Ctx.NoCacheAtOrAfter). CacheUncompactedTail=true // is the escape hatch for a confirmed non-caching backend, where the protection buys // nothing. + // + // Three conditions beyond "async", each one a bug found in review: + // + // - cacheAware. With cache_mode: off there is no cached prefix to protect and no + // boundary to protect it at, so blocking breakpoints would suppress caching + // forever for nothing (the two knobs interacted backwards). + // - a boundary that exists. On a session's FIRST turn prevLen is 0, so the whole + // request is "tail" and blocking it wrote zero breakpoints — on precisely the + // turn whose job is to write the prefix. There is also nothing to protect yet: + // no compaction is pending, because no earlier turn enqueued one. + // - the tail a pending job will actually replace. The job enqueued by the PREVIOUS + // turn targets that turn's tail, which by now sits at or below the boundary. + // Blocking from the boundary up protected this turn's new messages, which no + // pending job is going to touch — off by one turn, and it protected the wrong + // span. The doomed span starts where the previous turn's own tail started. tailPending, noCacheAt := false, 0 - if mode == components.ModeAsync && !o.Deferred && !bypass && !o.CacheUncompactedTail { + if mode == components.ModeAsync && !o.Deferred && !bypass && !o.CacheUncompactedTail && + cacheAware && o.PendingFrom > 0 { tailPending = true - if noCacheAt = maxCachedIdx + 1; noCacheAt < 0 { - noCacheAt = 0 - } + noCacheAt = o.PendingFrom } c := &components.Ctx{ - Ctx: ctx, - Session: sessionID, - Store: st, - Model: models, - Bypass: bypass, - CtxWindow: o.Window, - CacheAware: cacheAware, - MaxCachedIdx: maxCachedIdx, - Mode: mode, - Deferred: o.Deferred, - TailCachePending: tailPending, - NoCacheAtOrAfter: noCacheAt, + Ctx: ctx, + Session: sessionID, + Store: st, + Model: models, + Bypass: bypass, + CtxWindow: o.Window, + CacheAware: cacheAware, + MaxCachedIdx: maxCachedIdx, + Mode: mode, + Deferred: o.Deferred, + TailCachePending: tailPending, + NoCacheAtOrAfter: noCacheAt, + StripCallerBreakpoints: o.StripCallerBreakpoints, } res.Session = sessionID @@ -240,6 +258,7 @@ func BodyOpts(ctx context.Context, pipe *components.Pipeline, st store.Store, o } res.Run = pipe.Run(chat, c) + res.TailUnprotected = c.TailUnprotected() // A component changed the message count (summarize restructures the transcript // to [msg0, , last-K]). Rebuild the messages array preserving each diff --git a/apply/modes_test.go b/apply/modes_test.go index 57f1779..c524cff 100644 --- a/apply/modes_test.go +++ b/apply/modes_test.go @@ -121,10 +121,11 @@ func TestStaleAsyncResultIsDiscardedEndToEnd(t *testing.T) { Mode: components.ModeAsync, Tracker: tr, }) - // A newer turn's compaction lands first, advancing the generation. - if !tr.CommitIfCurrent("s", inline.Generation, func() {}) { - t.Fatal("could not advance the generation") - } + // A newer TURN ships, superseding the job's snapshot. This is the realistic path and + // the one that used to be broken: the generation advanced only on commit, so a job + // from turn 1 read its own generation as current no matter how many turns had + // shipped, and committed against a transcript long since replaced. + tr.Turn("s", 99) // Now the older job finishes. buf := store.NewBuffer(base) diff --git a/apply/opts.go b/apply/opts.go index 72998df..d7ce89d 100644 --- a/apply/opts.go +++ b/apply/opts.go @@ -33,13 +33,28 @@ type Opts struct { // sets it, and it is what re-enables the LLM components the inline async pass // deliberately withholds. Deferred bool - // CacheUncompactedTail disables async's tail cache protection. In async mode the - // tail beyond the cached prefix is by construction content a not-yet-landed - // compaction is going to replace, so by default no breakpoint is placed there — - // protecting cache-write economics, because a breakpoint written over a tail we - // then replace converts a 0.1x read into a 1.25x write. Set true only for a backend confirmed - // not to cache, where the protection costs a breakpoint slot and buys nothing. + // CacheUncompactedTail disables async's tail cache protection, which otherwise keeps + // a prompt-cache breakpoint off the span a pending compaction will replace — + // because caching that span and then replacing it converts a 0.1x read into a 1.25x + // write, 11.5x the cost. Set true only for a backend confirmed not to cache, where + // the protection costs a breakpoint slot and buys nothing. CacheUncompactedTail bool + // PendingFrom is the lowest message index a QUEUED-but-unlanded compaction may + // rewrite: the start of the tail the previous turn deferred. 0 = nothing pending, so + // no protection (which is also the correct answer on a session's first turn — no + // earlier turn enqueued anything, and blocking there would suppress the very + // breakpoint that writes the initial prefix). + // + // It is the PREVIOUS turn's tail, not this turn's: the pending job was built from + // that turn's body, so that is the span it will replace. Deriving it from this turn's + // boundary instead protects messages no pending job will touch. + PendingFrom int + // StripCallerBreakpoints permits the tail protection to remove a breakpoint the + // CALLER placed inside the protected span. Necessary for any agent that sets its own + // (claude-code does), or the protection silently does nothing. When false and such a + // breakpoint is found, cacheinject declines to act at all rather than pretend, and + // Result.TailUnprotected says so. + StripCallerBreakpoints bool // PrevLen, when non-nil, supplies the cached-prefix boundary (the number of // normalized messages the previous turn carried) instead of resolving it. The // off-path async job MUST set it: it runs against the body of turn N but at a time @@ -73,6 +88,13 @@ type Result struct { // Run is the pipeline's report for this request, nil when the pipeline did not run. // Observe mode needs it: the run is the ONLY output, since the body is thrown away. Run *components.RunReport + // TailUnprotected reports that async's tail protection was requested but could not + // be honored, because the caller had placed its own breakpoint inside the protected + // span and StripCallerBreakpoints was false. The host must NOT defer a compaction + // for this turn: the tail is being cache-written, so replacing it later would pay a + // 1.25x rewrite of a span the provider already committed to — worse than not + // deferring at all. + TailUnprotected bool } // SessionOf resolves the session id apply will use for this body — the explicit id diff --git a/cmd/context-guru-proxy/main.go b/cmd/context-guru-proxy/main.go index 9430f28..2cd65fd 100644 --- a/cmd/context-guru-proxy/main.go +++ b/cmd/context-guru-proxy/main.go @@ -77,9 +77,10 @@ func main() { Windows: modelWindows(), // dynamic context-window resolver (fraction triggers) Mode: mode, // sync (default) | async | observe — explicit, never inferred Async: proxy.AsyncOptions{ - CacheUncompactedTail: cfg.Async.CacheUncompactedTail, - MaxQueue: cfg.Async.MaxQueue, - Workers: cfg.Async.Workers, + CacheUncompactedTail: cfg.Async.CacheUncompactedTail, + StripCallerBreakpoints: cfg.Async.StripCallerBreakpoints, + MaxQueue: cfg.Async.MaxQueue, + Workers: cfg.Async.Workers, }, // Per-request /compact override: swap the pipeline (?preset / header) while diff --git a/components/component.go b/components/component.go index 02cf25a..68bb848 100644 --- a/components/component.go +++ b/components/component.go @@ -179,8 +179,31 @@ type Ctx struct { // fails the other way — see #25.) TailCachePending bool NoCacheAtOrAfter int + // StripCallerBreakpoints permits taking back a cache breakpoint the CALLER set + // inside the protected tail. Without it the protection cannot cover an agent that + // places its own breakpoints (claude-code does), which made it a no-op on the + // primary workload. Removing a directive an agent deliberately placed is a behavior + // change we do not own, so it is the host's decision; the host's other option is to + // not defer that turn at all. + StripCallerBreakpoints bool + // tailUnprotected is set by cacheinject when it had to decline the tail protection + // (a caller breakpoint sat inside the protected span and stripping was not allowed). + // The host reads it to avoid deferring a compaction it cannot protect. Written from + // the single pipeline goroutine that owns this Ctx, read after Run returns. + tailUnprotected bool } +// DeclineTailProtection records that async's tail protection could not be honored on +// this request. Called by cacheinject; read by the host via TailUnprotected. +func (c *Ctx) DeclineTailProtection() { + if c != nil { + c.tailUnprotected = true + } +} + +// TailUnprotected reports whether DeclineTailProtection was called during this run. +func (c *Ctx) TailUnprotected() bool { return c != nil && c.tailUnprotected } + // effMode is Ctx.Mode with the zero value normalized to sync, so a Ctx built by // older code (or a test) reports the default rather than an empty mode string. func (c *Ctx) effMode() Mode { diff --git a/components/reformat/cacheinject.go b/components/reformat/cacheinject.go index e367fc8..83b7ddb 100644 --- a/components/reformat/cacheinject.go +++ b/components/reformat/cacheinject.go @@ -151,15 +151,36 @@ func (ci Cacheinject) Reformat(req *schemas.BifrostChatRequest, rep *components. // tail it is going to REPLACE must not be committed to the provider cache: a // breakpoint at or beyond it turns what would have been a 0.1x read next turn into // a 1.25x write of that same span — 11.5x the cost. That is exactly the failure - // that tripled headroom's cache-write on Terminal-Bench. So drop every wanted - // position inside the doomed tail and put one at the highest index below it, which - // still writes the whole stable prefix. + // that tripled headroom's cache-write on Terminal-Bench. + // + // This has to cover breakpoints the CALLER set, not just the ones we wanted. An + // earlier version only pruned `want`, which made the whole protection a no-op on the + // primary workload: claude-code sets its own breakpoint on the newest message, so + // the doomed tail was cache-written anyway — async then paid the rewrite AND lost a + // slot, strictly worse than sync. Whether we may strip that breakpoint is the + // caller's call (StripCallerBreakpoints), because removing one an agent deliberately + // placed changes behavior we do not own. if c.TailCachePending { for i := range want { if c.CacheBlocked(i) { delete(want, i) } } + for i := range req.Input { + if !c.CacheBlocked(i) || !hasBreakpoint(&req.Input[i]) { + continue + } + if !c.StripCallerBreakpoints { + // Cannot protect this turn without overriding the caller, so do not + // pretend to: leave the request exactly as it came and tell the host, + // which then declines to defer (see proxy.applyMode). Reporting success + // here is what made the protection a silent no-op before. + c.DeclineTailProtection() + rep.Skipped = true + return nil + } + unmark(&req.Input[i]) + } if last := c.NoCacheAtOrAfter - 1; last >= 0 && last < len(req.Input) { want[last] = struct{}{} } @@ -228,6 +249,18 @@ func mark(m *schemas.ChatMessage, ttl *string) bool { return true } +// unmark removes every cache_control directive from a message. Used only by async's +// tail protection, to take back a breakpoint that sits on content a pending compaction +// is about to replace. +func unmark(m *schemas.ChatMessage) { + if m.Content == nil { + return + } + for i := range m.Content.ContentBlocks { + m.Content.ContentBlocks[i].CacheControl = nil + } +} + func hasBreakpoint(m *schemas.ChatMessage) bool { if m.Content == nil { return false diff --git a/components/reformat/cacheinject_test.go b/components/reformat/cacheinject_test.go index 5efbaf0..324df35 100644 --- a/components/reformat/cacheinject_test.go +++ b/components/reformat/cacheinject_test.go @@ -296,6 +296,7 @@ func TestNoBreakpointAtOrBeyondUncompactedTail(t *testing.T) { c.MaxCachedIdx = boundary - 1 c.TailCachePending = true c.NoCacheAtOrAfter = boundary + c.StripCallerBreakpoints = true idxs, rep := run(t, c, convo(n)) if rep.Skipped { @@ -317,18 +318,24 @@ func TestNoBreakpointAtOrBeyondUncompactedTail(t *testing.T) { // A boundary of 0 means the whole request is doomed tail. Nothing may be written — // there is no stable prefix to protect and a breakpoint anywhere would be rewritten. -func TestWholeRequestPendingPlacesNothing(t *testing.T) { +// A session's FIRST turn must still write the prefix. It has no pending compaction (no +// earlier turn enqueued one) and nothing to protect, so apply never turns the protection +// on there — a previous version derived the boundary from prevLen=0, blocked every index, +// and wrote zero breakpoints on precisely the turn whose job is to establish the cache. +// An earlier test asserted that as correct; it encoded the bug. +func TestFirstTurnStillWritesThePrefix(t *testing.T) { c := ctx() c.Mode = components.ModeAsync - c.TailCachePending = true - c.NoCacheAtOrAfter = 0 + c.CacheAware = true + c.MaxCachedIdx = -1 // first turn + // apply leaves TailCachePending false here: PendingFrom is 0 (nothing queued). - idxs, rep := run(t, c, convo(10)) - if len(idxs) != 0 { - t.Fatalf("wrote breakpoints over a fully-pending request: %v", idxs) + idxs, rep := run(t, c, convo(30)) + if len(idxs) == 0 || rep.Skipped { + t.Fatalf("first turn wrote no breakpoint: %v skipped=%v", idxs, rep.Skipped) } - if !rep.Skipped { - t.Fatal("placing nothing should report skipped") + if top := idxs[len(idxs)-1]; top != 29 { + t.Fatalf("first turn did not anchor the newest message: %v", idxs) } } @@ -383,3 +390,57 @@ func TestSkippedOnDeferredRun(t *testing.T) { } } } + +// The protection must cover breakpoints the CALLER set, not only the ones cacheinject +// wanted. claude-code marks its own newest message, so an earlier version that pruned +// only `want` left the doomed tail cache-written — the protection was a silent no-op on +// the primary workload, and async then paid the rewrite AND lost a slot. +func TestCallerBreakpointInProtectedTailIsStripped(t *testing.T) { + msgs := convo(30) + if !mark(&msgs[29], nil) { + t.Fatal("could not place the caller's breakpoint") + } + c := ctx() + c.Mode = components.ModeAsync + c.CacheAware = true + c.MaxCachedIdx = 21 + c.TailCachePending = true + c.NoCacheAtOrAfter = 22 + c.StripCallerBreakpoints = true + + idxs, _ := run(t, c, msgs) + for _, i := range idxs { + if i >= 22 { + t.Fatalf("breakpoint at %d survived inside the protected tail: %v", i, idxs) + } + } + if len(idxs) == 0 { + t.Fatal("stripped everything; the stable prefix must still be written") + } +} + +// Without permission to strip, cacheinject must DECLINE rather than report success it +// did not deliver — and say so, so the host can skip deferring a turn it cannot protect. +func TestCallerBreakpointDeclinesWhenStrippingIsNotAllowed(t *testing.T) { + msgs := convo(30) + mark(&msgs[29], nil) + c := ctx() + c.Mode = components.ModeAsync + c.CacheAware = true + c.MaxCachedIdx = 21 + c.TailCachePending = true + c.NoCacheAtOrAfter = 22 + c.StripCallerBreakpoints = false + + idxs, rep := run(t, c, msgs) + if !c.TailUnprotected() { + t.Fatal("declined the protection without telling the host") + } + if !rep.Skipped { + t.Fatal("declining should report skipped") + } + // The caller's request is left exactly as it came. + if len(idxs) != 1 || idxs[0] != 29 { + t.Fatalf("modified the request while declining: %v", idxs) + } +} diff --git a/config/config.go b/config/config.go index 44e99d0..73c30d6 100644 --- a/config/config.go +++ b/config/config.go @@ -42,6 +42,12 @@ type AsyncConfig struct { // 11.5x the cost — which makes async strictly worse than sync. The escape hatch // exists because a backend that genuinely does not cache needs no protection. CacheUncompactedTail bool `yaml:"cache_uncompacted_tail"` + // StripCallerBreakpoints lets async's tail protection remove a cache breakpoint the + // agent itself placed inside the protected span. Required for the protection to do + // anything on an agent that sets its own (claude-code does); without it async + // declines to defer on those turns instead of pretending. Default false because it + // changes a directive in someone else's request. + StripCallerBreakpoints bool `yaml:"strip_caller_breakpoints"` // MaxQueue bounds the off-path job queue (0 = 256). A full queue drops, counted, // and never blocks the request path. MaxQueue int `yaml:"max_queue"` diff --git a/docs/design.md b/docs/design.md index b6670de..3d540dd 100644 --- a/docs/design.md +++ b/docs/design.md @@ -192,8 +192,14 @@ Mode is a dimension. `Report`/`RunReport` carry `Mode`, stamped by the pipeline - enforced requests split into `sync_enforced` / `async_enforced`; - async adds the whole queue tuple (`queued`, `pending`, `processed`, `dropped`, - `errors`, `stale_discarded`) plus `async_realized_saved_tokens`, the savings a turn - got by replaying an earlier turn's deferred work; + `errors`, `stale_discarded`), `async_tail_unprotected_turns`, and + `async_realized_saved_tokens` — the savings a turn got by replaying an earlier turn's + deferred work. That last one is gated on the session having had a compaction actually + land (`Tracker.Landed`): recording it on every async turn that saved anything made it a + tautology that re-reported the inline saving, so it read equal to total savings even on + turn 1 with no deferred work in existence; +- off-path (`Deferred`) runs are excluded from the enforced rollups entirely — their + savings are counted where they are realized, on the request path; - observe results land in **physically separate** accumulators serialized under `potential_*` / `projected_*`, which share no key with an enforced metric. In observe mode every enforced aggregate is zero by construction. Getting this wrong would @@ -233,10 +239,22 @@ So `modes.Tracker` keeps, per session under one lock: lock is held, so two jobs cannot both observe `gen` as current. A stale result is **discarded**, not applied. -The generation advances only when a compaction actually lands. That is what makes the -scheme non-starving: dedup on `(session, generation)` keeps at most one useful job in -flight per session, a commit moves the session forward, and the next turn enqueues -fresh work against the longer transcript. +**The generation advances on every TURN.** That is what makes "stale" mean what it says: +a job built from turn N is stale the moment turn N+1 ships. An earlier version advanced it +only on commit, which looked equivalent and was not — a job from turn 1 still read its own +generation as current after eight later turns and committed happily. The guard existed but +could only ever fire on a dedup collision, never on actual staleness. + +The honest consequence: at agent turn rates (seconds) a compaction taking tens of seconds +is usually superseded before it lands, so async discards a lot of work it paid for. +`stale_discarded` is how you see that, and it is the number to watch when deciding whether +async suits a workload. Dedup on `(session, generation)` still keeps at most one job in +flight per session, and the deferral is not starving — a job that finishes inside one turn +commits — but "computed" and "applied" are genuinely different counts here. + +A session that produces several unproductive jobs in a row stops enqueueing them +(`Tracker.Barren`): each one is a real cheap-model call, and traffic that does not compact +would otherwise buy an attempt every turn forever. `store.Buffer` is what makes "discard" possible at all. A deferred run writes frozen decisions, stashes and sticky ids as it goes, so throwing the result away after the @@ -269,9 +287,29 @@ A cache-write costs 11.5x a cache-read, so letting the un-compacted tail be cach then replacing it converts a read into a write and makes async strictly worse than sync — the failure that tripled headroom's cache-write on Terminal-Bench. -`apply` therefore sets `Ctx.TailCachePending` + `Ctx.NoCacheAtOrAfter` in async mode, -and `cacheinject` drops every wanted breakpoint position at or beyond that index, -anchoring at the highest safe one instead so the stable prefix is still written. +`apply` therefore sets `Ctx.TailCachePending` + `Ctx.NoCacheAtOrAfter`, and `cacheinject` +drops every breakpoint at or beyond that index, anchoring at the highest safe one instead +so the stable prefix is still written. + +Four conditions gate it, each one a bug caught in review: + +- **The protected span is the PREVIOUS turn's tail** (`Opts.PendingFrom`), not this + turn's. The pending job was built from that turn's body, so that is what it will + replace. Deriving the span from the current boundary protected messages no pending job + would touch — off by one turn, and guarding the wrong bytes. +- **Only when something is actually pending.** A session's first turn has no queued job + and nothing to protect; blocking there wrote zero breakpoints on precisely the turn whose + job is to establish the cache. +- **Only when cache-aware.** With `cache_mode: off` there is no cached prefix to protect, + so blocking suppressed caching forever for nothing. +- **Caller breakpoints too, or not at all.** `cacheinject` originally pruned only the + positions it wanted, leaving breakpoints the *agent* set. claude-code marks its own + newest message, so on the primary workload the doomed tail was cache-written anyway and + the protection was a silent no-op — async paid the rewrite *and* lost a slot. It now + either strips those (`async.strip_caller_breakpoints`) or declines the turn entirely via + `Ctx.DeclineTailProtection`, and the host then does not defer + (`async_tail_unprotected_turns`). Declining is the default because removing a directive + an agent deliberately placed is a change to someone else's request. The protection needs a separate bool rather than a sentinel index, because index 0 is a legitimate value ("no breakpoint anywhere") — no integer is free to mean "off". The diff --git a/docs/how-to/operating-modes.md b/docs/how-to/operating-modes.md index b43b483..296c2f8 100644 --- a/docs/how-to/operating-modes.md +++ b/docs/how-to/operating-modes.md @@ -7,6 +7,7 @@ behavior that existed before modes did, byte for byte. mode: sync # sync | async | observe async: cache_uncompacted_tail: false # safe default: protect cache-write economics + strip_caller_breakpoints: false # true is REQUIRED for async to do anything with claude-code max_queue: 256 workers: 1 ``` @@ -66,6 +67,19 @@ tail a pending compaction is going to replace. `cacheinject` drops those positio and anchors at the highest index below them instead, so the whole stable prefix is still written and nothing the provider commits to is later rewritten. +!!! warning "With claude-code you must choose: `strip_caller_breakpoints`, or async does nothing" + The protection only works if it controls the breakpoints. claude-code sets its **own** + breakpoint on the newest message — inside exactly the span a pending compaction will + replace. context-guru will not silently override a directive the agent placed, so by + default it **declines to defer that turn at all**, counted as + `async_tail_unprotected_turns`. On such a workload async is inert and `sync` is what + you are effectively running. + + Set `async.strip_caller_breakpoints: true` to let context-guru take that breakpoint + back and actually get async's benefit. The trade is explicit: you override the agent's + caching choice on the newest message, in exchange for not paying an 11.5x rewrite of + it. + The cost of the protection is one breakpoint position: the newest messages are not cached until their compaction lands. On an append-only agent transcript that is a small, bounded loss, and it is bounded by construction — the protection only covers @@ -79,14 +93,24 @@ is the difference between async being cheaper than sync and being worse than it. ### What async guarantees - **One useful job per session per generation.** A session carries a compaction - generation; a job records the generation it was built from. Enqueue dedups on - `(session, generation)`, with the pending slot claimed before the job is observable - in the queue, so a concurrent enqueue of the same key cannot slip past. + generation that advances on **every turn**; a job records the generation it was built + from. Enqueue dedups on `(session, generation)`, with the pending slot claimed before + the job is observable in the queue, so a concurrent enqueue of the same key cannot slip + past. - **Stale results are discarded, never applied.** The job writes into a buffered - overlay of the store and that buffer is committed only if the session is still at - the generation the job was built from — checked under the same lock that advances - it. A result computed from a superseded snapshot is thrown away and counted as - `stale_discarded`. + overlay of the store and that buffer is committed only if the session is still on the + turn the job was built from — checked under the same lock that advances it. A result + computed from a superseded snapshot is thrown away and counted as `stale_discarded`. + + Expect this to happen often. At agent turn rates (seconds) a compaction taking tens + of seconds is usually superseded before it lands, so async pays for work it then + discards. That is the deliberate trade: never apply a decision computed against a + transcript the session has moved past. If `stale_discarded` dominates `processed`, + your turns are too tight for deferral and `sync` is the honest choice. + +- **Unproductive sessions stop paying.** After a few deferred jobs in a row that produce + nothing, a session stops enqueueing them. Each job is a real cheap-model call, and + traffic that simply does not compact would otherwise buy an attempt every turn forever. - **The request path never waits and never blocks.** A full queue drops, counted as `dropped`. The request has already been forwarded, so a drop costs savings only. - **Bounded, owned workers.** One queue and a fixed worker count owned by the proxy, @@ -105,9 +129,16 @@ is the difference between async being cheaper than sync and being worse than it. - `dropped` and `stale_discarded` are the counters that say *we silently gave up savings*. They are surfaced deliberately. (headroom's dashboard shows only `queued`, which hides precisely this.) -- A rising `stale_discarded` means turns arrive faster than compaction finishes. That - is a tuning signal, not a fault — raise `workers`, or use `sync` if the workload's - turns are too tight for deferral to ever land. +- A high `stale_discarded` relative to `processed` means turns arrive faster than + compaction finishes, so most deferred work is computed and then thrown away. Expect + this at agent turn rates. Raise `workers`, or use `sync` — deferral cannot pay off if + nothing ever lands. +- `async_tail_unprotected_turns` counts turns async **refused** to defer because the + agent had cache-written the span a compaction would replace. Non-zero and climbing + means async is inert on this workload; see `strip_caller_breakpoints` above. +- `async_realized_saved_tokens` counts savings a turn got by replaying deferred work, and + counts at all only once a compaction has actually landed for that session. It is a + strict subset of `saved_tokens`; if it ever equals it, the counter is lying. - A rising `dropped` means `max_queue` is too small for your concurrency. - `errors` counts jobs that ran and failed. Non-zero with zero `processed` means the compaction path itself is broken — check the cheap model's credentials. @@ -139,11 +170,22 @@ enforced metric**: | `potential_components` | Per-component hypothetical contributions. | | `potential_overhead_ms_avg` | What compaction *would* have added per request — measured off-path, so it is what `sync` would cost you, not what `observe` costs you. | -In observe mode every **enforced** aggregate is zero by construction: +In observe mode every enforced **savings** aggregate is zero by construction: `requests`, `tokens_before`, `tokens_after`, `saved_tokens`, `sync_enforced`, `async_enforced` and the `components` map. That zero is the machine-readable form of "context-guru did not modify any request". +Two enforced-namespace fields are deliberately **not** zero, because they are real +measurements rather than hypotheticals: + +- `cg_added_ms_avg` — the actual latency added to the enforced path, which in observe mode + is ~0 precisely because that path does no pipeline work. Zeroing it would hide the mode's + headline result. +- `llm_calls` / `llm_input_tokens` / `llm_output_tokens` — context-guru's own model spend. + Observe measures off-path, and that measuring costs real money. The spend is not + hypothetical, so it stays where cost tooling already reads it, labelled by + `observe_llm_notice` as the cost of measuring rather than of enforcing. + A mislabelled hypothetical is worse than no number at all, because it silently inflates a savings claim. The separation is therefore structural — two physically separate accumulators with disjoint serialized names — and a test asserts that no diff --git a/docs/reference/config.md b/docs/reference/config.md index fc264f4..999abe8 100644 --- a/docs/reference/config.md +++ b/docs/reference/config.md @@ -33,6 +33,7 @@ Always explicit — nothing infers it from the rest of the configuration. | Field | Default | Purpose | |---|---|---| | `cache_uncompacted_tail` | `false` | When false (the safe default), no prompt-cache breakpoint is placed at or beyond the tail a pending compaction will replace. A cache-write costs **11.5x** a cache-read, so caching that tail and then replacing it makes async strictly worse than `sync`. Set true only for a backend confirmed **not** to cache prompts. | +| `strip_caller_breakpoints` | `false` | Let the tail protection remove a cache breakpoint the **agent** placed inside the protected span. Required for the protection to do anything on an agent that sets its own — claude-code does — otherwise async declines to defer those turns (`async_tail_unprotected_turns`) and is effectively inert. Default false because it overrides a directive in someone else's request. | | `max_queue` | `256` | Bound on the off-path job queue. A full queue **drops** (counted as `dropped`) and never blocks the request path. | | `workers` | `1` | Drain goroutines. One keeps a single compaction LLM call in flight per process, which keeps cheap-model spend and gateway rate limits predictable. | @@ -50,7 +51,7 @@ components: smartcrush: { min_items: 5, keep_first: 3, keep_last: 2 } store: { ttl_seconds: 1800, max_entries: 1000 } mode: sync # sync | async | observe -async: { cache_uncompacted_tail: false, max_queue: 256, workers: 1 } +async: { cache_uncompacted_tail: false, strip_caller_breakpoints: false, max_queue: 256, workers: 1 } ``` A component registers its constructor + config type via `init()`, so adding one diff --git a/docs/results/operating-modes.md b/docs/results/operating-modes.md index 2126132..960078b 100644 --- a/docs/results/operating-modes.md +++ b/docs/results/operating-modes.md @@ -30,7 +30,7 @@ cite for savings. What is measured here is whether each mode does what it says. | context-guru's own LLM cost | $0.0122 (1 call) | $0.0435 (4 calls) | $0.0779 (7 calls) | | off-path compaction time | — | 80.8 s | 75.0 s | | deferred compactions committed | — | 1 | 0 (never commits) | -| `async_realized_saved_tokens` | — | 15,962 | — | +| `async_realized_saved_tokens` | — | 15,962 *(retracted — circular, see below)* | — | | queue `{dropped, stale_discarded}` | — | `{0, 0}` | `{0, 0}` | ## The four questions @@ -43,36 +43,53 @@ path and 71.3 ms cumulative across 42 requests on async's, with `acted=0` inline model call is genuinely gone from the hot path. 80.8 s of compaction ran off-path, charged to nobody's request. -**Cache-write: it went DOWN, which is the result the policy was designed for.** Absolute -cache-write 52,287 → 42,980 (**−17.8%**) on ~49% *more* cache-read traffic. Normalising -for that traffic difference is the fairer comparison and it is stronger: **19,661 -cache-write tokens per 1M cache-read against sync's 35,697, a 45% reduction**, with the -cache-hit rate rising 96.55% → 98.07%. - -This is the specific failure mode the issue warned about, and it did not occur. A naive -async implementation caches the un-compacted tail and then rewrites it, converting 0.1x -reads into 1.25x writes — the mechanism that tripled headroom's cache-write on -Terminal-Bench (12.37M vs a 4.01M baseline). Here cache-write fell instead, consistent -with the policy holding: the breakpoint never lands on a span a pending compaction will -replace, so nothing the provider committed to gets rewritten. - -Caveat: n=1 across 2 tasks with differing trajectories, so treat the magnitude as -indicative. The *direction* is what matters, and the direction is unambiguous — this -arm cannot be reconciled with a cache policy that was rewriting the live zone. +**Cache-write: it was lower, but this measurement does NOT establish that the policy +caused it.** Absolute cache-write 52,287 → 42,980 (−17.8%) on ~49% more cache-read +traffic; normalised, 19,661 per 1M cache-read against sync's 35,697. Terminal-Bench showed +the same direction (13,185 vs 21,689). + +Those numbers stand as measurements. The causal claim does not, and it was withdrawn after +review found the mechanism was not doing what the arms were credited to: + +- On this workload the protection was **inert**. claude-code sets its own breakpoint on the + newest message, and the policy only pruned positions `cacheinject` itself wanted — so the + doomed tail was cache-written anyway. Whatever moved cache-write here, it was not the + tail protection. +- Two other defects pushed cache-write down for uninteresting reasons: a session's first + turn placed **zero** breakpoints, and with `cache_mode: off` breakpoints were suppressed + entirely. Writing fewer breakpoints lowers cache-write; that is arithmetic, not a policy + win. +- The arms are not paired: cache-read differs by 49%, trajectories by 6 mean steps, and + the async arm was re-run separately after a port collision. + +All four defects are now fixed, and the policy is proven **structurally** — unit tests +assert no breakpoint survives at or beyond the protected span, including one the caller +placed, and that the protection declines rather than pretends when it may not strip. The +*measured* confirmation needs a re-run on a 50-task paired arm with +`strip_caller_breakpoints: true`. Until then: mechanism verified by test, effect +unmeasured. ### 2. Does async reach the same steady-state savings as sync, just later? **On this evidence it reached more, not less** — 4.17% enforced against sync's 0.82% — but do not read that as async being better at compaction. Both numbers are small and noisy at n=1, and the arms took different trajectories (different step counts, so -different traffic). The load-bearing observation is narrower and does hold: -`async_realized_saved_tokens` = 15,962 = the entire enforced saving, from 1 committed -deferred compaction. Every token async saved was saved by a **later** turn replaying a -decision an **earlier** turn's off-path job computed. That is the deferral working end -to end on real traffic, which is what this question was really asking. - -Note also what async spent to get there: 80.8 s of compaction ran off-path against 25.3 -ms/req on-path. The work did not disappear, it moved. +different traffic). **The `async_realized_saved_tokens` = 15,962 figure I originally cited as "the entire +enforced saving" was circular and is retracted.** The counter was recorded on every async +turn that saved anything, with no check that the saving came from deferred work — so it +re-reported the inline saving and necessarily equalled the total. Review demonstrated it +reading `saved=396, realized=396` on the first turn of a model-free pipeline, where no +deferred compaction existed at all. + +It is now gated on the session having had a compaction actually land, and a test asserts it +is a **strict** subset of `saved_tokens` (equality is the signature of the old bug). Under +the corrected counter a controlled five-turn session reports `realized=4125` of +`saved=4948` with 1 legitimate `stale_discarded` — deferral demonstrably contributing part +of the saving, which is the honest form of the claim. + +So this question is **not** answered by the arms above; the deferral mechanism is verified +by test, and its steady-state contribution on real traffic is unmeasured. What the arms do +show is where the work went: 80.8 s of compaction ran off-path against 25.3 ms/req on-path. ### 3. Does observe add measurable latency to the enforced path? diff --git a/metrics/metrics.go b/metrics/metrics.go index 7881ef8..c4237c6 100644 --- a/metrics/metrics.go +++ b/metrics/metrics.go @@ -94,6 +94,7 @@ type Aggregator struct { deferredRuns int64 // off-path async compactions that produced a committed result deferredMs float64 // wall time spent off the request path realizedSaved int64 // tokens saved on-path by replaying a previously deferred compaction + tailUnprotected int64 // turns where deferral was declined to protect the cache potentialRuns int64 potentialBefore int64 potentialAfter int64 @@ -131,9 +132,20 @@ func (a *Aggregator) RecordDeferred(ms float64, committed bool) { a.mu.Unlock() } +// RecordTailUnprotected notes a turn where async declined to defer because the caller +// had cache-written the tail a compaction would have replaced and stripping its +// breakpoint was not permitted. Deferring anyway would cost a 1.25x rewrite of a span +// the provider committed to. A high count means async is doing nothing on this workload +// and async.strip_caller_breakpoints is the knob to consider. +func (a *Aggregator) RecordTailUnprotected() { + a.mu.Lock() + a.tailUnprotected++ + a.mu.Unlock() +} + // RecordRealized notes tokens saved on the request path by replaying a compaction an -// EARLIER turn computed off-path. This is async's "savings realized on turn N+k" -// figure: without it the deferred value looks like it never arrived. +// EARLIER turn computed off-path. Gated by the caller on the session having had a +// compaction actually land — otherwise it would just re-report the inline saving. func (a *Aggregator) RecordRealized(tokens int) { if tokens <= 0 { return @@ -367,6 +379,15 @@ type Snapshot struct { SyncEnforced int64 `json:"sync_enforced"` AsyncEnforced int64 `json:"async_enforced"` + // ObserveLLMNotice warns that context-guru's own model spend (llm_calls / + // llm_input_tokens / llm_output_tokens, which feed cg_llm_cost in the harnesses) is + // OFF-PATH measurement cost in observe mode, not the cost of an enforced compaction. + // The tokens were really spent — the number is not hypothetical and must not be moved + // into the potential_* namespace — but attributing it to enforcement would be wrong. + // cg_added_ms_avg is likewise a real measurement of the enforced path, and in observe + // mode it correctly reads ~0 because that path does no pipeline work. + ObserveLLMNotice string `json:"observe_llm_notice,omitempty"` + // Async: the full queue counter tuple (queued/pending/processed/dropped/errors/ // stale_discarded) plus the deferred-work accounting. `dropped` and // `stale_discarded` are the "we silently gave up savings" counters and are @@ -375,6 +396,10 @@ type Snapshot struct { DeferredRuns int64 `json:"async_deferred_runs"` DeferredMsTotal float64 `json:"async_deferred_ms_total"` RealizedSavedTokens int64 `json:"async_realized_saved_tokens"` + // TailUnprotectedTurns counts turns async declined to defer because the caller had + // already cache-written the span a compaction would replace. Non-zero means async is + // largely inert here; see async.strip_caller_breakpoints. + TailUnprotectedTurns int64 `json:"async_tail_unprotected_turns"` // Observe mode: HYPOTHETICALS. Distinct keys (potential_* / projected_*) that // never share a name with an enforced metric, so a consumer cannot sum a @@ -397,6 +422,13 @@ type Snapshot struct { const observeNotice = "OBSERVE MODE: context-guru did not modify any request. " + "Every potential_*/projected_* field is a hypothetical, not a realized saving." +// observeLLMNotice covers the one place observe legitimately writes an enforced-namespace +// key: its own model spend is real money, so it stays where cost tooling already reads +// it, labelled for what it is. +const observeLLMNotice = "In observe mode llm_calls/llm_input_tokens/llm_output_tokens " + + "are the cost of MEASURING off-path, not of enforcing a compaction. The spend is real " + + "(not hypothetical); it simply bought a projection rather than a saving." + // Snapshot returns a point-in-time copy of the rollups. func (a *Aggregator) Snapshot() Snapshot { a.mu.Lock() @@ -447,13 +479,17 @@ func (a *Aggregator) Snapshot() Snapshot { SyncEnforced: a.syncRequests, AsyncEnforced: a.asyncRequests, DeferredRuns: a.deferredRuns, DeferredMsTotal: a.deferredMs, - RealizedSavedTokens: a.realizedSaved, + RealizedSavedTokens: a.realizedSaved, + TailUnprotectedTurns: a.tailUnprotected, } if a.asyncStats != nil { snap.AsyncQueue = a.asyncStats() } if a.potentialRuns > 0 || mode == components.ModeObserve { snap.ObserveNotice = observeNotice + if snap.LLMCalls > 0 || mode == components.ModeObserve { + snap.ObserveLLMNotice = observeLLMNotice + } snap.ObserveRequests = a.potentialRuns snap.ActualBaselineTokens = a.potentialBefore snap.ProjectedOptimizedTokens = a.potentialAfter diff --git a/modes/modes_test.go b/modes/modes_test.go index e155c07..240fcbf 100644 --- a/modes/modes_test.go +++ b/modes/modes_test.go @@ -3,6 +3,7 @@ package modes import ( "context" "runtime" + "strconv" "sync" "sync/atomic" "testing" @@ -12,12 +13,20 @@ import ( // --- Tracker ---------------------------------------------------------------- func TestTurnReturnsPreviousLengthAndAdvances(t *testing.T) { + // Generation VALUES are not per-session counters — they are drawn from a global + // high-water mark so a session recreated after eviction cannot reuse one an in-flight + // job still holds. Only the ordering is contractual: strictly increasing per turn. tr := NewTracker(0) - if pl, gen := tr.Turn("s", 5); pl != 0 || gen != 0 { - t.Fatalf("first turn: got (%d,%d), want (0,0)", pl, gen) + pl0, g0 := tr.Turn("s", 5) + if pl0 != 0 { + t.Fatalf("first turn prevLen: got %d, want 0", pl0) } - if pl, gen := tr.Turn("s", 9); pl != 5 || gen != 0 { - t.Fatalf("second turn: got (%d,%d), want (5,0)", pl, gen) + pl1, g1 := tr.Turn("s", 9) + if pl1 != 5 { + t.Fatalf("second turn prevLen: got %d, want 5", pl1) + } + if g1 <= g0 { + t.Fatalf("generation did not advance on a turn: %d then %d", g0, g1) } // A shorter turn must not shrink the boundary: content the provider already // cached would otherwise fall back into the mutable tail. @@ -35,9 +44,12 @@ func TestSessionsAreIsolated(t *testing.T) { if pl, _ := tr.Turn("b", 2); pl != 0 { t.Fatalf("session b saw session a's length: %d", pl) } - tr.CommitIfCurrent("a", 0, nil) - if g := tr.Gen("b"); g != 0 { - t.Fatalf("session b's generation moved with a's: %d", g) + // A commit on one session must not move another's generation (which would make + // b's in-flight jobs spuriously stale). + _, gb := tr.Turn("b", 4) + tr.CommitIfCurrent("a", 1, nil) + if g := tr.Gen("b"); g != gb { + t.Fatalf("session b's generation moved with a's: %d, want %d", g, gb) } } @@ -54,15 +66,52 @@ func TestStaleResultIsDiscarded(t *testing.T) { if applied != 1 { t.Fatalf("commit did not run: %d", applied) } - // A second job built from the SAME (now superseded) generation. + // A LATER TURN ships. That, not a previous commit, is what makes a job stale in + // practice — and it is exactly the case an earlier version got wrong: the + // generation only moved on commit, so a job from turn 1 stayed "current" through + // any number of later turns and committed against a transcript long since replaced. + tr.Turn("s", 9) if tr.CommitIfCurrent("s", gen, func() { applied++ }) { - t.Fatal("stale generation was accepted") + t.Fatal("a job superseded by a later TURN was accepted") } if applied != 1 { t.Fatalf("stale commit ran anyway: applied=%d", applied) } - if g := tr.Gen("s"); g != gen+1 { - t.Fatalf("generation did not advance exactly once: %d", g) +} + +// TestGenerationAdvancesPerTurn pins the invariant directly: every turn supersedes the +// jobs of every earlier turn. Without this the stale guard can only ever catch a dedup +// collision, never actual staleness — the guard exists but never fires. +func TestGenerationAdvancesPerTurn(t *testing.T) { + tr := NewTracker(0) + _, first := tr.Turn("s", 4) + for n := 5; n <= 12; n++ { + tr.Turn("s", n) + } + if g := tr.Gen("s"); g == first { + t.Fatal("the generation did not move across eight turns") + } + if tr.CommitIfCurrent("s", first, func() {}) { + t.Fatal("a job from the first turn committed after eight later turns") + } +} + +// TestLandedGatesRealizedSavings: before any deferred compaction commits, a session has +// realized nothing from deferral — whatever the inline pass saved, it saved on the +// request path. Crediting that to the deferral would make the "realized" counter a +// tautology (it reported exactly the inline saving on turn 1 of a model-free pipeline). +func TestLandedGatesRealizedSavings(t *testing.T) { + tr := NewTracker(0) + _, gen := tr.Turn("s", 4) + if tr.Landed("s") { + t.Fatal("a session with no committed compaction reports one") + } + tr.CommitIfCurrent("s", gen, func() {}) + if !tr.Landed("s") { + t.Fatal("a committed compaction was not recorded") + } + if tr.Landed("other") { + t.Fatal("Landed leaked across sessions") } } @@ -289,3 +338,73 @@ func settle() { time.Sleep(5 * time.Millisecond) } } + +// TestEvictionDoesNotResurrectAnInFlightJob: a session recreated after eviction must not +// restart at a generation an in-flight job could still match, or that job commits over a +// session that has moved several turns on. +func TestEvictionDoesNotResurrectAnInFlightJob(t *testing.T) { + tr := NewTracker(2) + _, gen := tr.Turn("victim", 4) // a job is now in flight holding `gen` + + // Churn other sessions until "victim" is evicted. + for i := 0; i < 10; i++ { + tr.Turn("filler"+strconv.Itoa(i), 3) + } + // "victim" comes back as a fresh session. + tr.Turn("victim", 5) + + if tr.CommitIfCurrent("victim", gen, func() {}) { + t.Fatalf("a pre-eviction job (gen %d) committed over the recreated session", gen) + } +} + +// TestStopDoesNotWaitForASlowJob: cancelling asks a job to stop, but one blocked in an +// HTTP call to the cheap model only notices when that call returns — and its client +// timeout is minutes. Shutdown must not inherit that: the job's result is pure savings +// nobody is waiting for. main.go defers Close(), so a blocking Stop would hang exit. +func TestStopDoesNotWaitForASlowJob(t *testing.T) { + p := NewPool(0, 1) + release := make(chan struct{}) + defer close(release) + + started := make(chan struct{}) + p.Enqueue("slow", func(context.Context) { + close(started) + <-release // ignores cancellation, like an in-flight HTTP call + }) + <-started + + done := make(chan bool, 1) + go func() { done <- p.Stop() }() + select { + case clean := <-done: + if clean { + t.Fatal("Stop reported a clean exit while a job was still running") + } + case <-time.After(stopGrace + 3*time.Second): + t.Fatal("Stop blocked past its grace period on an uncancellable job") + } +} + +// TestBarrenSessionStopsPayingForCompaction: each deferred job is a real cheap-model +// call, so traffic that simply does not compact must stop buying attempts. +func TestBarrenSessionStopsPayingForCompaction(t *testing.T) { + tr := NewTracker(0) + for i := 0; i < barrenLimit; i++ { + if tr.Barren("s") { + t.Fatalf("gave up after only %d unproductive jobs", i) + } + tr.RecordJobOutcome("s", false) + } + if !tr.Barren("s") { + t.Fatalf("still deferring after %d unproductive jobs", barrenLimit) + } + // One productive job proves the traffic does compact after all; resume. + tr.RecordJobOutcome("s", true) + if tr.Barren("s") { + t.Fatal("a productive job did not reset the budget") + } + if tr.Barren("untouched") { + t.Fatal("the barren budget leaked across sessions") + } +} diff --git a/modes/pool.go b/modes/pool.go index 9a8db79..139472c 100644 --- a/modes/pool.go +++ b/modes/pool.go @@ -4,6 +4,7 @@ import ( "context" "log/slog" "sync" + "time" ) // Pool is the bounded off-path worker pool for async and observe mode: one queue, @@ -183,20 +184,38 @@ func (p *Pool) Stats() Stats { } } -// Stop cancels the pool's context and waits for its workers to exit. Queued jobs are -// abandoned — they were pure savings, and the requests they belonged to went out long -// ago. Idempotent. -func (p *Pool) Stop() { +// stopGrace bounds how long Stop waits for an in-flight job. Cancelling the context asks +// the job to stop, but a compaction sitting in an HTTP call to the cheap model only +// notices when that call returns, and its client timeout is minutes. Since the job's +// result is pure savings that nobody is waiting for, a shutdown must not inherit that +// timeout — it gives up and lets the goroutine die with the process. +const stopGrace = 2 * time.Second + +// Stop cancels the pool's context and waits briefly for its workers to exit. Queued jobs +// are abandoned — they were pure savings, and the requests they belonged to went out long +// ago. Returns false if a worker was still running at the grace deadline (its goroutine +// is left to exit on its own; nothing depends on its result). Idempotent. +func (p *Pool) Stop() bool { if p == nil { - return + return true } p.mu.Lock() if !p.started { p.mu.Unlock() - return + return true } p.started = false p.mu.Unlock() p.cancel() - p.wg.Wait() + + done := make(chan struct{}) + go func() { p.wg.Wait(); close(done) }() + select { + case <-done: + return true + case <-time.After(stopGrace): + slog.Warn("context-guru: async worker still busy at shutdown; abandoning its result", + "grace", stopGrace) + return false + } } diff --git a/modes/tracker.go b/modes/tracker.go index 978fbca..5272c0a 100644 --- a/modes/tracker.go +++ b/modes/tracker.go @@ -34,14 +34,29 @@ import "sync" // raced on it (the hazard #31 calls out, overlapping with #25). Reading and writing it // under the same lock, in one call, removes the race. type Tracker struct { - mu sync.Mutex - m map[string]*sessState - max int // bound on tracked sessions; 0 => default + mu sync.Mutex + m map[string]*sessState + // issued is a high-water mark across ALL sessions, so a session recreated after + // eviction starts above any generation a still-in-flight job could be holding. + issued uint64 + max int // bound on tracked sessions; 0 => default } type sessState struct { - gen uint64 - prevLen int + gen uint64 + prevLen int + landed bool // a deferred compaction has committed for this session + committed uint64 // highest generation whose result already landed (0 = none) + // pendingFrom is the lowest message index an enqueued-but-unlanded compaction may + // rewrite — the start of the tail the turn that enqueued it was built from. 0 = + // nothing pending. This is what async's cache protection must cover, and it is the + // PREVIOUS turn's tail, not the current one's. + pendingFrom int + // barren counts consecutive deferred jobs that ran and produced nothing. Each such + // job is a full off-path compaction — real cheap-model spend — so a session whose + // traffic simply is not compactable would otherwise pay for one on every turn, + // forever, for a saving that never materialises. + barren int } // defaultMaxSessions bounds the tracker so an unbounded stream of distinct sessions @@ -62,13 +77,23 @@ func (t *Tracker) get(session string) *sessState { if s == nil { if len(t.m) >= t.max { // ponytail: arbitrary eviction, same policy as the store's sticky sets. - // A dropped session just re-starts at generation 0 — correct, less saving. for k := range t.m { delete(t.m, k) break } } - s = &sessState{} + // A recreated session must NOT restart at generation 0. An in-flight job from + // before the eviction still holds its old generation, and starting over at 0 + // would let it match and commit over a session that has moved on. Seeding above + // every generation ever issued makes any surviving job unmatchable — the safe + // direction, since the cost is one discarded compaction. + // + // prevLen deliberately stays 0: it is a claim about what the provider has cached, + // and after eviction we no longer know. 0 means "treat everything as tail", which + // is what the cache-aware offloaders already handle; MaxCachedIdx = -1 (the + // fail-open #25 addresses) is the separate concern. + t.issued++ + s = &sessState{gen: t.issued} t.m[session] = s } return s @@ -76,10 +101,22 @@ func (t *Tracker) get(session string) *sessState { // Turn records that this session's current turn carries n normalized messages and // returns the snapshot the request must be built from: the PREVIOUS turn's length -// (the cached-prefix boundary) and the current compaction generation. Atomic, so two +// (the cached-prefix boundary) and the generation this turn belongs to. Atomic, so two // concurrent turns of one session each get a consistent pair and the second's write // cannot be lost to the first's deferred write-back. // +// The generation advances on every TURN, which is what makes "stale" mean what the +// design says it means: a job built from turn N is stale the moment turn N+1 ships. +// An earlier version advanced it only on commit, so a job from turn 1 still read its +// own generation as current after eight later turns and committed happily — the guard +// existed but could never fire for staleness, only for a dedup collision. +// +// The cost of getting this right is real and is the point of the mode's tuning knobs: +// at agent turn rates (seconds) a compaction that takes tens of seconds is usually +// superseded before it lands, so async trades a lot of would-be savings for never +// applying a decision computed against a transcript the session has moved past. +// `stale_discarded` is how you see that happening. +// // prevLen only ever grows: an agent that re-sends a shorter transcript (a rewind, or // a second, smaller request under the same session id) must not shrink the boundary, // or content the provider already cached would fall back into the mutable tail. @@ -87,11 +124,79 @@ func (t *Tracker) Turn(session string, n int) (prevLen int, gen uint64) { t.mu.Lock() defer t.mu.Unlock() s := t.get(session) - prevLen, gen = s.prevLen, s.gen + prevLen = s.prevLen if n > s.prevLen { s.prevLen = n } - return prevLen, gen + s.gen++ + if s.gen > t.issued { + t.issued = s.gen + } + return prevLen, s.gen +} + +// Pending returns the protected span's start (see sessState.pendingFrom): the lowest +// index a queued-but-unlanded compaction may rewrite. 0 = nothing pending. +func (t *Tracker) Pending(session string) int { + t.mu.Lock() + defer t.mu.Unlock() + return t.get(session).pendingFrom +} + +// SetPending records that a compaction covering [from, end) is now queued for this +// session, so later turns keep their cache breakpoints out of that span. Called after a +// successful enqueue; Clear undoes it once the job resolves. +func (t *Tracker) SetPending(session string, from int) { + t.mu.Lock() + defer t.mu.Unlock() + s := t.get(session) + // Keep the LOWEST pending start: two overlapping jobs mean everything from the + // earlier one's tail onward is in play, and under-protecting is the expensive + // direction (a rewritten cached span costs 11.5x a read). + if s.pendingFrom == 0 || (from > 0 && from < s.pendingFrom) { + s.pendingFrom = from + } +} + +// ClearPending records that no compaction is outstanding for this session, so the next +// turn may cache its tail again. Called when a job commits, is discarded, or fails — +// every terminal path, or the protection would latch on forever and permanently cost a +// breakpoint slot. +func (t *Tracker) ClearPending(session string) { + t.mu.Lock() + defer t.mu.Unlock() + t.get(session).pendingFrom = 0 +} + +// barrenLimit is how many consecutive unproductive deferred jobs a session may run +// before deferral is switched off for it. Small on purpose: the evidence that this +// traffic does not compact arrives immediately, and the cost of ignoring it recurs every +// turn. Any productive job resets the count. +// +// ponytail: a flat count, not a backoff schedule. A backoff would let spend resume +// periodically on traffic already shown not to compact; add one only if a workload turns +// out to become compactable mid-session. +const barrenLimit = 3 + +// Barren reports whether this session has exhausted its unproductive-job budget, in +// which case the host must stop enqueueing off-path compactions for it. +func (t *Tracker) Barren(session string) bool { + t.mu.Lock() + defer t.mu.Unlock() + return t.get(session).barren >= barrenLimit +} + +// RecordJobOutcome notes whether a deferred job produced anything usable, so a session +// that never compacts stops paying for compaction attempts. +func (t *Tracker) RecordJobOutcome(session string, productive bool) { + t.mu.Lock() + defer t.mu.Unlock() + s := t.get(session) + if productive { + s.barren = 0 + return + } + s.barren++ } // Gen returns the session's current compaction generation. @@ -101,24 +206,48 @@ func (t *Tracker) Gen(session string) uint64 { return t.get(session).gen } -// CommitIfCurrent runs commit and advances the generation IF the session is still at -// gen — the stale-result guard. commit is called while the session's lock is held, so -// a concurrent job for the same session cannot also observe gen as current and commit -// on top of it. Returns false when the result was stale and therefore discarded. +// CommitIfCurrent runs commit IF the session is still at gen — the stale-result guard. +// commit is called while the session's lock is held, so a concurrent job for the same +// session cannot also observe gen as current and commit on top of it. Returns false +// when the result was stale and therefore discarded. +// +// It also marks that this session has had a deferred compaction land, which is what +// lets the metrics distinguish savings a later turn got from replaying that work from +// savings the inline pass would have produced anyway. See Landed. func (t *Tracker) CommitIfCurrent(session string, gen uint64, commit func()) bool { t.mu.Lock() defer t.mu.Unlock() s := t.get(session) + // Stale: a later turn has already shipped, so this job was built from a transcript + // the session has moved past. if s.gen != gen { return false } + // Already satisfied: another job for this same generation committed first. The pool's + // dedup makes this unreachable in production (one job per key), but the guard must be + // exact on its own — a second commit at one generation would apply two independent + // compactions of the same snapshot on top of each other. + if s.committed >= gen { + return false + } if commit != nil { commit() } - s.gen++ + s.committed = gen + s.landed = true return true } +// Landed reports whether a deferred compaction has ever committed for this session. +// The metrics use it to gate "realized" savings: before anything has landed, whatever +// the inline pass saved was saved by deterministic components on the request path, not +// by deferred work, and crediting it to the deferral would be circular. +func (t *Tracker) Landed(session string) bool { + t.mu.Lock() + defer t.mu.Unlock() + return t.get(session).landed +} + // Sessions reports how many sessions are tracked (test/telemetry aid). func (t *Tracker) Sessions() int { t.mu.Lock() diff --git a/proxy/modes.go b/proxy/modes.go index ae0681e..4134fe2 100644 --- a/proxy/modes.go +++ b/proxy/modes.go @@ -46,21 +46,44 @@ func (h *Handler) applyMode(r *httpReqInfo) ([]byte, time.Duration) { return r.body, time.Since(start) } + // The span a pending job may rewrite, resolved before the pipeline runs so + // cacheinject can keep a breakpoint off it. Session id is not known yet when the + // host supplied none (apply derives it), so this covers the explicit-session case + // and degrades to "no protection" otherwise — the same direction as no pending job. + pendingFrom := 0 + if mode == components.ModeAsync && r.session != "" { + pendingFrom = h.tracker.Pending(r.session) + } res := apply.BodyOpts(r.ctx, h.pipe, h.store, apply.Opts{ Provider: r.provider, Body: r.body, Session: r.session, Bypass: r.bypassed, Models: r.models, Window: r.window, CacheMode: h.opts.CacheMode, Mode: mode, Tracker: h.tracker, - CacheUncompactedTail: h.opts.Async.CacheUncompactedTail, + CacheUncompactedTail: h.opts.Async.CacheUncompactedTail, + PendingFrom: pendingFrom, + StripCallerBreakpoints: h.opts.Async.StripCallerBreakpoints, }) added := time.Since(start) if mode == components.ModeAsync && !r.bypassed { - // The savings this turn came from replaying an EARLIER turn's off-path work. - // Attributing them is the only way deferred value stops looking invisible. - if h.agg != nil && res.Run != nil && res.Run.Saved() > 0 { + // Savings realized from DEFERRED work only. Gated on the session having had a + // compaction land, because before that whatever the inline pass saved was saved by + // deterministic components on the request path — crediting it to the deferral made + // this counter a tautology (it reported the inline saving verbatim on turn 1 of a + // model-free pipeline, so "realized == total saved" was true by construction). + if h.agg != nil && res.Run != nil && res.Run.Saved() > 0 && + res.Session != "" && h.tracker.Landed(res.Session) { h.agg.RecordRealized(res.Run.Saved()) } - h.enqueueAsync(r, res) + if res.TailUnprotected { + // The tail is being cache-written and we were not allowed to prevent it, so + // deferring would buy a 1.25x rewrite of a span the provider has committed to + // — strictly worse than staying synchronous for this turn. Skip the job. + if h.agg != nil { + h.agg.RecordTailUnprotected() + } + } else { + h.enqueueAsync(r, res) + } } if res.Body == nil { return r.body, added @@ -119,9 +142,20 @@ func (h *Handler) enqueueAsync(r *httpReqInfo, inline apply.Result) { if sess == "" { return // the pipeline never ran (no messages array) — nothing to defer } + // A session whose traffic simply does not compact must stop paying for off-path + // compaction attempts: each one is a real cheap-model call, and without this an + // unproductive session runs one every turn indefinitely. + if h.tracker.Barren(sess) { + return + } key := jobKey(sess, gen) - h.pool.Enqueue(key, func(ctx context.Context) { + // The span this job may rewrite: the tail of the turn it was built from. Recorded + // BEFORE the enqueue so a turn arriving while the job is queued already sees the + // protection — recording it after would leave a window where the tail gets cached + // and then rewritten, which is the whole failure this policy exists to prevent. + h.tracker.SetPending(sess, prevLen) + if !h.pool.Enqueue(key, func(ctx context.Context) { start := time.Now() buf := store.NewBuffer(h.store) info.ctx = ctx @@ -139,7 +173,9 @@ func (h *Handler) enqueueAsync(r *httpReqInfo, inline apply.Result) { PrevLen: &prevLen, }) committed := false - if res.Changed && buf.Writes() > 0 { + productive := res.Changed && buf.Writes() > 0 + h.tracker.RecordJobOutcome(sess, productive) + if productive { committed = h.tracker.CommitIfCurrent(sess, gen, buf.Commit) if !committed { h.pool.RecordStale() @@ -150,7 +186,13 @@ func (h *Handler) enqueueAsync(r *httpReqInfo, inline apply.Result) { if h.agg != nil { h.agg.RecordDeferred(float64(time.Since(start).Microseconds())/1000.0, committed) } - }) + // Every terminal path clears the protection, including "ran and produced + // nothing": leaving it set would latch the block on forever and permanently + // cost a breakpoint slot for a rewrite that is never coming. + h.tracker.ClearPending(sess) + }) { + h.tracker.ClearPending(sess) // dropped or deduped: nothing is pending from THIS turn + } } // enqueueObserve runs the pipeline off-path on a COPY of the request, against observe's diff --git a/proxy/modes_test.go b/proxy/modes_test.go index 018514f..3939e28 100644 --- a/proxy/modes_test.go +++ b/proxy/modes_test.go @@ -200,6 +200,14 @@ func TestObserveMetricsCannotBeSummedIntoEnforcedTotals(t *testing.T) { if snap.SyncEnforced != 0 || snap.AsyncEnforced != 0 { t.Fatalf("observe counted as enforced: sync=%d async=%d", snap.SyncEnforced, snap.AsyncEnforced) } + // Two enforced-namespace fields are deliberately NOT zeroed, because they are real + // measurements rather than hypotheticals — cg_added_ms_avg (the actual enforced-path + // latency, ~0 here, which IS the headline) and context-guru's own model spend (observe + // measures off-path, and that costs real money). The notice labels the latter so it is + // not read as the cost of enforcing. + if snap.ObserveLLMNotice == "" { + t.Fatal("observe did not label its own off-path model spend") + } if len(snap.Components) != 0 { t.Fatalf("observe results leaked into the enforced per-component map: %v", snap.Components) } diff --git a/proxy/proxy.go b/proxy/proxy.go index 3fa61de..ce66acb 100644 --- a/proxy/proxy.go +++ b/proxy/proxy.go @@ -97,6 +97,14 @@ type AsyncOptions struct { // 11.5x the cost, making async strictly WORSE than sync. Set true only for a // backend confirmed not to cache, where the protection buys nothing. CacheUncompactedTail bool `yaml:"cache_uncompacted_tail"` + // StripCallerBreakpoints lets the tail protection remove a cache breakpoint the + // AGENT placed inside the span a pending compaction will replace. Without it the + // protection cannot cover an agent that sets its own breakpoints — claude-code does, + // so on that workload async declines to defer at all rather than pretend to protect + // (counted as async_tail_unprotected_turns). Default false: removing a directive the + // agent deliberately placed is a behavior change in someone else's request, so it is + // opt-in. Turn it on to actually get async's benefit with claude-code. + StripCallerBreakpoints bool `yaml:"strip_caller_breakpoints"` // MaxQueue bounds the off-path job queue; a full queue DROPS (counted) rather than // blocking the request path. 0 = modes.DefaultMaxQueue. MaxQueue int `yaml:"max_queue"` diff --git a/store/buffer.go b/store/buffer.go index 6d5b0d5..d8bc150 100644 --- a/store/buffer.go +++ b/store/buffer.go @@ -103,3 +103,25 @@ func (b *Buffer) Writes() int { defer b.mu.Unlock() return len(b.writes) } + +// FrozenLost forwards the optional FrozenLoser capability (#40) to the base store, so +// wrapping a store in a Buffer does not silently disable it. A key the buffer itself +// holds is present, not lost, whatever the base thinks. +// +// Type-asserting on the wrapper is why this is needed: a component checks +// `c.Store.(store.FrozenLoser)`, and without this method an off-path async run — which +// always sees a Buffer — would take the degraded path and re-derive nothing, exactly the +// case #40 added the signal for. +func (b *Buffer) FrozenLost(key string) bool { + b.mu.Lock() + _, held := b.writes[key] + b.mu.Unlock() + if held { + return false + } + // Asserted on a locally-declared shape rather than store.FrozenLoser, because that + // type arrives with #40 and this branch must compile before it. Structural matching + // means it binds to the real interface the moment #40 lands, with no edit here. + fl, ok := b.Base.(interface{ FrozenLost(string) bool }) + return ok && fl.FrozenLost(key) +}