Skip to content

test(voice): judge first audio by chunks released, not a wall-clock race (#16407) - #16420

Merged
mrveiss merged 1 commit into
mainfrom
issue-16407-voice-latency-signal
Sep 13, 2026
Merged

mrveiss merged 1 commit into
mainfrom
issue-16407-voice-latency-signal

Conversation

@mrveiss

@mrveiss mrveiss commented Sep 12, 2026 •

Copy link
Copy Markdown
Owner

Refs #16407 (AC2 delivered; AC1, the CI-history question, is still open, see the issue)

Thinking Path

  • test_streaming_synthesize_reaches_first_audio_far_sooner failed on shard 8 of fix(ci): let the system-package retry recover from its own timeout, and fetch before unpacking (#15515) #16367: streaming time-to-first-audio was 1.238s, against 0.522s for blocking.
  • Only one assertion there can flake: the upper bound streaming_ttfb < blocking_ttfb / 2, a limit on wall time on a shared runner. The blocking check is a lower bound on an asyncio.sleep, and a sleep never finishes early.
  • 1.238s is more than twice the whole simulated utterance (0.5s). Buffering doesn't explain it either: a route that buffered everything would read about 0.5s. Before its first yield, the streaming path does a mocked request, one 0.1s paced read and a WAV parse. Something delayed the event loop on that runner, and I could not determine what.
  • The fake worker already offers a signal that doesn't depend on load. _PacedStreamReader releases a chunk only when the route pulls one. When the first audio byte leaves, a streaming route has pulled exactly 1 chunk. The perf(voice): 4.7-10.1s to first audio — the voice path uses blocking /tts/synthesize while the streaming route sits unused #13215 defect, buffering the whole utterance, has pulled all CHUNK_COUNT.

What Changed

Only autobot-backend/api/voice_latency_test.py:

  • _PacedStreamReader.released. _make_worker_http_client keeps each stream-route reader on client.stream_readers, read through _stream_progress(http_client).
  • _time_to_first_byte samples an optional progress callable on each ASGI send and returns its value at the first body byte.
  • test_streaming_synthesize_reaches_first_audio_far_sooner becomes test_streaming_synthesize_sends_first_audio_after_the_first_chunk. It asserts released == 1 instead of the wall-clock ratio. The blocking lower bound (>= 0.8 × SYNTH_SECONDS) stays.
  • New contrast test, test_a_route_that_buffers_the_utterance_is_caught. It patches api.voice._framed_audio_chunks with a version that drains the stream before yielding, and asserts released == CHUNK_COUNT. This shows the new signal catches the defect it guards against.

Verification

  • Not run locally: repo policy is not to run repository code, so CI's python-suite is the check. The file parses (AST), and ruff, black and isort are clean.
  • Traced by hand:
    • Streaming: synthesize_stream calls readexactly(4), which releases frame 0, then reads the rest from the buffer and yields. StreamingResponse sends it with progress at 1.
    • Buffering: the route drains all 5 frames, and the next readexactly ends the stream before the first send, so progress is 5.
  • AC1 (CI history): a sweep of recent failed python-suite shards for this test is running. The result will go on test(voice): voice_latency_test's streaming-vs-blocking TTFB race looks flaky under CI load (found triaging #16367) #16407.

Deliberately out of scope

  • .test_durations still keys the old test name. test-durations.yml regenerates that file, and pytest-split tolerates stale keys.
  • What stalled the event loop on that runner: I can't determine it from the code or the one log.

Model Used

Claude Opus 5 (claude-opus-5).

Single-issue rationale: a test-only fix to one voice-latency test; no other open issue shares this file or the voice test scope.

…ace (#16407)

The streaming-vs-blocking comparison put an upper bound on wall time, which
a loaded runner can exceed at any moment (streaming 1.238s vs blocking 0.522s
on shard 8 of #16367). The fake worker releases a chunk only when the route
pulls one, so the number released when the first audio byte leaves is 1 for a
streaming route and CHUNK_COUNT for the #13215 buffering defect, on any
machine. A contrast test pins the buffering case.
@coderabbitai

coderabbitai Bot commented Sep 12, 2026

Copy link
Copy Markdown
Contributor

Important

  • 🔍 Trigger review

This repository does not receive automatic reviews because it has fewer than 10 stars.

⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: ASSERTIVE

Plan: Advanced

Run ID: 795232e1-9c9a-43af-bac0-9f47b53fcad7


Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@github-actions

Copy link
Copy Markdown
Contributor

Notice: 29 open PRs — past the runaway threshold (25)

There is no PR queue limit, and this is not a request to defer this PR. Work proceeds one issue at a time without a cap on open PRs; review capacity is the constraint.

This notice only means the count is high enough to be worth a glance for a runaway — something opening PRs in a loop, or a merge pipeline that has stalled so nothing is draining.

Currently open:

If the queue is draining normally, ignore this. Otherwise:

  1. Check whether CI is dispatching at all — see the ci-dispatch-watchdog status on these PRs
  2. Merge the ones whose CI has finished and review has passed: gh pr merge <number> --squash --delete-branch
  3. Look for a loop opening near-identical PRs

Warn-only runaway detector — .github/workflows/pr-queue-gate.yml. It never blocks a merge.

@github-actions

Copy link
Copy Markdown
Contributor

✅ SSOT Configuration Compliance: Passing

🎉 No new hardcoded values of either class — ssot and other both block.

Known backlog in pipeline-scripts/hardcoded_values_baseline.txt is suppressed and tracked in #14371.

@mrveiss

mrveiss commented Sep 12, 2026

Copy link
Copy Markdown
Owner Author

Code review of b878e8c2b: APPROVE, no defects. It was traced against the code, not just the diff.

  • released == 1 is guaranteed, not incidental.
    • StreamingResponse.stream_response sends straight from async for chunk in body_iterator and never reads ahead.
    • The chain _framed_audio_chunks → stream_or_synthesize → synthesize_stream is sequential async generators, with no create_task or start_soon anywhere.
    • readexactly(4) releases frame 0. The next readexactly(20) is served from the buffer.
    • _SynthesisThroughput.start()/observe() are synchronous, so there is no extra suspension before the first send.
    • So the count can't be 0 or 2.
  • The contrast test exercises the patch. _synthesized_audio_response looks up _framed_audio_chunks as a module global each time it's called. _buffered calls the test module's own import-time binding, which is the original, so it can't recurse.
  • The main test catches perf(voice): 4.7-10.1s to first audio — the voice path uses blocking /tts/synthesize while the streaming route sits unused #13215. A buffering route releases all 5 frames before the first send, so released == 1 fails.
  • The remaining wall-clock check can't flake. blocking_ttfb >= 0.8 × SYNTH_SECONDS is a lower bound on asyncio.sleep, which never returns early.
  • Every caller of _time_to_first_byte was updated for the 3-tuple return; there are no callers outside this file.

The nits (the bare list annotation, two pre-existing truthiness asserts) need no action.

@mrveiss mrveiss added this to the v0.9.0 milestone Sep 12, 2026
@mrveiss mrveiss self-assigned this Sep 12, 2026
@mrveiss
mrveiss merged commit 5c17a4f into main Sep 13, 2026
89 of 90 checks passed
@mrveiss
mrveiss deleted the issue-16407-voice-latency-signal branch September 13, 2026 13:36
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant