fix(extract_llm): size the per-call budget for a loaded server, and count the calls it abandons - #64
Merged
OsherElhadad merged 1 commit intoAug 12, 2026
Conversation
…ount the calls it abandons
The 15s per-call ceiling was a client-side assumption about server latency. On a
shared on-prem vLLM under KV-cache pressure the server-side QUEUE WAIT alone was
p50 17.2s / p95 78.8s, so the deadline expired before the model started on more
than half of all calls.
Measured across one 50-task SWE-bench arm at equal request volume:
leg proxy requests llm_calls calls/request cg_added_ms_avg
low (idle server) 2,513 2,093 0.83 5,530
high (KV-pressured) 2,387 255 0.11 8,563
8.2x fewer calls at 5% fewer requests while per-request overhead ROSE 55%: the
component was starting calls, blocking, hitting the ceiling and discarding the
work. Because it fails open silently, the arm degraded into a partial no-op that
read as a 42-point latency IMPROVEMENT on every dashboard.
So:
- CONTEXT_GURU_LLM_TIMEOUT (Go duration; bare integers are seconds) now sets the
budget, defaulting to 90s. Fail-open behaviour is unchanged; what changes is
that a loaded server gets to answer.
- llm_timeouts / llm_errors / llm_call_timeout_ms are served at /stats, merged by
the host with the same layering as the Frozen* counters. A non-zero timeout
count means this arm's savings are an UNDERCOUNT, not a measurement. The budget
travels with the counts because a timeout total is meaningless without it.
- The counters are recorded from ctx.Err(), INDEPENDENTLY of whether a result came
back: RunExtractionSummary returns ("","","none") for every failure mode, and in
`code` mode the deterministic fallback can still shrink an output whose LLM leg
timed out. Counting only in an else-branch would therefore record nothing in
exactly the case that matters.
And one interaction with rossoctl#28's economic gate, which is why this could not be a
straight bump of the constant: a timed-out call with no result is no longer fed to
the ratio tracker. Counting it as ratio 0 means "the model could not shrink this
output", but a deadline is evidence about server latency, not compressibility.
minRatioSampleTokens is 1500, so ONE timed-out medium output both ends that
session's exploration and starts pulling ratio() below the 0.12 prior; a few more
and evaluateGate suppresses every call. The tracker lives on the Pipeline for the
proxy's lifetime, so nothing revises it — the self-justifying prior that
extract_econ.go's exploration budget exists to prevent, re-entered through the
timeout path. Timeouts still brake exploration via slowCallMs, which is the layer
that decides BEFORE spending the wall clock.
This is a live regime: 13 timeouts in one 50-task arm at the 90s budget on a
KV-pressured TP=1 server.
Tests pin both halves of the contract (fail-open preserved AND the abandoned call
counted), the tracker guard, and the env parsing; each is built through
newExtractLLM rather than a struct literal, so rossoctl#28's per-session maps are
initialized as in production. Verified the tracker test fails without the guard
(total=715 of poisoned evidence from a single timeout). The three new /stats keys
are registered in statsGoldenTopLevel.
Assisted-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Signed-off-by: Itay-Nakash <itay.nakash@ibm.com>
OsherElhadad
approved these changes
Aug 12, 2026
OsherElhadad
pushed a commit
that referenced
this pull request
Aug 13, 2026
…calls it abandons (#65) #64 did this for extract_llm and left summarize on a hardcoded `summarizeCallTimeout = 150 * time.Second`. That 150s was sized against an IDLE server, and the 10x asymmetry with extract_llm's old 15s hid the fact that it has the same failure mode: on a loaded self-hosted backend the deadline can expire before the model answers, and the operator has no knob and no counter to see it. Two things make summarize's budget the harder of the two to size, and they ADD: - queue wait, which is what a loaded server actually charges: p50 17.2s / p95 78.8s measured under KV-cache pressure, before the model starts work at all; - this component's own prefill, which is large by construction. Measured over one 50-task SWE-bench arm: 78,155,276 input tokens across 1,372 calls, i.e. ~57k prompt tokens per call, because it summarizes the whole middle of the transcript. The same arm spent 26,890,609 ms on those calls — a 19.6s mean, so the idle-server figure measured only the third of those three terms. So: - CONTEXT_GURU_SUMMARIZE_TIMEOUT (Go duration; bare integers are seconds) now sets the budget, defaulting to 300s. It is deliberately SEPARATE from CONTEXT_GURU_LLM_TIMEOUT: the two components send requests that differ in size by ~20x, so a single ceiling is either generous for one or tight for the other. - summarize_timeouts / summarize_errors / summarize_call_timeout_ms are served at /stats, merged by the host with the same layering as the LLM* and Frozen* counters, and registered in the /stats golden contract. - The timeout is distinguished from a transport error. summarize's fail path is louder than extract_llm's — it returns the error and the pipeline reverts the component, which shows up as a per-component `reverted` count — but `reverted` cannot say WHY, and the two causes call for opposite responses: a blown deadline means the budget is too small for this load (savings are an undercount), while a model error means the compaction route is broken (the arm is not measuring summarization at all). - The retry loop now stops once the shared deadline has expired. The ctx is built by the caller, OUTSIDE the loop, so all three attempts share one deadline: past it, each retry failed instantly and only obscured the cause. This also documents that the worst case is one budget, not three. The env parsing is extracted to resolveTimeoutEnv and shared with extract_llm rather than duplicated. A value accepted by one component and silently ignored by the other would be invisible in a run and would look like the component not firing. Fail-open behaviour is unchanged throughout: a summarize that cannot summarize must leave the request valid. What changes is that a loaded server gets time to answer, and that giving up is now countable. Tested: a slow model that always exhausts the deadline is counted as a timeout and not as an error, and the message list is left intact on the error path (summarize is the one component that changes the message COUNT, so a partial rebuild would hand the caller a transcript with no summary in it). Plus a table test for the shared parser: bare integers, Go durations, and fallback on zero/negative/garbage. Assisted-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Signed-off-by: Itay-Nakash <itay.nakash@ibm.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
llmCallTimeout was a hardcoded 15s bound on a single extract model call. That
constant was a CLIENT-SIDE assumption about SERVER latency, and on a shared
on-prem GPU it was wrong by a factor of five.
Measured on an on-prem vLLM under KV-cache pressure: server-side queue wait alone
was p50 17.2s / p95 78.8s. The old ceiling therefore expired BEFORE THE MODEL EVEN
STARTED on more than half of all calls. Observed over one 50-task SWE-bench arm at
equal request volume:
8.2x fewer calls at 5% FEWER requests, while per-request overhead ROSE 55%. The
component was starting calls, blocking, hitting the ceiling, and discarding the
work. And because it fails open silently, the arm degraded into a partial no-op
that READ AS AN IMPROVEMENT on every dashboard: its apparent time penalty shrank
by 42 points. That is the failure this PR is about -- not the latency itself, but
that the latency was unmeasurable.
Three changes.
The budget is configurable and defaults to 90s.
CONTEXT_GURU_LLM_TIMEOUT=90s (Go duration; bare integers are seconds)
Invalid, zero and negative values fall back to the default, because a zero budget
would disable compaction entirely. Fail-open behaviour is unchanged; what changes
is that a loaded server gets to answer. This is a per-call CEILING, not a target:
raising it trades "silently does nothing" for "measurably costs latency", which is
the correct trade, because the cost then shows up in the numbers instead of
hiding.
llm_call_timeout_ms are served at /stats, merged by the host with the same
layering as the existing FrozenStats counters (the deadline lives in the component
package, so metrics does not need to depend on components/offload). A non-zero
timeout count means this arm's savings are an UNDERCOUNT rather than a
measurement. The configured budget travels with the counts because a timeout total
is meaningless without the ceiling it was measured against. All three are additive
and registered in statsGoldenTopLevel, so the /stats contract test still passes
and deploy/harbor/*.py keeps parsing the payload unchanged.
The counters read ctx.Err() INDEPENDENTLY of whether a result came back, which is
deliberate and slightly counterintuitive. RunExtractionSummary returns
("", "", "none") for every failure mode alike, so timeout, sandbox rejection and
"nothing shrank" are indistinguishable in its return value; our own ctx is the one
reliable signal. And in
codemode the deterministic strategy runs as a fallback,so a call whose LLM leg timed out can still return a smaller result -- an
else-branch would record nothing in exactly that case, which is the shape of the
bug the counter exists to expose. Confirmed in the test fixture: the timed-out
call still shrank its output 10,200 -> 4,064 chars via the fallback.
is the only behavioural change, and it is why this could not be a straight bump of
the constant.
The gate learns this workload's compression ratio from outcomes and, per its own
comment, counts a call that produced nothing as ratio 0 so that "a model that
keeps failing to reduce this workload's outputs should drive the estimate down".
That is right for a miss. A deadline is not the model failing to reduce anything --
the call never completed -- so it is evidence about server latency, not
compressibility. Feeding it in shuts the gate on precisely the deployment whose
budget was already too small. Measured with the tracker and evaluateGate
unmodified, at a 3,000-token output, $0.005/call, non-caching backend:
ONE timed-out output flips the gate off. Two mechanisms compound: ratio() decays
toward zero, and minRatioSampleTokens is only 1500, so that same single timeout
also pushes r.total past the sample floor -- after which exploring() returns false
and the bounded exploration budget that exists to stop a pessimistic prior
justifying itself is gone. The tracker lives on the Pipeline for the proxy's
lifetime, so nothing revises it afterwards. This is the self-justifying prior
extract_econ.go was written to prevent, re-entered through the timeout path.
Real misses still record ratio 0, so the learning behaviour is intact for the case
it was written for. A timeout whose deterministic fallback DID shrink the output
still records a real observation, because that is genuine evidence. And timeouts
still brake speculative calls through slowCallMs, which is the layer designed for
"the server is slow, stop spending wall clock" and which decides BEFORE paying the
latency rather than after. The distinction that matters: the ratio gates EVERY
call, while slowCallMs gates only exploration, so poisoning the ratio is the
strictly more damaging path.
This is a live regime, not a hypothetical: 13 timeouts in one 50-task arm at the
90s budget on a KV-pressured TP=1 server.
Tests pin both halves of the fail-open contract (the request stays valid AND the
abandoned call is counted), the tracker guard, and the env parsing including that
the default can never return to 15s. Each builds the component through
newExtractLLM rather than a struct literal, because #28 added maps that only the
constructor initializes -- a literal panics with "assignment to entry in nil map"
as soon as per-session size tracking runs. The tracker test was verified to fail
without the guard: total=715 of poisoned evidence from a single timeout. The
fixture deliberately sits under sampleChars so the deterministic fallback cannot
reduce it, which is the only way to reach the "timed out with nothing back"
branch; it skips rather than passes vacuously if that ever stops holding.
What to scrutinise: change 3 alters logic added three commits ago in #51, so it
deserves more review than the rest of this PR. One residual issue I did not touch
-- ExtractionAvgLatencyMs is a cumulative process-wide mean, so after a long slow
period exploration stays braked for a while even once the server recovers. Same
"no fast recovery" shape one layer down, but it only suppresses speculative calls
rather than all of them.