Skip to content

REQUEST_TIMEOUT of 300s silently censored the cortex's output distribution — two turns lost and scored as wrong answers (was: a contention claim, now corrected) #41

Description

@OriNachum

Rewritten 2026-08-01. The original premise of this issue was wrong, and
the correction is the most useful thing in it — see
What this issue used to say at the bottom. The
title and body above it now describe what was actually measured.

The finding

WorkerSeam.REQUEST_TIMEOUT was 300 s, and one clean cortex generation on
these problems takes 175–290 s. The margin was under 1.1×, so any turn that
thought a little longer than usual was cut mid-generation, re-run from the top,
and — after four attempts — thrown away.

Every one of those calls recorded truncated: false. The turn was not lost to
the network and not to the token budget. It was lost to a clock that nothing
reports.

The measurement

Cell C1-E — arm E, rung C1, the easiest rung — ran all six pre-registered
repetitions. Ten calls, eight of which produced tokens:

rep seconds completion tokens retries finish_reason generation s tok/s
0 588.8 6,110 1 tool_calls 268.8 22.7
0 175.7 4,463 0 tool_calls 175.7 25.4
1 1,260.4 0 4 transport_failure
2 881.2 5,436 2 tool_calls 241.2 22.5
2 222.3 5,100 0 tool_calls 222.3 22.9
3 1,248.3 6,185 3 tool_calls 288.3 21.5
3 286.7 6,372 0 tool_calls 286.7 22.2
4 1,260.3 0 4 transport_failure
5 267.0 6,209 0 tool_calls 267.0 23.3
5 147.0 3,741 0 tool_calls 147.0 25.4

generation s removes the retry overhead each row's own retries count
implies: n × (300 s timeout + 20 s backoff) for a call that eventually
succeeded, n × 300 + (n−1) × 20 for the two that did not.

Two things fall straight out.

The generation rate is constant — 21.5 to 25.4 tok/s, a 1.19× spread across
ten calls whose wall clock spans 147 s to 1,260 s. The residual variation
tracks completion length (3,741 tokens at 25.4 tok/s, 6,372 at 22.2), which is
ordinary decode slowdown as the KV cache grows.

Both exhausted calls land on the retry arithmetic exactly.
4 × 300 + 3 × 20 = 1260.0 s, against 1260.4 and 1260.3 observed. To a
few tenths of a second, on two independent calls.

Three consequences, in ascending order of seriousness

1. Cost. The cell spent 105.6 minutes of wall clock to produce 41 minutes
of generation. Raising the timeout alone recovers 2.6×.

2. The output distribution is censored, and the censoring is invisible.
300 s at 23.2 tok/s is ~6,975 tokens. The eight successful completions run
3,741–6,372 tokens — every one under that ceiling, because the ones above it
could not be recorded
. A histogram of these completions describes the timeout,
not the model. This applies retroactively to every live measurement this repo
has taken through this seam, including the four capability probes.

3. Two answers were lost and scored as wrong. Repetitions 1 and 4 both
returned verdict: NO ANSWER, is_correct: false, exit_reason: aborted. Arm
E reads 4 of 6 where the model answered correctly on every repetition it
was allowed to finish — 4 of 4.

(3) is the reason this is a defect and not a tuning note. The timeout was not
merely inflating the cost axis; it was corrupting the correctness axis, in
the direction of understating whichever arm thinks longest — which is the exact
comparison the series exists to make. It falsified a pre-registered prediction
(P2) on the instrument's behalf.

The fix

Raised to 1200 s, derived rather than chosen:

REQUEST_TIMEOUT >= max_tokens / slowest_measured_rate
                =  16000       / 21.5 tok/s
                =  744 s

The point of the bound: the token budget must be the binding constraint,
because the budget is the one that reports itself.
Above 744 s, a turn that
exhausts its budget arrives as finish_reason == "length" — visible, already
handled as an instrument event, already predicted by P1. Below it, the same
turn arrives as a retry and nothing downstream can tell it happened.

This is the same shape as
#37 (ModelResponse
carries no finish_reason, so a truncated turn and a deliberate one arrive at
the loop as the same object) and the same reason d16 raised the token budget
rather than trusting a silent cut.

300 s was also this repository's outlier, in front of its slowest model:

harness REQUEST_TIMEOUT
league_h2h.py 1800 s
league_commander.py 900 s
devague_legs.py 600 s
worker_seam.py 300 s → now 1200 s

The pre-registration pre-committed the raise — §14: "If timeouts appear at
all, the timeout is raised and the write-up says so, exactly as
league-h2h raised its token budget rather than scoring the truncated turn."

Recorded as amendment 1 (appended and dated, never edited into the sections
above it) and deviation d4. C1-E's six repetitions are preserved verbatim
as C1-E-at-300s.jsonl and the cell is re-run at the corrected value.

What to carry forward

  • A client timeout in front of a thinking model is a silent sampling filter.
    Size it from max_tokens / measured_rate, not from a latency percentile —
    especially not one measured on an easier task.
  • Record retries in every results table. It is already on the call record
    and it is the cheapest contention-or-clock detector available.
  • ss -tnp | grep :8001 before a timed run, and record what was connected
    in the run's config artifact — the discipline configurations.md exists for,
    applied to the environment rather than to sampling parameters. That check is
    what disproved this issue's original premise.

What this issue used to say

It claimed the cortex was contended by reachy behavior engine run (pid
3267, four days up), that the effective rate was 5.0–25.4 tok/s "driven by
whether a neighbour happened to be dialling", and that no uncontended
baseline exists
. All three are wrong.

The connection was real; the inference was not. reachy's LLM edge is pinned
in ~/.config/environment.d/10-reachy-llm.conf:

REACHY_OPENAI_MODEL_ID=coolthor/gemma-4-12B-it-NVFP4A16

It dials senses, not the cortex — and the file's own commented-out
alternative names the previous cortex model id, so it was moved off the
cortex before the upgrade and never moved back. Its other two edges are a
/v1/realtime transcriber (STT) and a vision path reachable only from agent
attach, not from the runtime. None of them touch the cortex. (Confirmed by
reachy's maintainer against the live unit files, then verified here against the
config and ss.)

The "Running: 2 reqs" observed in the vLLM log is the cortex server's own
--max-num-seqs=2 cap, visible in its ps line — not evidence of a second
tenant.

The "5.0–25.4 tok/s, a 5× spread" figure was wall clock including retry
overhead, divided by tokens
. It is an artifact of the defect described above,
not a measurement of throughput. Corrected for retries, the rate never left a
1.19× band.

Three errors are worth naming explicitly, because the third is the expensive
one:

  1. "The series is running cells in parallel." It is not — one driver, one
    cell at a time. Asserted from a subagent's phrase "two-request
    contention"
    , without reading its output.
  2. "wall_clock_s is None, so the cost axis may not be capturing
    anything."
    Wrong — the field is seconds and is populated on every call.
    The schema was never checked.
  3. "The subagent may be mistaken." It was not. Its own results document
    already recorded the reachy process, its pid, its uptime and the vLLM line,
    before any of this was relayed. Its diagnosis of contention was wrong, but
    so was mine, and its observations were sound and already written down. The
    error was relaying a summary of work without reading the work.

The operator caught (1) and (2) by asking whether the code had actually been
read — it had not — and (3) by asking reachy's maintainer instead of accepting
the inference.

The transferable lesson, which is why the wrong version is kept here rather
than deleted:
an environmental explanation is the most comfortable kind of
finding, because it blames nothing you own. That is exactly why it needs the
same evidentiary bar as any other claim. A four-day-old connection to the right
port is not a measurement of what it dials, and "the environment was noisy"
should be the hypothesis you try hardest to kill — here, one constant rate and
one exact arithmetic identity killed it, and the real defect was in our own
harness the whole time.

  • embodiment (Claude)

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions