Skip to content

[Core] Add LLM-stage queue/prefill/decode split to StageRequestStats - #8575

Open
MinhaoLi0318 wants to merge 8 commits into
vllm-project:mainfrom
MinhaoLi0318:metrics/ar-stage-attribution
Open

MinhaoLi0318 wants to merge 8 commits into
vllm-project:mainfrom
MinhaoLi0318:metrics/ar-stage-attribution

Conversation

@MinhaoLi0318

Copy link
Copy Markdown
Contributor

Purpose

For an LLM stage (an AR or generation stage served by a vLLM engine core), stage_gen_time_ms runs from stage submit to the finished output. It includes engine-core queueing, prefill, decode and preemption, and today the only way to split it is a profiler trace.

vLLM already records the timestamps for this split, and vLLM-Omni already keeps a per-request copy of them (OmniRequestState.native_text_stats) for vllm_ttft_ms / vllm_tpot_ms. This PR adds the finished-request split from that copy to StageRequestStats. It shows up in the per-request [StageRequestStats] table (logged at DEBUG with --log-stats) and in build_and_log_summary()["stage_table"]:

Field Interval (same as upstream FinishedRequestStats)
vllm_queued_ms QUEUED event to first SCHEDULED event
vllm_prefill_ms first SCHEDULED event to first output token
vllm_decode_ms first output token to last output token
vllm_num_preemptions number of PREEMPTED events

The semantics are documented in the new "LLM-stage phase split" section of docs/design/metrics.md. Two points matter for review:

  • Missing is not zero. A field is None when its interval was not observed: a diffusion stage, --log-stats off, or a missing engine-core event. Upstream subtracts an unobserved timestamp as 0.0; here that interval is left out. A measured 0 stays 0.
  • Input wait is included. Upstream calls this interval queue time, but in vLLM-Omni it is scheduler wait only for stages that do not wait for input. An async_chunk receiver is submitted together with stage 0 and stays in WAITING_FOR_CHUNK until the first upstream chunk arrives. A requires_full_payload_input stage stays in WAITING_FOR_INPUT until its payload arrives. That time lands in vllm_queued_ms, and with async_chunk the later waits for chunks land in vllm_decode_ms. This PR does not separate input wait.
  • Two smaller cases, also documented. A KV-transfer sender keeps its request running until the KV extraction is acknowledged, and the token-less kv_ready output still advances the last-token timestamp, so its vllm_decode_ms includes that wait. In the default (non-windowed) chunk path, the chunk transfer adapter's overflow requeue sets PREEMPTED without an event, so vllm_num_preemptions does not count it.

Scope

  • No new Prometheus family. The wrapped vllm:request_{queue,prefill,decode}_time_seconds and vllm:request_num_preemptions histograms already carry {stage, replica} labels and use the same intervals.
  • The client stage_metrics snapshot, and so the benchmark JSON, is unchanged. [Bugfix][Bench] Save per-request stage metrics in detailed results #6464 is defining that schema. A perf-PR stage-attribution table needs the split there, so that is a follow-up.
  • Input wait is not split out. A follow-up can report it from the input coordinator and chunk adapter, which already track when a request starts waiting (_waiting_since).
  • Duplex tables leave the fields out. They describe one engine-core request, not a response turn, so they are in DUPLEX_STAGE_TABLE_EXCLUDE until turn semantics are defined ([RFC]: Duplex Request Metrics #6614 / [Frontend] Emit per-turn --log-stats tables for native duplex #6892). Duplex session code is otherwise untouched.
  • Streaming input: only the terminal event carries the split, and it covers the last input segment. That segment's vllm_queued_ms may be missing, because its QUEUED event can arrive before the per-segment reset.
  • Generation stages: the first engine-core output ends prefill even without a token, so a stage that emits one output when it stops reports its whole run as vllm_prefill_ms and a measured 0 decode (tested).

Related: the field rules follow the null and clock-domain proposal in #6472 (request-scoped stream-edge first events): an unobserved interval is None, not 0, and both endpoints of each interval are engine-core monotonic timestamps. #3995 (OTel tracing RFC): upstream do_tracing reads req_state.stats, which vLLM-Omni's output processor does not update (it keeps its own copy, native_text_stats), so per-stage spans would need to read that copy to carry these intervals; these fields expose them in logs and stats without a trace collector. Open PRs near these files, checked on 2026-10-06: #6464, #8170, #4798, #6892. None of them touches these hunks (#6892 edits stats.py from line 174 on; this PR changes the dataclass fields and DUPLEX_STAGE_TABLE_EXCLUDE above it). I left docs/contributing/metrics.md alone because #6892 rewrites its stage table.

Questions for reviewers

  1. Naming: vllm_queued_ms follows vllm_ttft_ms / vllm_tpot_ms. Would you prefer vllm_queue_time_ms to match the upstream histogram?
  2. Follow-up: add the split to stage_metrics once [Bugfix][Bench] Save per-request stage metrics in detailed results #6464 settles the detailed-result schema?

Test Plan

vLLM Version: v0.31.0 (db9527a46873, the tag's source archive), used as a source tree on PYTHONPATH without compiled extensions (vllm._C absent; only a _version.py added).

vLLM-Omni Commit: base 712b90de9 (upstream/main on 2026-10-07), head 8072f77ee (6 commits).

Environment: macOS 26.6 (arm64), Python 3.12.14, torch 2.13.0 CPU, pytest 9.1.1. No GPU. HF_HUB_OFFLINE=1 for every run, so tests that need a model download fail fast instead of hanging.

export PYTHONPATH=<vllm v0.31.0 source>:$PWD HF_HUB_OFFLINE=1
K="phase or image_ttfo or first_output_without_stats or stage_table"
NEW="tests/engine/test_output_processor.py tests/engine/test_orchestrator.py tests/metrics/test_stats.py tests/engine/duplex/test_engine_session.py"

# New and changed tests
pytest -q $NEW -m "core_model and cpu" -k "$K"

# The same test files against base production code
git worktree add --detach ../o1-base 712b90de9
for f in $NEW; do cp $f ../o1-base/$f; done
(cd ../o1-base && PYTHONPATH=<vllm v0.31.0 source>:$PWD pytest -q $NEW -m "core_model and cpu" -k "$K")

# Neighbouring suites (head, and base with its own test files)
pytest -q tests/metrics tests/engine/test_output_processor.py tests/engine/test_terminal_stage_metrics_order.py \
  tests/engine/test_orchestrator_segment_stage_keying.py tests/engine/test_orchestrator.py tests/engine/duplex \
  -m "core_model and cpu"

# CI "Simple · Engine&Entrypoints Test" selection, serial as in CI
pytest -q tests/entrypoints tests/engine -m "core_model and cpu"

# CI "Simple · Other Test" selection (head and base)
pytest -q tests/ -m "core_model and cpu" --ignore=tests/diffusion --ignore=tests/model_executor \
  --ignore=tests/entrypoints --ignore=tests/engine --ignore=tests/worker_v2/test_omni_ar_model_runner.py \
  --continue-on-collection-errors

# Lint
pre-commit run --files $(git diff --name-only 712b90de9...HEAD)

Test Result

  • New and changed tests: 24 passed. Against base production code: 18 failed, 6 passed. Of the 6 that pass on base, 3 check that nothing is reported (stats off, segment end, no table rows when unobserved), 1 checks that the duplex table has no phase columns (base never adds them), and 2 are existing duplex stage-table tests that the -k filter also selects.
  • Mutation check: I made 12 one-line edits to the change, one at a time: each interval guard, always reporting preemptions, dropping the record update or one field copy, None to 0.0 in build_stage_metrics, defaulting preemptions to 0, and removing the fields from DUPLEX_STAGE_TABLE_EXCLUDE. Every edit failed at least one test.
  • Neighbouring suites: head 801 passed, 1 skipped; base 780 passed, 1 skipped (the difference is the 21 new test cases).
  • Engine&Entrypoints, serial: head 3832 passed, 21 failed, 5 skipped, 1 xfailed; base 3814 passed with the same 21 failing test ids (the difference is the 18 new engine test cases). All 21 come from this environment: 17 need a Hugging Face snapshot that is not cached (offline mode), 2 need Triton for Model Runner V2, 1 needs onnxruntime, 1 needs /bin/true.
  • Other selection (run on base aad309087 before the last rebase; the 20 upstream commits since then touch none of the 8 changed files): tests/worker_v2/test_omni_ar_model_runner.py segfaults on both head and base in this environment (async_tensor_h2d with pinned memory on macOS), so I ignored that file. Head: 4627 passed, 192 failed, 82 skipped, 57 errors; base: 4624 passed (the difference is the 3 new metrics tests). The 249 failing or erroring test ids are identical on head and base. Their error lines are mostly macOS (/proc/self/mountinfo, /dev/shm, spawn pickling) and missing optional modules (opencc, torchmetrics).
  • pre-commit: all hooks pass except mypy-3.10. Its 16 errors are the same on base (compared without line numbers), and none is on a changed line. CI skips this hook.

Not run (an unrun check is not a pass):

  • No GPU serve. I have no real [StageRequestStats] log, and none from an async_chunk deployment. The input-wait behaviour above comes from reading the code (orchestrator prewarm, OmniSchedulingCoordinator, OmniChunkTransferAdapter), not from a measurement.
  • Not run on Linux with the compiled vllm==0.31.0 wheel, and not on CI's L4 image. CI L1/L2 (.buildkite/cuda/test-ready.yml) runs after a maintainer adds the ready label. The local L1 results are above.
  • No L2 (core_model and cuda) tests, because there is no GPU.
  • Not checked: a Prometheus scrape, a live duplex session, or a live streaming-input request.

AI assistance: Claude Code helped implement and test this change, run the local checks and draft this description. I reviewed every change and can explain its behavior. Validation: the commands and results above; the checks I could not run are listed under "Not run".

With --log-stats, each finished request on a vLLM engine-core stage now
carries vllm_queued_ms, vllm_prefill_ms, vllm_decode_ms and
vllm_num_preemptions in its StageRequestStats row and in the
[StageRequestStats] table. The intervals match vLLM's
FinishedRequestStats and come from the omni RequestStateStats that the
output processor already maintains.

A field is None when its interval was not observed (diffusion stage,
--log-stats off, or a missing engine-core event); a measured 0 stays 0.
The client-facing stage_metrics snapshot is unchanged.

Signed-off-by: MinhaoLi0318 <lminhao039@gmail.com>
vllm_queued_ms is the wait in the stage's engine-core scheduler, not
the orchestration-layer request_queue_wait_s or the diffusion
stage_in_queue_s. The per-request [StageRequestStats] table is logged
at DEBUG; INFO only prints the [OmniTiming] line.

Signed-off-by: MinhaoLi0318 <lminhao039@gmail.com>
Move the phase-split tests next to the helpers they need instead of
keeping two new test files with SimpleNamespace fakes:

- tests/engine/test_output_processor.py: interval math, including every
  unobserved or negative interval guard; QUEUED/SCHEDULED/PREEMPTED
  events end to end on both the AR text path (vLLM's no-tokenizer
  detokenizer, upstream process_outputs) and the multimodal-only path,
  cross-checked against FinishedRequestStats; a first output processed
  without stats; no split with stats off or at a segment end.
- tests/engine/test_orchestrator.py: StagePool copies observed keys and
  keeps absent ones None, using FakeStageClient/FakeOutputProcessor and
  a real RequestOutput; the diffusion TTFO test also checks the split
  stays None.
- tests/metrics/test_stats.py: zero vs missing in the summary and the
  rendered DEBUG table rows.

The private stage_metrics snapshot test is dropped: the snapshot is
built from an explicit key list, so it could only change by an
intentional edit.

Signed-off-by: MinhaoLi0318 <lminhao039@gmail.com>
vllm_queued_ms runs from the engine core accepting a request to its
first scheduling. For a downstream stage this includes waiting for
input: an async-chunk receiver is submitted with stage 0 and stays in
WAITING_FOR_CHUNK until the first chunk arrives (later chunk waits fall
inside vllm_decode_ms), and a requires_full_payload_input stage stays
in WAITING_FOR_INPUT until the payload arrives. Say so, instead of
calling it scheduler wait.

Also name the section after LLM stages, which is what it covers, and
say how the fields differ from the upstream histograms: same intervals,
but an unobserved interval is left out rather than subtracted from 0.0.

Signed-off-by: MinhaoLi0318 <lminhao039@gmail.com>
The four engine-core phase fields describe one vLLM request, not a duplex
response turn, so add them to DUPLEX_STAGE_TABLE_EXCLUDE until turn
semantics are defined. The non-duplex [StageRequestStats] table keeps
them.

Document two more limitations in metrics.md: a KV-transfer sender's
vllm_decode_ms includes the wait for the extraction ack (the token-less
kv_ready output advances the last-token timestamp), and the chunk
transfer adapter's overflow requeue sets PREEMPTED without an event, so
vllm_num_preemptions does not count it.

Signed-off-by: MinhaoLi0318 <lminhao039@gmail.com>
…hase split

The first engine-core output ends prefill even without a token, so a
generation stage that emits one output at stop reports its whole run as
vllm_prefill_ms and a measured 0 decode; add a test for that case. Note
that the last streaming segment's vllm_queued_ms may be missing, that
the overflow-requeue limitation applies to the default non-windowed chunk
path, that negative intervals are also omitted, and that per-request
tables log at DEBUG.

Signed-off-by: MinhaoLi0318 <lminhao039@gmail.com>
@vllm-omni-review-bot

Copy link
Copy Markdown

This PR appears to belong to: docs/design/module/engine_orchestration.md, docs/design/module/observability.md, docs/design/module/entrypoints.md.

Module owners: @alex-jw-brooks @linyueqian @NickCao

Routing: @alex-jw-brooks via module named in the PR description; @linyueqian via module named in the PR description; @NickCao via module named in the PR description

@MinhaoLi0318, 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.

@vllm-omni-review-bot

Copy link
Copy Markdown
Omni ReviewBot routing record

Assigned Strict on zcode (GLM-5.3-Flash) under experiment fleet-strict-cursor-grok46-zcode-glm53flash-5050-c5-z10-20261002.

@vllm-omni-review-bot

vllm-omni-review-bot commented Oct 7, 2026 •

Copy link
Copy Markdown

Omni ReviewBot triage note

Automated triage of commit b3ccf7d8cc88 produced:

  • Priority: high. Prompt maintainer attention is suggested.

These are automated triage suggestions only — the final decision belongs to the maintainers.

@MinhaoLi0318

Copy link
Copy Markdown
Contributor Author

Self-review (author). What I checked before asking for review:

  • Scope: 54 production lines in 3 files (metrics/stats.py, outputs/output_processor.py, engine/stage_pool.py); the rest is tests and a new section in docs/design/metrics.md. The current head ccb8fecf2 only adds a merge of main ([Model] MiniCPM-o 4.5: enable fused CFM body by default on CUDA #8557, MiniCPM-o Code2Wav files), so the results in the description, run at 8072f77ee, still cover all 8 changed files.
  • Intervals: _native_phase_metrics uses the same endpoints as vLLM's FinishedRequestStats (queued → scheduled → first output → last output), all EngineCore timestamps. An endpoint that was never observed (left at 0.0) or a negative interval produces no field instead of a 0, and stage_pool.py passes the resulting None through.
  • Boundaries: as the metrics.md section says, for async_chunk and full-payload receivers vllm_queued_ms includes waiting for upstream input, so it is not pure scheduler time, and later chunk waits can land in vllm_decode_ms. Following @EchoHayate's note on [RFC]: Request-scoped stream-edge first-event telemetry #6472, I'll add one sentence there that these fields must not be summed with transfer intervals or [RFC]: Request-scoped stream-edge first-event telemetry #6472 edge milestones into an end-to-end breakdown.
  • Unchanged: no new Prometheus family; the stage_metrics snapshot and benchmark JSON are untouched ([Bugfix][Bench] Save per-request stage metrics in detailed results #6464); duplex tables exclude the fields.
  • Not run yet: a GPU serve (listed under "Not run" in the description).

Coordination: on #6472, @EchoHayate proposed keeping this PR as the focused LLM-stage part, with diffusion and transfer fields in a companion RFC (#6472 (comment)). @lishunyang12 @vraiti, as metrics owners, could you take a look when you have time, especially whether the None-vs-0 rule and the field names fit the module?

AI assistance: drafted with Claude Code; I reviewed the diff and this summary myself before posting.

The LLM-stage phase fields can overlap with the upstream stage's run,
the transfer times in TransferEdgeStats and the transfer_tx_s /
transfer_rx_s histograms, and stage-to-stage handoff events. Say in the
metrics.md section that they are not added together into an end-to-end
breakdown unless the intervals are known not to overlap and use the
same clock.

Signed-off-by: MinhaoLi0318 <lminhao039@gmail.com>
@tzhouam

tzhouam commented Oct 9, 2026

Copy link
Copy Markdown
Collaborator

@vllm-omni-review-bot

@vllm-omni-review-bot vllm-omni-review-bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Omni ReviewBot review

4 actionable finding(s).

CI at b3ccf7d8cc88 (2026-10-09T09:51:48.090628+00:00): required check(s) blocking: buildkite/vllm-omni (missing).

Full review analysis

Scan:

Category Result
Tests / verification 4 finding(s) below
Security no finding reported
Docs / comments no finding reported
Behavior / compatibility no finding reported
Correctness no finding reported

Validated:

  • [resolved] 0-vs-None conflation concern (the one a reviewer would raise first): closed by parametrized tests at all three layers (output_processor record, stage_pool copy, table rendering); residual checked — vllm_num_preemptions is omitted entirely when the event stream was unobserved, which is itself tested ('nothing_observed', 'never_scheduled').
  • [claim-verified] 'stage_metrics snapshot returned to clients and benchmarks is unchanged': snapshots are built only by _merge_stage_metric_event whose field list is explicit and excludes the four fields (stats.py:582-606, update branch :609-670), consumed at omni_base.py:744 and stats.py:688; benchmark reads (benchmarks/patch/patch.py:1247) touch no new key.
  • [claim-verified] 'Wrapped vllm:request_* histograms carry {stage, replica} and use the same intervals': OmniPrometheusStatLogger relabels engine into (stage, replica) for the ~37 vllm:* families (metrics/stat_logger.py:6-8) and upstream logs those histograms from finished_requests fed with the same native_stats (output_processor.py:904-910).
  • [claim-verified] Input-wait follow-up is grounded: _waiting_since exists in OmniSchedulingCoordinator (core/sched/omni_scheduling_coordinator.py:88) and per omni_scheduler_mixin.py:65 also in OmniChunkTransferAdapter.
  • [claim-verified] 'overflow requeue sets PREEMPTED without an event': distributed/omni_connectors/transfer_adapter/chunk_transfer_adapter.py:1164 sets request.status = RequestStatus.PREEMPTED directly (no EngineCoreEvent), so vllm_num_preemptions cannot count it — doc claim accurate.
  • [claim-verified] chunk_transfer_adapter.py:1162-1165 — legacy-path overflow requeue pops running requests over scheduler_max_num_seqs and sets request.status=RequestStatus.PREEMPTED without an engine-core event; the doc's preemption caveat is code-accurate

4 actionable finding(s).

Verdict: COMMENT

Findings

  • [P2] The doc's streaming paragraph (docs/design/metrics.md:312) documents two behavi… — docs/design/metrics.md
Evidence for The doc's streaming paragraph (docs/design/metrics.md:312) documents two behavi…

The doc's streaming paragraph (docs/design/metrics.md:312) documents two behaviors — the terminal event's split covers only the last input segment because apply_streaming_update rebuilds native_text_stats, and the last segment's QUEUED event can arrive with the previous segment's final output, before that restart, so its vllm_queued_ms may be missing. The restart is real but pre-existing and unchanged by this diff (output_processor.py:143-145: self.native_text_stats = RequestStateStats(arrival_time=float(update.arrival_time or 0.0))), and none of the tests this PR adds to tests/engine/test_output_processor.py drive apply_streaming_update against the phase split — the only two streaming tests in the repo are pre-existing (lines 113, 197) and assert raw stats fields / tpot-itls, never the phase fields, while every other documented split behavior got a pinning test in this PR. Add one test: finish segment 1 with QUEUED/SCHEDULED events, call state.apply_streaming_update(...), finish segment 2 with events, then assert segment 2 carries the split with vllm_queued_ms absent and segment 1 carried none.

Evidence: Unmet requirement: the PR documents streaming behavior in docs/design/metrics.md:312 — 'For a streaming-input request, only the terminal event carries the split, and it covers the last input segment, because the request stats restart at each streaming update. The last segment's QUEUED event can arrive with the previous segment's final output, before that restart, so its vllm_queued_ms may be missing.' — but guards neither sentence with a test. The restart the doc relies on is pre-existing code, unchanged by this diff (its hunks touch only output_processor.py:86-112 and ~909-912): vllm_omni/outputs/output_processor.py:143-145 def apply_streaming_update(self, update) -> None: / super().apply_streaming_update(update) / self.native_text_stats = RequestStateStats(arrival_time=float(update.arrival_time or 0.0)). Repo-wide, the only tests calling apply_streaming_update are pre-existing: tests/engine/test_output_processor.py:113-131 asserts only raw-field reset (assert state.native_text_stats.first_token_ts == 0.0) and :197-223 asserts only num_generation_tokens/vllm_itls_ms/vllm_tpot_ms — neither names any of the four phase fields — and every phase-split test this PR adds (test_output_processor.py ~917-1131, plus the duplex/orchestrator/metrics test additions in the diff) builds stats directly or via process_outputs with no apply_streaming_update call. Adverse effect: a regression that makes the terminal segment's split inherit pre-restart timestamps (vllm_queued_ms appearing where the doc says it may be missing, or segment-2's split spanning segment-1 events) would pass the entire suite.

- **[P2] The new phase split is emitted at every finished request, but only the multimod…** — `vllm_omni/outputs/output_processor.py`
Evidence for The new phase split is emitted at every finished request, but only the multimod…

The new phase split is emitted at every finished request, but only the multimodal-only path distinguishes a streaming segment stop from a real finish: output_processor.py:813 gates on not is_segment_finished, while the text path delegates to upstream super().process_outputs (output_processor.py:745), which finishes any output carrying finish_reason and reaches the emit at :912. That shape is not hypothetical: omni_ar_scheduler.py:713-715 captures finish_reason = request.get_finished_reason() before the resumable reset ('may reset the status to WAITING for streaming requests that continue'), :722 sets is_segment_finished = not finished, and :797-817 emits the output with both fields — orchestrator.py:1700-1704 confirms segment stops flow through processed outputs. So on a streaming/duplex text (AR) stage with --log-stats, every intermediate segment emits a phase split into its StageRequestStats row, contradicting this PR's own doc claim that 'only the terminal event carries the split, and it covers the last input segment' (docs/design/metrics.md:312). Please add the same is_segment_finished gate on the text path, or correct the doc: as written the guarantee only holds for generation stages.

Evidence: Trigger on this PR head: an AR text stage with streaming segments under --log-stats. Producer (unchanged by this diff, present in the PR-time tree): vllm_omni/core/sched/omni_ar_scheduler.py:713-715 # Capture finish_reason BEFORE _handle_stopped_request, which may / # reset the status to WAITING for streaming requests that continue. / finish_reason = request.get_finished_reason(), :722 is_segment_finished = not finished, :797-817 OmniSchedulerMixin._append_request_output(self, outputs, request, new_token_ids=new_token_ids, finish_reason=finish_reason, ..., is_segment_finished=is_segment_finished, ...) — a mid-stream segment stop emits finish_reason set with is_segment_finished=True; vllm_omni/core/sched/omni_scheduler_mixin.py:747 finish_reason=finish_reason, / :762 is_segment_finished=is_segment_finished, forward both verbatim; vllm_omni/engine/orchestrator.py:1700-1701 # Streaming segment stops set ``is_segment_finished=True`` and are handled / # via processed outputs. In the changed file: vllm_omni/outputs/output_processor.py:745 upstream_processed = super().process_outputs( sends detokenizer-equipped outputs to upstream, which finishes on any finish_reason (the diff's own test test_engine_core_events_reach_native_phase_split[ar_text_path] pins that dispatch), reaching :912 self._native_text_metric_record(req_state.external_req_id).update(_native_phase_metrics(native_stats)) per segment; the mm-only gate that prevents exactly this, :813 if finish_reason is not None and not is_segment_finished and not is_non_final_audio_chunk:, has no text-path counterpart. Adverse effect: docs/design/metrics.md:312 (added by this diff) states For a streaming-input request, only the terminal event carries the split, and it covers the last input segment, because the request stats restart at each streaming update. — intermediate text-stage segments nonetheless carry measured vllm_queued_ms/vllm_prefill_ms/vllm_decode_ms in their StageRequestStats rows, so the documented guarantee is false for text stages.

- **[P2] The four engine-core phase fields added to StageRequestStats (stats.py:76-79) c…** — `vllm_omni/metrics/stats.py`
Evidence for The four engine-core phase fields added to StageRequestStats (stats.py:76-79) c…

The four engine-core phase fields added to StageRequestStats (stats.py:76-79) cannot survive the duplex end-of-response fold: _one_row_per_stage keeps the first chunk as template (templates.setdefault(sid, evt), stats.py:235), _merge_stage_metric_event's dict (stats.py:582-606) and _apply_merged_stage_stats's copy whitelist (stats.py:222-223) both omit the new fields, and engine_session.py:938 replaces aggregator.stage_events[rid] with the folded rows. A multi-chunk stage therefore folds to a row carrying the first chunk's None while the terminal chunk carries the measured split (mid-stream chunks carry None because the split attaches only at a terminal finish). No shipped table shows them today (DUPLEX_STAGE_TABLE_EXCLUDE, stats.py:149-157) and duplex turn semantics are deferred (#6614/#6892), but stage_events rows themselves expose the fields — the added test reads event.vllm_prefill_ms — and the per-turn consumer that work implies will read exactly these folded rows. Propagate terminal-wins values through _one_row_per_stage/_apply_merged_stage_stats, or leave a one-line note at the folding site (stats.py:244) so the follow-up does not inherit a silent None.

Evidence: Trigger: a duplex response whose LLM stage emits multiple chunks with --log-stats. Each chunk appends its own StageRequestStats (vllm_omni/metrics/stats.py:732 self.stage_events.setdefault(str(stats.request_id), []).append(stats)); the terminal chunk carries the measured split, the first chunk carries the dataclass defaults added by this diff at stats.py:76-79 (vllm_queued_ms: float | None = None ... vllm_num_preemptions: int | None = None), and the diff's own test pins that a non-terminal segment yields no phase keys. At response end, code unchanged by this diff — vllm_omni/engine/duplex/session/engine_session.py:937-938 for rid, events in aggregator.stage_events.items(): aggregator.stage_events[rid] = _one_row_per_stage(events) — folds per stage keeping the FIRST chunk as template (stats.py:235 templates.setdefault(sid, evt)), while _apply_merged_stage_stats copies a whitelist ending stats.vllm_itl_ms = _as_float(merged.get(defs.VLLM_ITL_MS)) / return stats (stats.py:222-223) and _merge_stage_metric_event's explicit dict ends defs.VLLM_ITLS_MS: list(evt.vllm_itls_ms or []), (stats.py:605) — neither mentions the four new fields. Adverse effect on this head: the folded row stored in aggregator.stage_events (the per-stage rows the PR's own added test reads via event.vllm_prefill_ms, tests/engine/duplex/test_engine_session.py) reports the engine-core phase split as unobserved (None) although the terminal chunk measured it; no shipped output shows the values today because this diff's DUPLEX_STAGE_TABLE_EXCLUDE (stats.py:149-157) excludes them from the duplex table, and repo-wide grep finds no other production reader — which is why this stays minor and the comment itself discloses it.

Suggestion: row_stats = _apply_merged_stage_stats(templates[sid], merged)
for field in ("vllm_queued_ms", "vllm_prefill_ms", "vllm_decode_ms", "vllm_num_preemptions"):
setattr(
row_stats,
field,
next(
(getattr(chunk, field) for chunk in reversed(chunks_by_stage[sid]) if getattr(chunk, field) is not None),
None,
),
)
rows.append(row_stats)


🤖 This review was generated by InferMatrix Copilot, an open-source repo-maintenance agent for PR review, CI debugging and issue triage. Try it on your own repo, and ⭐ star it if it helped!

DUPLEX_STAGE_TABLE_EXCLUDE = frozenset(
{
defs.SERVING_TIME_TO_FIRST_OUTPUT_MS,
"vllm_queued_ms",

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[P3] This diff adds the four new phase field names to DUPLEX_STAGE_TABLE_EXCLUDE as…

Evidence and suggested fix

This diff adds the four new phase field names to DUPLEX_STAGE_TABLE_EXCLUDE as raw string literals ("vllm_queued_ms".."vllm_num_preemptions", vllm_omni/metrics/stats.py:152-155) while the sibling entry in the same frozenset uses the defs constant (defs.SERVING_TIME_TO_FIRST_OUTPUT_MS, stats.py:151), and this file already consumes defs.VLLM_* constants as the canonical names for the sibling family (stats.py:219, stats.py:602). vllm_omni/metrics/definitions.py:132-135 centralizes that family as constants (VLLM_TTFT_MS..VLLM_ITLS_MS). Add VLLM_QUEUED_MS/VLLM_PREFILL_MS/VLLM_DECODE_MS/VLLM_NUM_PREEMPTIONS next to definitions.py:135 and reference them here, so the name registry stays the single source for the snapshot-schema work. (STAGE_EXCLUDE's raw strings are pre-existing; only this newly added set starts consistent. No runtime risk alleged — the duplex test pins the exclusion.)

Evidence: In this diff, vllm_omni/metrics/stats.py:149-157: DUPLEX_STAGE_TABLE_EXCLUDE = frozenset( with entries stats.py:151 defs.SERVING_TIME_TO_FIRST_OUTPUT_MS, followed by stats.py:152-155 "vllm_queued_ms", / "vllm_prefill_ms", / "vllm_decode_ms", / "vllm_num_preemptions", — four raw-string literals beside a defs constant in the same newly written set. Unchanged by this diff, present in the PR-time tree: vllm_omni/metrics/definitions.py:132-135 VLLM_TTFT_MS = "vllm_ttft_ms" / VLLM_TPOT_MS = "vllm_tpot_ms" / VLLM_ITL_MS = "vllm_itl_ms" / VLLM_ITLS_MS = "vllm_itls_ms" centralizes the sibling field-name family, and stats.py:219 stats.vllm_ttft_ms = _as_float(merged.get(defs.VLLM_TTFT_MS)) plus stats.py:602 defs.VLLM_TTFT_MS: float(evt.vllm_ttft_ms), show the same file consuming those constants as canonical names; a repo-wide grep for VLLM_(QUEUED|PREFILL|DECODE|NUM_PREEMPTION) returns no matches, so the four new names exist only as unregistered literals. Unmet requirement: the newly added members of this registered name family bypass the registry, leaving the family with two name sources on this head; adverse effect is drift risk for the upcoming snapshot-schema consumers, not a current runtime defect (the diff's duplex test asserts the fields' absence), hence nit.

Suggestion: defs.SERVING_TIME_TO_FIRST_OUTPUT_MS,
defs.VLLM_QUEUED_MS,
defs.VLLM_PREFILL_MS,
defs.VLLM_DECODE_MS,
defs.VLLM_NUM_PREEMPTIONS,

@hsliuustc0106 hsliuustc0106 added the high priority high priority issue, needs to be done asap label Oct 10, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

core related to core module: cache, scheduler, engine, worker, modelrunner high priority high priority issue, needs to be done asap

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants