Fix prefill delayer wait histograms always observing 0#25975
Conversation
The sglang:prefill_delayer_wait_{forward_passes,seconds} histograms
incremented their _count but kept _sum (and every percentile) at 0. The
wait length was derived from output.next_state, which is None on every
release path, while the histogram is only observed on release
(output_allow and actual_execution). Delay outcomes do carry the
accumulated count via next_state but skip the observation because
output_allow is False, so the histograms only ever saw observe(0).
Surface the accumulated wait (forward passes and seconds) explicitly
through _NegotiateOutput so the release paths carry the real value, and
observe those fields in _record_single_pass_result. Extend the
negotiate unit test to assert the surfaced wait on release outcomes.
Fixes sgl-project#25949
Co-Authored-By: Claude Opus 4.7 (1M context) <[email protected]>
There was a problem hiding this comment.
Code Review
This pull request enhances the prefill delayer by explicitly tracking and reporting accumulated wait metrics, specifically wait_forward_passes and wait_seconds, within the _NegotiateOutput structure. This change ensures that metrics are accurately captured during prefill release paths. Corresponding tests were updated to include assertions for these new fields. A review comment suggests an optimization to use a dictionary literal and avoid unnecessary time calculations when no previous state exists.
| wait_info = dict( | ||
| wait_forward_passes=prev_state.delayed_count if prev_state else 0, | ||
| wait_seconds=( | ||
| (time.perf_counter() - prev_state.start_time) if prev_state else 0.0 | ||
| ), | ||
| ) |
There was a problem hiding this comment.
Optimization: Use a dictionary literal and only calculate wait metrics if prev_state exists. This avoids unnecessary time.perf_counter() calls and dictionary allocations when no prefill is being delayed. Since _NegotiateOutput has default values for these fields (0 and 0.0), an empty dictionary is sufficient when there is no previous state to report.
wait_info = {
"wait_forward_passes": prev_state.delayed_count,
"wait_seconds": time.perf_counter() - prev_state.start_time,
} if prev_state else {}|
/rerun-test test/registered/scheduler/test_prefill_delayer.py |
|
/tag-and-rerun-ci |
|
🚀 |
Motivation
The
sglang:prefill_delayer_wait_forward_passesandsglang:prefill_delayer_wait_secondshistograms increment their_countbut their_sum(and every percentile) stays at0forever, regardless of how long the prefill delayer actually held prefills. Theprefill_delayer_outcomes_totalcounter is unaffected.Fixes #25949.
Root cause
_record_single_pass_resultderived the wait length fromoutput.next_state:next_stateisNoneon every release path (wait_success,no_wait,wait_timeout,token_watermark,""), so the wait values fell to0.output_allow and actual_execution).delayoutcomes do carry the accumulated count vianext_state, but they skip the observation becauseoutput_allow=False.These two conditions are mutually exclusive, so the histograms only ever saw
observe(0).Modifications
wait_forward_passes/wait_secondsfields to_NegotiateOutputand populate them fromprev_stateon every release path (delay paths keep the default0, since the wait isn't finished and isn't observed)._record_single_pass_resultnow observes these surfaced fields instead of recomputing fromnext_state.gloonegotiate unit test with anexpected_wait_forward_passesexpectation and assert it on theno_wait,wait_success,wait_timeout, and queue-trigger release outcomes (regression guard — these would all observe0before this change).No behavior change to scheduling decisions: the set of observed outcomes is unchanged; only the recorded magnitude is corrected from
0to the real accumulated wait.Accuracy Tests
N/A — observability-only change; no kernel or model-forward code is touched.
Speed Tests and Profiling
N/A — no inference hot path is affected.
Checklist
🤖 Generated with Claude Code
CI States
Latest PR Test (Base): ❌ Run #26215523528
Latest PR Test (Extra): ❌ Run #26215523120