Repository navigation
fix(session): stamp COMPLETE with the arrival time of its chunks - #536
kimseunghyun-kr wants to merge 4 commits into
Conversation
In streaming runs a sample's COMPLETE could be earlier than its own RECV_FIRST, which gave a negative TPOT. The ZMQ transport decodes a whole drain before the session handles any message, so QueryResult.completed_at (set at decode) predates the handling-time stamp of chunks from the same drain. COMPLETE now uses the same per-response monotonic_ns() read as the RECV_FIRST/RECV_NON_FIRST events. Closes mlcommons#533 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
|
MLCommons CLA bot: |
There was a problem hiding this comment.
🟡 Changes recommended
The design document still contains a contradictory description of the old completion timestamp behavior.
1 open finding
What changed in this PR
Fixes negative streaming TPOT by timestamping COMPLETE when responses are handled.
Changes:
- Uses arrival timestamps for completion events.
- Adds streaming ordering regression tests.
- Updates timestamp documentation and diagrams.
| File | Summary |
|---|---|
tests/unit/load_generator/test_async_session.py |
Adds regression coverage and updates timestamp expectations. |
src/inference_endpoint/load_generator/session.py |
Uses handling-time timestamps for COMPLETE. |
docs/load_generator/DESIGN.md |
Documents the revised timestamp behavior. |
🧠 Review effort: Lite
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
|
recheck |
The "Timestamp Fidelity" section and its _handle_response example still described COMPLETE as stamped with QueryResult.completed_at. Both now match the implementation: one arrival stamp per response, shared by the chunk events and COMPLETE. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The _receive_responses example called _handle_response(resp) and read the clock again for the liveness stamp. It now reads monotonic_ns() once per response and passes it to _handle_response, as the implementation does. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
|
recheck |
|
@kimseunghyun-kr Please complete the CLA process:
|
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #536 +/- ##
=======================================
Coverage ? 81.37%
=======================================
Files ? 157
Lines ? 22472
Branches ? 0
=======================================
Hits ? 18286
Misses ? 4186
Partials ? 0 ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
|
@kimseunghyun-kr please complete the CLA so we can review the PR.
|
| # The same arrival stamp as RECV_FIRST/RECV_NON_FIRST. | ||
| # resp.completed_at is set at decode, so a result decoded | ||
| # in the same transport drain as its chunks would precede | ||
| # them (negative TPOT). | ||
| timestamp_ns=now_ns, |
| same drain as its chunks would precede them and give a negative TPOT.) Both | ||
| ISSUED and COMPLETE timestamps share the same ZMQ transit bias. TTFT |


What does this PR do?
Fixes #533: in streaming runs, a sample's
sample.completecould be stamped before its ownsample.recv_first, which gave a negative TPOT.Cause. The ZMQ transport decodes every waiting message of one drain before the session handles any of them.
QueryResult.completed_atis set at decode, butRECV_FIRST/RECV_NON_FIRSTare stamped when the session handles each chunk. So when a response's chunks and its final result arrive in the same drain,COMPLETEis older than the chunks.Fix.
COMPLETEnow uses the same per-responsemonotonic_ns()read (now_nsin_receive_responses) as the chunk events. Responses are handled in arrival order, so a sample'sCOMPLETEcan no longer precede its own chunks. The source change is one line, plus a comment.QueryResult.completed_atitself is unchanged.The design doc (
docs/load_generator/DESIGN.md, "Timestamp fidelity" and the sequence diagram) is updated to match.Type of change
Related issues
Closes #533
Testing
test_streaming_complete_not_before_chunks_of_one_drain. It runs a real session in which theQueryResultis created first (as a decode in the same drain would), then the chunks and the result are delivered. It checks thatRECV_FIRST ≤ RECV_NON_FIRST ≤ COMPLETE. Without the fix it fails:COMPLETEis about 11 ms before the chunks._handle_responsetest now expectsCOMPLETEto carry the caller's arrival stamp, as the chunk events already do.pytest -m unit: 2,255 passed, 6 skipped, 1 failed on macOS:test_token_metrics.py::TestRayonCaps::test_init_worker_overrides_inherited_cap_with_block_size. It fails the same way onmain, becauseos.sched_setaffinityis Linux-only.Checklist
os.sched_*affinityattributes incpu_affinity.pyandtoken_metrics.py. Those files are not touched here, andmaingives the same errors.Note for reviewers. The issue lists a second option: stamp chunks at decode time too, so the client's own backlog is also removed from TTFT. That needs a new decode-time field on
StreamChunk(more bytes on every chunk), so it is not in this focused fix. I can do it as a follow-up if you prefer it.AI assistance: prepared with Claude Code. I reviewed every change.
🤖 Generated with Claude Code