Skip to content

Measure socket swaps and reply after a handoff - #511

Merged
jserv merged 5 commits into
mainfrom
rotation-metrics
Oct 26, 2026
Merged

jserv merged 5 commits into
mainfrom
rotation-metrics

Conversation

@jserv

@jserv jserv commented Oct 26, 2026 •

Copy link
Copy Markdown
Contributor

Gemini closes a Live socket about every ten minutes, so a long interview swaps sockets several times, and nothing in the agent log said how long the candidate waited for the interviewer after a swap, whether the swap kept the conversation, or why the socket was replaced. The browser-check soak that judges a handover also decided too much from too little: it called a locally rebuilt conversation "lost" from the text of a notice, let any earlier recovery stand in for the rotation under test, and counted the looped microphone's own turns as the interviewer going on. This change measures and explains each replacement, makes the soak judge from those facts, and fixes one wait the measurements exposed: a replacement after a speech handoff that stayed silent until the reply watchdog replaced it again.

Improvements

Each replacement now logs rotation_gap_ms (handling the close to the new socket finishing setup), trigger (watchdog, close or goaway), handover (resumed, cold_handoff or degraded) and fallback (why it did not resume), and replacement first audio: follows with the time to the first reply audio when the briefing asked for one. None of this was logged on main. What it reads on real replacements, from four live soaks of this branch (BROWSER_CHECK_FLOW=soak BROWSER_CHECK_AGENT=rust, one machine, one Gemini project):

Run At trigger handover fallback rotation_gap_ms First audio from setup (ms) First audio from start (ms)
A 9:03.6 goaway cold_handoff checkpoint_before_handoff 479 no line (a handoff asks for no reply) -
A 9:15.1 watchdog resumed none 682 639 1321
B 7:39.1 watchdog resumed none 672 1851 2523
C 9:11.5 goaway resumed none 660 no line -
D 1:03.0 watchdog resumed none 638 no line -
D 1:18.8 watchdog degraded resume_suppressed 389 22120 (candidate first heard at 7672 from start) 22509
D 2:04.8 watchdog degraded resume_suppressed 425 no line -

Setup took 389 to 682 ms across the seven. The waits that matter to a candidate were the reply timeouts that preceded the watchdog rows and, in run D, a 22 s wait for a locally rebuilt socket to speak, none of which were visible before.

A speech handoff (a GoAway while the candidate is speaking) tells the replacement to keep listening and answer after their remaining audio. That note requests no reply, so a candidate who had already finished left the new socket nothing to answer: in each of the three cold handoffs seen before the fix (two logged in the table below) it stayed silent until the reply watchdog replaced it again. Sending the note the way the agent does, followed by silence, got no reply in 16 s in two of two probes; a turn-completing request three seconds later got one in under a second. The replacement is now asked once for the reply when neither the provider nor the microphone has heard the candidate for the silence window plus 2.5 s and it has produced nothing. Measured on live soaks, from the handoff replacement to the first audio the candidate heard:

Run Handoff replacement at Reply requested at First audio at Handoff to first audio Second swap
Before, run 1 9:01.5 none 9:13.7 12.2 s yes, reply watchdog at 9:13.1
Before, run 2 9:03.6 none 9:15.8 12.2 s yes, reply watchdog at 9:15.1
After, run 3 9:01.3 9:06.4 9:07.2 5.9 s no
After, run 4 9:01.3 9:06.5 9:07.1 5.9 s no
After, run 5 (a handoff that resumed) 9:01.6 9:06.4 9:07.3 5.6 s no

The reply came about 0.7 s after the request in each of the three. The request is one extra provider message per speech handoff whose replacement stayed silent through the wait, and none when it answers earlier; the contract change is in docs/provider-cost-and-degradation.md. It keeps the request the socket still owed and holds its deadline to the recovery minimum, so a request that is also ignored still ends in the watchdog.

The soak (scripts/soak-judge.cjs) now judges from those fields for its own room. The same captured agent log replayed through the old rules (as on main, applied to the log text) and through the new judge:

Captured log Old rules New judge
Run C: one GoAway handover, no stall pass pass
Run D: three reply timeouts in two minutes, two rebuilt from local state FAIL on the 1:18.8 rebuild, "the conversation was lost" tolerates the 1:18.8 rebuild, FAIL on the 2:04.8 one, "2 rebuilds from local state after reply timeouts"

The outcome of whole soak runs:

Build Soaks Exit 0 Exit 1 Exit 77
main (6b7e2b06) 2 1 1: "no transport restart was requested" n/a
This branch, final judge 9, the last five with the handoff reply 6 1: two rebuilds after reply timeouts (run D) 2: no GoAway in 660 s

The same condition, Gemini sending no GoAway in the window, failed a main soak with exit 1 and is now exit 77, an inconclusive result.

Rules that the live runs did not exercise, each pinned by a test in tests/browser/soak-judge.test.js (before, then after): an earlier watchdog resume followed by a GoAway that is never acted on passed and now fails; an interviewer that stays silent while the looped microphone adds candidate turns passed and now fails, because only the interviewer's transcript rows count; another room's lines in the same log were matched and are now filtered by room; a rebuild from local state on a close or a GoAway with no handle failed without a reason and now names the trigger and reason; a passing run left nothing to read and now prints the replacement lines it saw. The young-socket log line now says what happened instead of claiming the resume failed, and the notices end with room=.

The fake microphone clip needs at least two seconds of trailing silence, since Gemini ends an utterance after 1500 ms of quiet; the note is in scripts/browser-check.sh.

Limitations

  • The agent change is limited to the wait after a speech handoff. A reply that stalls on an ordinary socket still costs the reply timeout and a swap, and a locally rebuilt socket can still take long to speak (22 s in run D).
  • The soak still depends on the provider. Gemini may send no GoAway inside the 660 s window (exit 77, a result a runner has to read as inconclusive, not as a pass), and a second reply stall in one run fails it.
  • The post-handover check measures from the last Jim count taken before the rotation was read, so a turn Jim took in the tick before it (up to 15 s) counts as growth. The check is looser by that much.
  • replacement first audio: is left out for a replacement whose briefing asked for no reply (a speech handoff), when the wait outlived the longest reply timeout, and when a hold, a later prompt, a turn without audio or a newer socket makes the next audio answer something else. It measures to queued audio, not to what the browser plays, and does not include the stall that preceded the swap.
  • The trigger passed at each of the five replacement call sites, the point that arms the handoff wait and the tick that sends the request have no unit test, since they sit in the async room loop. The decision, the cancellation and the send helper are unit-tested, and the soak is the only thing that exercises the rest.
  • With a silence window past about seven seconds, the reply timeout counts from the handoff and comes first, so the request never lands there and the second swap remains. The default window is 1.5 s.
  • Live evidence is small: nine soaks of the final judge, two of main, and three handoff replies, on one machine and one Gemini project. A speech handoff only happens when a GoAway lands while the candidate is speaking, so most soaks contain none. Reply stalls dominate the variation between runs, so the tables show what was measured, not a rate.

Left out and scope

  • Opening a second socket before the first closes. A direct probe showed a resumption handle works while the first socket stays open, but the saving is the setup time, against a stale handle losing later turns.
  • The second commit adds a test that a refused audio flush keeps its bytes for the replacement socket. It is not about timing; say if you would rather it go in its own PR.

Validation

  • ./scripts/test.sh exits 0 on the final head, rebased on current main. Not checked by it: desktop clippy (no libwebkit2gtk-4.1-dev) and cargo-deny.
  • The judge has 16 Node tests; each rule was mutated and a test failed. The Rust tests pin the fallback and handover table, the field format and the notice texts.
  • BROWSER_CHECK_FLOW=soak BROWSER_CHECK_AGENT=rust scripts/browser-check.sh against a real interview, with the logs replayed as shown in the tables above. Before the judge was rewritten, three soaks of the timing-lines head passed twice and failed once, on a rebuild after a reply stall.
  • Outside reviews by two other models of the soak commit found seven issues in the judge and the soak flow, and of the handoff commit found three and five more (a request that could cut off a candidate still inside the model's window, a lost recovery deadline, an overwritten owed request, arming after a failed note); all are fixed here except the long-silence limit above, which is documented.

jserv added 5 commits October 26, 2026 20:46
Gemini closes a Live socket about every ten minutes, so a long
interview swaps sockets several times. Nothing in the agent log said
how long the candidate waited for the interviewer after a swap, or
whether the swap kept the conversation, so the handover could not be
judged except by listening.

The replacement: line now carries rotation_gap_ms, from handling the
close to the new socket finishing setup. A new "replacement first
audio:" line follows when the briefing asked for a reply, with the time
from the start and from setup, and how long after the start the
candidate was first heard, since audio that follows their speech may
answer them and not the briefing. The watch is dropped when a hold, a
later prompt, a turn without audio or a newer socket makes the next
audio answer something else, and a wait longer than the longest reply
timeout goes unlogged rather than misreported.

The notice that says how a socket came up is now three texts. A
candidate speaking at the GoAway with no checkpoint after their speech
is rebuilt locally on purpose, because resuming from an older
checkpoint can replay a cancelled reply; it no longer reads as a
degraded restart. A handle that was refused, missing or suppressed
still does. Each notice ends with the room. The soak accepts a resumed
or locally rebuilt handover and fails only on the degraded one.

The soak also needed a fake microphone clip with at least two seconds
of trailing silence: Gemini ends an utterance after 1500 ms of quiet,
so a clip that never goes quiet keeps the candidate talking and the
interviewer silent for the whole run.
The audio sent to a replacement socket is cleared only after the write
succeeds, so a flush the dead socket refused must leave the buffered
PCM for the next one. Nothing asserted that, and a change that cleared
the buffer before the send would drop the candidate's words across a
swap without failing any test.

Refuse a flush with a failing sink, check that the bytes are still
queued, then flush them to a replacement and check it receives them and
the buffer empties.
A passing soak said only that a handover happened. The replacement and
replacement first audio lines the agent logs were not kept on a pass,
so the timing they report could not be read from a run, and a handover
that was slow to speak looked the same as a quick one.

Print each such line once as the soak sees it. The agent output is a
rolling window, so the lines are taken on every tick rather than at the
end. The first audio line is not required: it is left out on purpose
when the briefing asked for no reply or its wait is no longer the
replacement's, and a soak that failed on its absence would fail runs
that handed over correctly.
The soak decided that a conversation was lost from the text of a
notice, and that a handover happened from the first replacement of any
kind. A reply timeout that rebuilt the interviewer from local state
failed it as a lost conversation, an earlier recovery could stand in for
the rotation under test, and the looped microphone clip added candidate
turns, so the post-handover check passed with the interviewer silent.

The replacement line now carries why the socket was replaced (reply
watchdog, server hang-up, or a GoAway acted on), whether it resumed, was
rebuilt on purpose after a speech handoff, or degraded, and the reason
it did not resume. The soak reads those fields for its own room. A
GoAway followed by a resumed or designed cold handover passes. A rebuild
from local state on any other cause fails and names it. One rebuild
after a reply timeout is allowed and reported when the replaced socket
had offered no handle or was itself a young resumed one, since a
provider that does not answer an utterance is not the rotation under
test; a second one fails, and so does one whose handle was refused.
Only the interviewer's rows in the transcript count as having gone on,
measured from the last count taken before the rotation was read.

A run in which Gemini sends no GoAway tested nothing about rotation, so
it exits 77 instead of passing or failing. The log line for a young
resumed socket that is replaced again now says that, instead of
claiming the resume failed.
A speech handoff tells the replacement to keep listening and answer
after the candidate's remaining audio. That note adds to the
conversation without requesting output, so when the candidate had
already finished, the replacement was sent nothing it would answer.
It stayed silent until the reply watchdog gave up on it, and the
interview paid for a second socket swap and the wait before it.

Once neither the provider nor the microphone has heard the candidate
for the silence window plus 2.5 seconds, and the replacement has
produced nothing, ask it once for the reply with a turn-completing
context message. The wait counts from the latest of the handoff, the
candidate's last voiced audio and the provider's end-of-speech edge, so
a candidate who is still inside the model's window is not cut off. The
request keeps whatever platform request the socket still owed and holds
its first-output deadline to the recovery minimum, so a request that is
also ignored still ends in the watchdog as before. Only a socket that
was told to keep listening and owes a reply is asked, and any output,
later prompt, completed turn, hold or newer socket cancels the wait.

The extra request is recorded in the provider cost and degradation
contract: one per speech handoff whose replacement stayed silent, none
when it answers earlier.
@jserv jserv changed the title Measure and judge Gemini socket replacements Measure socket swaps and reply after a handoff Oct 26, 2026
@jserv
jserv merged commit ef644be into main Oct 26, 2026
13 checks passed
@jserv
jserv deleted the rotation-metrics branch October 26, 2026 18:11
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant