Repository navigation
[Frontend][Benchmark] Add duplex performance metrics for OmniInteract and Omni-DuplexEval benchmark - #7242
Conversation
|
Codex usage limits have been reached for code reviews. Please check with the admins of this repo to increase the limits by adding credits. |
|
This PR appears to belong to: docs/design/module/benchmarking.md. Module owners: @alex-jw-brooks @Bounty-hunter @ZacheryAU, please review your own changes and leave a short self-review comment describing what you checked. PRs without author self-review may not be assigned a reviewer. Please take a look when you have a chance. If you would like an automated review, mention @vllm-omni-review-bot in a comment. |
hsliuustc0106
added
high priority
ZacheryAU
changed the title
| async def _run() -> bool: | ||
| nonlocal runtime_closed | ||
| try: | ||
| session.mark_model_turn_request_started(append_turn_id, time.monotonic()) |
There was a problem hiding this comment.
per-response ttf* start
| epoch=session.epoch, | ||
| ) | ||
| response_request_metrics = session.mark_response_first_outputs( | ||
| observed_at_s=time.monotonic(), |
There was a problem hiding this comment.
pre-response ttf* end
| and bool(event["delta"]) | ||
| and first_text_received_at_s is None | ||
| ): | ||
| first_text_received_at_s = received_at_s |
| delta = event.get("delta") or event.get("audio") | ||
| if not isinstance(delta, str) or not delta: | ||
| continue | ||
| audio_received_at_s.append(received_at_s) |
| session_from = 0 # the collector holds only this session's events | ||
| pcm = _ensure_final_commit_tail(pcm, client.events.events) | ||
| playback = _Playback() | ||
| stream_start = time.monotonic() |
There was a problem hiding this comment.
global_ttf* start
| await client.configure(model, ref_audio=_ref_audio(ref_audio), instructions="Streaming Omni Conversation.") | ||
| ack_task = asyncio.create_task(_ack_playback(client)) | ||
| try: | ||
| stream_start = time.monotonic() |
There was a problem hiding this comment.
global ttf* start
Signed-off-by: ZacheryAU <zachery.au@gmail.com> Co-authored-by: Ruirui Yang | Rein <73573651+R2-Y@users.noreply.github.com>
Signed-off-by: ZacheryAU <zachery.au@gmail.com>
Signed-off-by: ZacheryAU <zachery.au@gmail.com>
Signed-off-by: ZacheryAU <zachery.au@gmail.com>
Signed-off-by: ZacheryAU <zachery.au@gmail.com>
3ec242b to
67e8db9
Compare
amy-why-3459
left a comment
amy-why-3459
left a comment
There was a problem hiding this comment.
Reviewed commit 67e8db9 across all 18 changed files and the related call paths. I found two P2 issues, detailed inline, and recommend addressing them before merging. Both were reproduced with isolated minimal examples. All 40 duplex client tests passed under isolated loading; the full server-side suite and real-model end-to-end evaluation were not run.
| session_metrics = [result.session_metrics for result in results if result.session_metrics] | ||
| path = Path(response_root) / DUPLEX_METRICS_FILENAME | ||
| path.parent.mkdir(parents=True, exist_ok=True) | ||
| path.write_text( |
There was a problem hiding this comment.
[P2] Preserve existing performance metrics when resuming generation
Without --overwrite, generate_sample() returns a GenerateSampleResult with empty metrics for an already-generated sample, but this function unconditionally overwrites duplex_metrics.json using only the returned metrics. Running the same command twice therefore preserves the generated responses while erasing their performance metrics; a partial resume also drops metrics for previously completed samples. In a minimal reproduction, a non-empty report became {"duplex_request_metrics": [], "duplex_session_metrics": []} after skipping the existing sample and writing the report again. Please persist/reload per-sample metrics or merge existing records by (split, sample_id), and add regression coverage for both all-skipped and partially resumed runs.
| record["vllm_itl_ms"] = sum(itls_ms) / float(len(itls_ms)) | ||
| record["vllm_tpot_ms"] = _mean_time_per_output_token_ms(native_stats) | ||
| record["vllm_tpot_ms"] = ( | ||
| record["vllm_itl_ms"] if record["vllm_itls_ms"] else _mean_time_per_output_token_ms(native_stats) |
There was a problem hiding this comment.
[P2] Account for multiple tokens per engine output when computing TPOT
The ITL list above appends one interval per engine output, while new_token_ids can contain multiple tokens. Using the arithmetic mean of those intervals as TPOT is therefore only correct when each output contributes exactly one token. In an isolated reproduction with an existing first token followed 30 ms later by an output containing three new tokens, the previous token-count-based calculation gives 10 ms/token, while this code reports 30 ms/token. The changed finished-request path also avoids replacing this value whenever ITLs exist. Please calculate TPOT from elapsed time and the corresponding token count within continuous generation segments, excluding gaps between segments, and add a multi-token-output regression test. This change is in the shared output processor, so its effect extends beyond the duplex benchmark.
Signed-off-by: ZacheryAU <zachery.au@gmail.com>
…async-chunk path Implements item 8 of vllm-project#7389. Behind VLLM_OMNI_DUPLEX_FRAME_TIMING (off by default; VLLM_OMNI_DUPLEX_FRAME_TIMING_LOG_EVERY throttles per-event lines, emit one greppable DUPLEX_FRAME_TIMING log line per frame/chunk at five points of the duplex tick journey: - append (session runner): 80 ms frame reserved; inter-append jitter and input drift vs the tick budget - connector_put / connector_get (chunk transfer adapter): connector hop wrap times; same-process put->get handoff age, cross-process joins via key + monotonic t_ns stamps - stage1_decode (PersonaPlex Code2Wav): streaming Mimi decode time per request with the new-frame count - audio_emit (runtime bridge): audio delta projected; emit jitter and output drift vs the tick budget All stamps use time.monotonic_ns() — the same clock family as the client-side duplex timeline proposed in vllm-project#7242/vllm-project#7025 — and the tick period comes from the backend capabilities rather than a hard-coded constant. No control-flow, payload, or ordering changes; every hook is a no-op when the flag is unset. EOF )
…async-chunk path Implements item 8 of vllm-project#7389. Behind VLLM_OMNI_DUPLEX_FRAME_TIMING (off by default; VLLM_OMNI_DUPLEX_FRAME_TIMING_LOG_EVERY throttles per-event lines, emit one greppable DUPLEX_FRAME_TIMING log line per frame/chunk at five points of the duplex tick journey: - append (session runner): 80 ms frame reserved; inter-append jitter and input drift vs the tick budget - connector_put / connector_get (chunk transfer adapter): connector hop wrap times; same-process put->get handoff age, cross-process joins via key + monotonic t_ns stamps - stage1_decode (PersonaPlex Code2Wav): streaming Mimi decode time per request with the new-frame count - audio_emit (runtime bridge): audio delta projected; emit jitter and output drift vs the tick budget All stamps use time.monotonic_ns() — the same clock family as the client-side duplex timeline proposed in vllm-project#7242/vllm-project#7025 — and the tick period comes from the backend capabilities rather than a hard-coded constant. No control-flow, payload, or ordering changes; every hook is a no-op when the flag is unset. EOF )
…async-chunk path Implements item 8 of vllm-project#7389. Behind VLLM_OMNI_DUPLEX_FRAME_TIMING (off by default; VLLM_OMNI_DUPLEX_FRAME_TIMING_LOG_EVERY throttles per-event lines), emit one greppable DUPLEX_FRAME_TIMING log line per frame/chunk at five points of the duplex tick journey: - append (session runner): 80 ms frame reserved; inter-append jitter and input drift vs the tick budget - connector_put / connector_get (chunk transfer adapter): connector hop wrap times; same-process put->get handoff age, cross-process joins via key + monotonic t_ns stamps - stage1_decode (PersonaPlex Code2Wav): streaming Mimi decode time per request with the new-frame count - audio_emit (runtime bridge): audio delta projected; emit jitter and output drift vs the tick budget All stamps use time.monotonic_ns() - the same clock family as the client-side duplex timeline proposed in vllm-project#7242/vllm-project#7025 - and the tick period comes from the backend capabilities rather than a hard-coded constant. No control-flow, payload, or ordering changes; every hook is a no-op when the flag is unset. Signed-off-by: shihongzhi <shi65881583@gmail.com>
…o stream_* Signed-off-by: ZacheryAU <zachery.au@gmail.com>
Solved in 8beca59, @amy-why-3459 PTAL |
linyueqian
left a comment
linyueqian
left a comment
There was a problem hiding this comment.
Approving. Most of this is benchmark and client code, but the change in outputs/output_processor.py is the part that affects serving, so that is where I spent the review.
Making TPOT token-weighted is a real correctness fix rather than a presentation change. The previous code recomputed vllm_tpot_ms from the whole-request mean on every update, which is only equivalent to the per-step view when every decode step emits exactly one token. Duplex and chunked paths do not, so a step that emitted several tokens was being averaged as though it emitted one, and the reported TPOT drifted from what the engine actually did. _accumulate_segment_tpot weighting each step by its token count while leaving ITL at one sample per step is the right split: they answer different questions and should not be derived from each other.
The precedence between the three writers is consistent, which is the part most likely to go wrong. The whole-request mean is only used while no per-step samples exist, both in _update_stats_from_output and again at finish, so once weighted data is available nothing overwrites it with the coarser number. I did go looking for a bug here: elif not record["vllm_itls_ms"] indexes directly while the finish path uses .get() on the same key, which is the shape of a KeyError waiting for the first request that takes the fallback branch. It is safe, because _native_text_metric_record seeds vllm_itls_ms to an empty list when the record is created. Worth knowing that the direct index depends on that seeding.
Stripping the _tpot_elapsed_ms and _tpot_intervals accumulators in pop_native_text_metrics keeps the internal weighting state out of the reported payload, so consumers see only the derived value.
On the benchmark side, the thing worth calling out is _STREAM_MEASUREMENT_ORIGIN spelling out what each number measures, including that stream RTF "includes concurrent realtime input". Duplex numbers are easy to quote without that caveat and then compare against a non-duplex baseline that never had it.
CI: buildkite/vllm-omni green at this head. The informational lanes carry their standing reds, covered by ci_approval_override_head.
Validation: static review of the twenty-one-file author diff from the GitHub file list, the three TPOT write paths and their precedence, the record seeding in _native_text_metric_record, and the RTF derivation guards. Fork head, so the branch was not executed.
…ith vllm-project#7242/vllm-project#7025 Review follow-up for vllm-project#7453: the five site hooks now call dedicated log_*_event helpers in metrics/duplex_frame_timing.py, so gating, cadence state, and field building live in one durable module. The serving-side call sites (session runner, runtime bridge) are single calls, ready to move to the new session owner when the framework rework (vllm-project#7413) deletes their files. Name/clock alignment so the numbers line up with vllm-project#7242 / vllm-project#7025 once they land: period_ms -> tick_period_ms, duration_ms -> audio_duration_ms, handoff_ms -> chunk_age_ms, and a shared DEFAULT_TICK_PERIOD_MS (80 ms) replaces the disagreeing per-site fallbacks (1000 vs 80). All stamps stay time.monotonic_ns() - the same CLOCK_MONOTONIC origin as vllm-project#7242 stream_start / *_at_s instants; the mapping is documented in the module docstring. Signed-off-by: shihongzhi <shi65881583@gmail.com>
…st in vllm-project#7413 vllm-project#7413 rebuilt the duplex serving stack around engine-resident sessions and dropped the per-response request timing that vllm-project#7242 had added for the MiniCPM-o Omni-DuplexEval / OmniInteract benchmarks: the engine no longer emitted ``response_request_metrics``, so ``DuplexClient`` and the benchmark summaries silently fell back to the client's receive clock, and the TPOT weighting regressed to counting a one-token segment as one interval. Port the timing into the engine session: the model-turn request start is recorded when the model channel submits the append, the first text / audio of the response fix TTFT / TTFP, and the numbers ride response.created (under response.metadata.duplex_event) and every speak / audio delta (under metadata.vllm_omni), exactly where the client already reads them. Restore the interval-weighted TPOT mean. Re-home the MiniCPM-o plugin policy unit tests deleted with tests/engine/duplex/test_duplex_runtime.py, make the duplex e2e gate assert the server-side anchor, fix the pre-existing mypy errors in the two touched test files, and drop three doc passages that still describe the session-per-request chat adapter removed before vllm-project#7413 merged. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Signed-off-by: chickeyton <ngton2014@gmail.com>
… and Omni-DuplexEval benchmark (vllm-project#7242) Signed-off-by: Matthieu Laneuville <matthieu.laneuville@surf.nl>
… and Omni-DuplexEval benchmark (vllm-project#7242)
5 participants
Summary
Improve full-duplex performance metrics and surface them through
vllm bench serve --omni --dataset-name omniinteractandvllm bench omni-duplex-eval --omnifor native Realtime duplex sessions. Draw on ideas from #6042.What changed
mean_duplex_stream_*aggregates.Introduced metrics and definitions
Each request/session payload includes
measurement_origin(orstream_measurement_origin) describing the start/end of the corresponding value.Session means (
duplex_session_metrics)ttft_ms/ttfp_ms/rtf/tpot_msmean_tpot_msonly when positive TPOT samples exist).audio_turn_countSession stream window (
stream_*andmean_duplex_stream_*)Measured over the full OmniInteract input-stream window (not an average of per-response TTF*):
stream_ttft_msstream_ttfp_msstream_rtf(stream start → last audio receive) / total emitted audio duration, including concurrent realtime input.stream_audio_generation_ms/stream_audio_duration_msduplex_stream_ttft_ms/duplex_stream_ttfp_ms/duplex_stream_rtfNotes
max_output_tokens_per_s) may beNaNfor duplex sessions when a session-stream token timeline cannot be reconstructed; this is intentional.openai-realtime-ttsbackend changes are out of scope for this PR.Test Plan
vLLM Version:
0.29.0vLLM-Omni Commit: current commit on top of e540dfb
vllm bench serve --omni --dataset-name omniinteract --save-result --result-dir ~/ --result-filename omniinteract-metrics.jsonas well asvllm bench omni-duplex-eval --omni generateand see duplex metrics in output json filespython -m pytest -m 'core_model and cpu' tests/benchmarks/ tests/clients/test_duplex_client.py tests/e2e/online_serving/test_minicpmo_realtime_duplex_drivers.py tests/engine/test_output_processor.py tests/entrypoints/openai_api/test_duplex_handler.py tests/e2e/features/fullduplex/test_omni_duplex_eval_cli.py -qpytest -s -v tests/e2e/online_serving/test_minicpmo_4_5_duplex.py -m 'advanced_model and cuda' --run-level 'advanced_model'Test Result
duplex metrics in OmniInteract's json file
Show more
"duplex_session_metrics": [ { "session_id": "omniinteract:1q1a:bench-5eb902d6-0:868711023927840", "audio_turn_count": 13, "ttft_ms": { "count": 13, "mean": 547.801, "p50": 492.138, "p99": 968.235 }, "ttfp_ms": { "count": 13, "mean": 547.801, "p50": 492.138, "p99": 968.235 }, "rtf": { "count": 13, "mean": 0.976753, "p50": 0.96645, "p99": 1.427951 }, "tpot_ms": { "count": 13, "mean": 11.462, "p50": 10.976, "p99": 14.241 }, "stream_ttft_ms": 2692.873, "stream_ttfp_ms": 2692.866, "stream_rtf": 2.001713, "stream_audio_generation_ms": 151809.897, "stream_audio_duration_ms": 75840, "stream_measurement_origin": { "ttft": "input stream start to first non-empty text delta", "ttfp": "input stream start to first audio packet", "rtf": "input stream start-to-last-audio receive time divided by total emitted audio duration; includes concurrent realtime input" } }, { "session_id": "omniinteract:1q1a_math:bench-5eb902d6-1:868867447377069", "audio_turn_count": 14, "ttft_ms": { "count": 14, "mean": 574.871, "p50": 562.294, "p99": 991.494 }, "ttfp_ms": { "count": 14, "mean": 574.871, "p50": 562.294, "p99": 991.494 }, "rtf": { "count": 14, "mean": 0.905495, "p50": 0.92149, "p99": 1.692973 }, "tpot_ms": { "count": 13, "mean": 12.85, "p50": 11.9, "p99": 20.734 }, "stream_ttft_ms": 3069.068, "stream_ttfp_ms": 3069.051, "stream_rtf": 3.038951, "stream_audio_generation_ms": 279461.891, "stream_audio_duration_ms": 91960, "stream_measurement_origin": { "ttft": "input stream start to first non-empty text delta", "ttfp": "input stream start to first audio packet", "rtf": "input stream start-to-last-audio receive time divided by total emitted audio duration; includes concurrent realtime input" } }, { "session_id": "omniinteract:1q1a:bench-5eb902d6-2:869172431146001", "audio_turn_count": 14, "ttft_ms": { "count": 14, "mean": 390.68, "p50": 341.632, "p99": 811.194 }, "ttfp_ms": { "count": 14, "mean": 390.68, "p50": 341.632, "p99": 811.194 }, "rtf": { "count": 14, "mean": 0.87263, "p50": 0.869336, "p99": 1.36989 }, "tpot_ms": { "count": 14, "mean": 11.052, "p50": 10.742, "p99": 13.812 }, "stream_ttft_ms": 2612.752, "stream_ttfp_ms": 2612.745, "stream_rtf": 3.708184, "stream_audio_generation_ms": 161528.484, "stream_audio_duration_ms": 43560, "stream_measurement_origin": { "ttft": "input stream start to first non-empty text delta", "ttfp": "input stream start to first audio packet", "rtf": "input stream start-to-last-audio receive time divided by total emitted audio duration; includes concurrent realtime input" } } ], "duplex_stream_ttft_ms": { "count": 3, "mean": 2791.564, "p50": 2692.873, "p99": 3069.068 }, "duplex_stream_ttfp_ms": { "count": 3, "mean": 2791.554, "p50": 2692.866, "p99": 3069.051 }, "duplex_stream_rtf": { "count": 3, "mean": 2.916283, "p50": 3.038951, "p99": 3.708184 }duplex metrics in Omni-DuplexEval's json file
Show more
"duplex_session_metrics": [ { "sample_id": "560", "split": "RTD_OCR", "session_id": "560", "audio_turn_count": 6, "ttft_ms": { "count": 6, "mean": 534.093, "p50": 409.494, "p99": 924.225 }, "ttfp_ms": { "count": 6, "mean": 534.093, "p50": 409.494, "p99": 924.225 }, "rtf": { "count": 6, "mean": 0.739869, "p50": 0.702124, "p99": 1.188374 }, "tpot_ms": { "count": 5, "mean": 12.8, "p50": 10.235, "p99": 22.204 }, "stream_ttft_ms": 4433.793, "stream_ttfp_ms": 4433.705, "stream_rtf": 2.17538, "stream_audio_generation_ms": 22710.967, "stream_audio_duration_ms": 10440.0, "stream_measurement_origin": { "ttft": "input stream start to first non-empty text delta", "ttfp": "input stream start to first audio packet", "rtf": "input stream start-to-last-audio receive time divided by total emitted audio duration; includes concurrent realtime input" } }, { "sample_id": "561", "split": "RTD_OCR", "session_id": "561", "audio_turn_count": 2, "ttft_ms": { "count": 2, "mean": 909.971, "p50": 699.576, "p99": 1120.367 }, "ttfp_ms": { "count": 2, "mean": 909.971, "p50": 699.576, "p99": 1120.367 }, "rtf": { "count": 2, "mean": 1.022577, "p50": 0.92334, "p99": 1.121814 }, "tpot_ms": { "count": 1, "mean": 9.498, "p50": 9.498, "p99": 9.498 }, "stream_ttft_ms": 2579.53, "stream_ttfp_ms": 2579.511, "stream_rtf": 1.224425, "stream_audio_generation_ms": 23508.958, "stream_audio_duration_ms": 19200.0, "stream_measurement_origin": { "ttft": "input stream start to first non-empty text delta", "ttfp": "input stream start to first audio packet", "rtf": "input stream start-to-last-audio receive time divided by total emitted audio duration; includes concurrent realtime input" } }, { "sample_id": "562", "split": "RTD_OCR", "session_id": "562", "audio_turn_count": 4, "ttft_ms": { "count": 4, "mean": 223.012, "p50": 55.557, "p99": 419.301 }, "ttfp_ms": { "count": 4, "mean": 223.012, "p50": 55.557, "p99": 419.301 }, "rtf": { "count": 4, "mean": 0.899004, "p50": 0.825088, "p99": 1.185069 }, "tpot_ms": { "count": 4, "mean": 10.934, "p50": 10.654, "p99": 12.08 }, "stream_ttft_ms": 2767.268, "stream_ttfp_ms": 2767.243, "stream_rtf": 1.146916, "stream_audio_generation_ms": 40233.798, "stream_audio_duration_ms": 35080.0, "stream_measurement_origin": { "ttft": "input stream start to first non-empty text delta", "ttfp": "input stream start to first audio packet", "rtf": "input stream start-to-last-audio receive time divided by total emitted audio duration; includes concurrent realtime input" } } ], "duplex_stream_ttft_ms": { "count": 3, "mean": 3260.197, "p50": 2767.268, "p99": 4433.793 }, "duplex_stream_ttfp_ms": { "count": 3, "mean": 3260.153, "p50": 2767.243, "p99": 4433.705 }, "duplex_stream_rtf": { "count": 3, "mean": 1.515574, "p50": 1.224425, "p99": 2.17538 }pytest results
'core_model and cpu': 669 passed, 18 warnings in 134.32s
'advanced_model and cuda': 3 passed, 1 deselected, 15 warnings in 706.16s