Skip to content

fix(session): stamp COMPLETE with the arrival time of its chunks - #536

Open
kimseunghyun-kr wants to merge 4 commits into
mlcommons:mainfrom
kimseunghyun-kr:fix/complete-arrival-timestamp
Open

kimseunghyun-kr wants to merge 4 commits into
mlcommons:mainfrom
kimseunghyun-kr:fix/complete-arrival-timestamp

Conversation

@kimseunghyun-kr

Copy link
Copy Markdown

What does this PR do?

Fixes #533: in streaming runs, a sample's sample.complete could be stamped before its own sample.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_at is set at decode, but RECV_FIRST / RECV_NON_FIRST are stamped when the session handles each chunk. So when a response's chunks and its final result arrive in the same drain, COMPLETE is older than the chunks.

Fix. COMPLETE now uses the same per-response monotonic_ns() read (now_ns in _receive_responses) as the chunk events. Responses are handled in arrival order, so a sample's COMPLETE can no longer precede its own chunks. The source change is one line, plus a comment. QueryResult.completed_at itself is unchanged.

The design doc (docs/load_generator/DESIGN.md, "Timestamp fidelity" and the sequence diagram) is updated to match.

Type of change

  • Bug fix
  • New feature
  • Documentation update
  • Refactor/cleanup

Related issues

Closes #533

Testing

  • Tests added/updated
    • New test_streaming_complete_not_before_chunks_of_one_drain. It runs a real session in which the QueryResult is created first (as a decode in the same drain would), then the chunks and the result are delivered. It checks that RECV_FIRST ≤ RECV_NON_FIRST ≤ COMPLETE. Without the fix it fails: COMPLETE is about 11 ms before the chunks.
    • The _handle_response test now expects COMPLETE to carry the caller's arrival stamp, as the chunk events already do.
  • All tests pass locally
    • 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 on main, because os.sched_setaffinity is Linux-only.
  • Manual testing completed

Checklist

  • Code follows project style
  • Pre-commit hooks pass. ruff, ruff-format, prettier, license headers and the PR size check pass. On macOS, mypy reports only the Linux-only os.sched_*affinity attributes in cpu_affinity.py and token_metrics.py. Those files are not touched here, and main gives the same errors.
  • Documentation updated (if needed)

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

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>
@kimseunghyun-kr
kimseunghyun-kr requested review from a team and a lite review from Copilot October 14, 2026 06:46
@github-actions

github-actions Bot commented Oct 14, 2026 •

Copy link
Copy Markdown

MLCommons CLA bot:
Thank you very much for your submission; we really appreciate it. Before we can accept your contribution,
we ask that you sign the MLCommons CLA (Apache 2). Please submit your GitHub ID to our onboarding form to initiate
authorization. If you are from a MLCommons member organization, we will request that you be added to the CLA.
If you are not from a member organization, we will email you a CLA to sign. For any questions, please contact
support@mlcommons.org.
1 out of 2 committers have signed the MLCommons CLA.
✅ @arekay-nv
❌ @kimseunghyun-kr
You can retrigger this bot by commenting recheck in this Pull Request

@github-actions github-actions Bot added the size/normal PR Review Policy: <=500 non-test lines & <=20 files label Oct 14, 2026

Copilot AI 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.

🟡 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.

Comment thread docs/load_generator/DESIGN.md
@kimseunghyun-kr

Copy link
Copy Markdown
Author

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>
Copilot AI lite review requested due to automatic review settings October 14, 2026 07:05

Copilot AI 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.

🟡 Changes recommended

Update the design documentation’s timestamp explanation and remaining _handle_response example.

1 open finding
1 resolved since last review

🧠 Review effort: Lite

Comment thread docs/load_generator/DESIGN.md
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>
Copilot AI lite review requested due to automatic review settings October 14, 2026 08:05
@kimseunghyun-kr

Copy link
Copy Markdown
Author

recheck

Copilot AI 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.

🟢 Approval recommended

The focused fix, tests, and documentation updates address the reported timing issue with no unresolved review concerns.

0 open findings

1 resolved since last review

🧠 Review effort: Lite

@arekay-nv

Copy link
Copy Markdown
Collaborator

@kimseunghyun-kr Please complete the CLA process:

Thank you very much for your submission; we really appreciate it. Before we can accept your contribution,
we ask that you sign the MLCommons CLA (Apache 2). Please submit your GitHub ID to our onboarding form to initiate
authorization. If you are from a MLCommons member organization, we will request that you be added to the CLA.
If you are not from a member organization, we will email you a CLA to sign. For any questions, please contact
support@mlcommons.org.

@arekay-nv
arekay-nv requested a review from nv-alicheng October 14, 2026 15:43
viraatc
viraatc approved these changes Oct 22, 2026 •
@codecov-commenter

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
⚠️ Please upload report for BASE (main@d3c57f2). Learn more about missing BASE report.

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.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

Copilot AI lite review requested due to automatic review settings October 26, 2026 17:20
@arekay-nv

Copy link
Copy Markdown
Collaborator

@kimseunghyun-kr please complete the CLA so we can review the PR.

MLCommons CLA bot: Thank you very much for your submission; we really appreciate it. Before we can accept your contribution, we ask that you sign the MLCommons CLA (Apache 2). Please submit your GitHub ID to our onboarding form to initiate authorization. If you are from a MLCommons member organization, we will request that you be added to the CLA. If you are not from a member organization, we will email you a CLA to sign. For any questions, please contact support@mlcommons.org.1 out of 2 committers have signed the MLCommons CLA.✅ @arekay-nv❌ @kimseunghyun-krYou can retrigger this bot by commenting recheck in this Pull Request

Copilot AI 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.

🔵 Needs a closer look

The ordering fix is correct, but it also changes the reported COMPLETE-based latency and OSL/s for all runs, and maintainers need to decide whether to accept or document that shift.

2 open issues

Review effort: Lite

Comment on lines +796 to +800
# 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,
Comment on lines +363 to +364
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
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/normal PR Review Policy: <=500 non-test lines & <=20 files

Projects

None yet

5 participants