[janbernloehr]

Summary

Prevent ProfileMetricCoverageError when a healthy, long-running streaming request is cancelled at the profiling boundary before it produces a completed metric record.

Retain actual content-arrival timestamps independently of request completion. Workers send rate-limited activity updates while a request is in flight and attach the exact last content timestamp to its credit return. The coverage gate accepts this evidence alongside its existing TTFT and inter-token-latency signals, retaining the scenario's 95% threshold.

This also covers forced phase completion when the cancellation drain times out before the worker returns its credit: activity already delivered to the Timing Manager remains available for validation.

Error and fix

Why the current gate can reject a healthy run

The gate introduced in this repository measures the latest TTFT and inter-token-latency observations in completed metric records against the configured profiling duration. PR #41 relaxed the required ratio from 98% to 95% to tolerate sparse tails, but it did not preserve activity from a request cancelled before completion.

The failure sequence is:

1. A duration-based profiling phase reaches its send deadline while a long request is still streaming.
2. The grace period expires and the worker is told to cancel the request.
3. Cancelled credits do not produce the completed records used by the coverage calculation.
4. The last completed request can predate the coverage cutoff even though the cancelled request continued producing content.
5. Both record-based ratios fall below the threshold, and the run is rejected with a stalled-server diagnosis.

Increasing the quiet-tail allowance only moves this boundary. A sufficiently long final request can exceed any fixed allowance. Attaching activity only to the final credit return is also insufficient because the cancellation drain can time out and force completion before that return arrives.

Synthetic example

The following values illustrate the regression independently of any particular model, server, dataset, or deployment:

Observation	Value
Configured profiling duration	1,800 seconds
Required coverage ratio	0.95
Latest completed-record TTFT	1,440 seconds after phase start: ratio 0.80
Latest completed-record ITL	1,620 seconds after phase start: ratio 0.90
Content from an unfinished stream	1,790 seconds after phase start
Request outcome	Cancelled during shutdown; no completed metric record

Previously, this fails because neither 0.80 nor 0.90 reaches 0.95. With this change, streaming_content_ratio is approximately 0.9944, so the coverage check passes. The cancelled request still contributes no successful-request count, throughput, or latency samples.

A stream whose last content arrived at 1,709 seconds still fails. Cancellation, an open connection, and a positive in-flight count do not establish recent content activity.

Implementation

Worker observation. For a scenario that enables coverage validation, profiling workers continue using the existing SSE callback after the first meaningful response. The endpoint parser determines whether a chunk contains content. Its arrival timestamp is converted from the performance clock to wall-clock nanoseconds using a per-request clock offset. The observer records arrival time, not cancellation or credit-return time.

In-flight reporting. A new typed StreamingContent message carries the phase, concrete phase index, and content timestamp over the existing worker-to-router PUSH/PULL return channel. The first content observation is reported immediately; further reports are limited to one per second per request. These messages do not return credits, change request counts, or release concurrency slots.

Final observation. CreditContext retains the latest timestamp, and both normal and fallback credit-return paths include it in CreditReturn.last_streaming_content_ns. This preserves the exact final observation, including a chunk that arrived between periodic reports.

Phase accounting. The router forwards activity to the matching phase callback. The phase progress tracker retains the maximum timestamp, so older observations cannot move coverage backwards. Unknown or completed phases ignore activity updates. The timestamp flows through credit phase statistics into records phase statistics; aggregate statistics retain the maximum, while validation uses each concrete profiling phase's own statistics.

Validation and export. ProfileMetricDurationCoverage adds streaming_content_ratio, defaulting to zero. The Records Manager calculates it as:

clamp((last_content_timestamp - phase_start) / configured_duration, 0, 1)

Coverage passes when any of ttft_ratio, inter_token_latency_ratio, or streaming_content_ratio reaches required_ratio. Success and failure diagnostics include all three signals. The new ratio uses FiniteFloat and is bounded to [0, 1].

Behavior preserved

• The inferencex-agentx-mvp threshold remains 0.95.
• Cancelled requests remain excluded from successful-request accounting and latency distributions.
• Role-only chunks, usage-only chunks, finish markers, keepalives, and [DONE] do not advance content coverage for the chat endpoint. Text and reasoning content do.
• Warmup activity cannot satisfy a profiling phase's coverage requirement, and one profiling phase cannot rescue another.
• First-token notifications still release prefill concurrency at most once per request, including when coverage observation continues afterward.
• Scenarios without coverage validation retain the existing callback fast path.
• Existing short-duration smoke-run and whole-run cancellation handling remain in place.

Scope and limitations

The coverage check establishes recent activity; it is not a continuous-availability or successful-completion guarantee. Content observed during the grace period is clamped to full coverage, consistent with the existing handling of completed-record timestamps beyond the configured window.

If a credit never returns, the gate uses the last delivered periodic observation. Because reports are limited to once per second, that observation can precede the exact final content timestamp by less than one second. No timestamp is fabricated when the worker has never reported content. A worker or communication failure that prevents all activity reports remains distinguishable from a healthy reported stream only through other diagnostics.

The additional work is endpoint parsing throughout streaming for coverage-enabled profiling requests, plus at most one activity message per second per active request. Other scenarios do not incur continuous parsing for this feature. No inference-server changes or GPU-specific behavior are required. Worker and Timing Manager processes should run the same harness revision because the typed return protocol gains a new message variant.

Validation

Deterministic reproduction of the missing-evidence failure

A prior CPU-only reproduction exercised the shipped ColumnStore and
MetricsAccumulator.profile_metric_duration_coverage at
754356e9,
using synthetic request records:

Input to the coverage calculation	TTFT coverage	ITL coverage	Verdict at 95%
Completed records, with the cancelled straggler omitted	84.80%	92.40%	Fail
Same records, plus the straggler's observed first-token timestamp	99.72%	—	Pass

The decisive change was retaining evidence from the unfinished request. The threshold and
configured duration stayed fixed. This establishes that discarding the straggler's observations
can cause the false positive without any inference-server failure. It validates the diagnosis and
proposed use of in-flight activity; it does not constitute an end-to-end run of this PR's patch.
The added record was an experimental input to isolate the cause, not the implementation proposed
here: this PR preserves activity separately from successful-request metrics.

Verification of this implementation

The regression tests carry streaming evidence through typed message serialization, the real
router and credit callback, phase progress statistics, the records tracker, and the coverage gate.
They establish the behaviors needed to fix the reproduced failure:

• Recent content passes even when cancellation produces no completed metric record.
• Already-delivered activity still passes when the credit never returns and the phase is forced
  to complete.
• Stale or absent content still fails; cancellation alone cannot satisfy the gate.
• Activity from another phase cannot rescue the failing phase, and completed-request counts and
  latency samples remain unchanged.

A real loopback HTTP/SSE stream also exercised AioHttpClient with the worker callback. It
produced rate-limited content reports before external task cancellation, without requiring a
completed record or credit return. This verifies that the transport supplies the evidence used by
the regression tests.

Validation covers the deterministic failure mechanism and the new activity-delivery path. The
patched harness has not been rerun against the original workload. Repository checks were also
run; the full suite's two failures reproduce on unchanged upstream.

Documentation

Updated the AgentX FAQ to explain cancelled-stream coverage, content filtering, and missing-return behavior. Updated the architecture and developer patterns to describe the activity-message path, phase scoping, callback contract, and unchanged accounting semantics.

Contribution checklist

• Regression tests added.
• User and developer documentation updated.
• Applicable pre-commit hooks passed.
• Commit signed off under the Developer Certificate of Origin.

Created with the assistance of Codex (GPT-6)

---

Note

Medium Risk
Changes AgentX run-validity logic and the worker/credit return protocol, but liveness evidence is scoped to coverage-only and does not alter successful-request or latency accounting.

Overview
Fixes false insufficient_profile_metric_coverage failures when a long streaming request is cancelled at the profiling boundary but was still producing content.

Coverage gate. Profiling phases can now pass the scenario’s 95% duration check via a third signal, streaming_content_ratio, alongside TTFT and inter-token latency. The ratio uses the latest parsed content timestamp (including cancelled credits with no metric record), clamped over the configured phase duration.

Worker → timing path. For scenarios with minimum_profile_metric_coverage_ratio, profiling workers keep the SSE callback active after first token, retain last_streaming_content_ns on the credit context, and emit rate-limited StreamingContent messages (≤1/s) on the existing return channel. CreditReturn carries the exact final timestamp; phase progress tracks the max and flows through records stats into RecordsManager validation. Activity messages do not return credits, release slots, or add latency/throughput samples; prefill release still happens once via FirstToken.

Docs and tests cover AgentX FAQ behavior, architecture/patterns, and edge cases (missing returns, phase isolation, non-content chunks).

^{Reviewed by Cursor Bugbot for commit 70af1f5. Bugbot is set up for automated code reviews on this repo. Configure here.}

[github-actions]

Try out this PR

Quick install:

pip install --upgrade --force-reinstall git+https://github.com/ai-dynamo/aiperf.git@4eda12b426c03b5dea9f7938fdb85b958b9f8916

Recommended with virtual environment (using uv):

uv venv --python 3.12 && source .venv/bin/activate
uv pip install --upgrade --force-reinstall git+https://github.com/ai-dynamo/aiperf.git@4eda12b426c03b5dea9f7938fdb85b958b9f8916

---

Last updated for commit: 4eda12b • Browse code

[ajcasagrande]

/ok to test 70af1f5

[ajcasagrande]

I reviewed this PR at 70af1f53 against master (merge-base 56a0cf70). Keeping streaming evidence separate from successful-request accounting fixes the cancelled-tail gap without inventing completed requests. Nothing blocks merging; the inline suggestions are optional naming and comment cleanup.

Verified

• A real loopback HTTP/SSE cancellation probe emitted two rate-limited activity reports and exactly one first-token notification, without a completed record or credit return. The exact final content timestamp remained 150,377,035 ns newer than the last periodic report; cancellation did not advance it.
• 1,863 focused worker, credit, records, timing, transport and exporter tests passed (11 deselected), including stale-content rejection, phase isolation and missing-return coverage.
• The full unit run reported 17,616 passed and one failure, test_completed_excludes_analyzer_metrics; that same failure reproduced on the base commit. The original production workload was not rerun.

_{🤖 The agent keeps its streaming contacts alive.}

[ajcasagrande]

Nit: _make_first_token_callback and on_first_token now also observe content throughout the stream, as this docstring describes. Optional: _make_content_callback / on_content would make that broader role easier to spot; there is no behavioral issue here.

_{🤖 A streaming agent wears more than one badge.}

[ajcasagrande]

Nit: This insertion separates the atomic-counting header from the counting step it describes. Keep the header immediately above that step; the observation is synchronous, so the existing no-await invariant already holds.

-        # 1. ATOMIC COUNTING (no await before this!)
         handler.progress.observe_streaming_content(
             credit_return.last_streaming_content_ns
         )
+        # 1. ATOMIC COUNTING (no await before this!)

_{🤖 The agent keeps its counting instructions in order.}

[ajcasagrande]

Nit: The message enumeration at sticky_router.py:603 omits this new variant; the PULL-channel note at :586 also names only CreditReturn/FirstToken. Add StreamingContent to both, or use generic wording so another variant cannot stale the list.

_{🤖 One more contact joins the agent's routing directory.}

[FrankD412]

I reviewed this at 70af1f53 (code reading, the focused unit suites, mutation checks on the new lines, and an end-to-end base-vs-head run against the mock server, below). Keeping streaming evidence separate from successful-request accounting is the right way to fix the cancelled-tail false failure, and most of the new mechanism is pinned by tests: reverting the after-first-token observation, the streaming_content_ratio OR clause, the is_complete guard, the 1 s rate limit, the tracker max, the [0, 1] clamp, or the arrival-time timestamp each fails a new test.

End-to-end reproduction

I reproduced the original failure and the fix with --scenario inferencex-agentx-mvp against aiperf_mock_server. The setup: one synthetic Weka trace in which every turn streams 2,000 tokens (TTFT 100 ms, ITL 100 ms, so about 200 s per request), concurrency 1, --benchmark-duration 900, --benchmark-grace-period 10. --unsafe-override was needed only because the trace is a local file. It marks the run submission_valid=false, but the coverage gate still runs. In both arms, four requests completed by about 813 s; the fifth was streaming at 900 s and was cancelled when the grace period expired (completed=4, cancelled=1, grace_period_timeout=True).

	base 56a0cf70	head 70af1f53
ttft_ratio	0.677	0.677
inter_token_latency_ratio	0.903	0.903
streaming_content_ratio	—	1.0 (last content at 909.97 s, clamped)
Coverage gate	fails insufficient_profile_metric_coverage, exit 1	passes, exit 0
request_count	4	4

The cancelled request adds liveness evidence without adding a completed request, as described. The trace generator and run script are available if you want to include them.

With that, the end-to-end evidence is covered. What remains is test coverage for two of the paths:

Asks

1. The final timestamp carried by CreditReturn is untested. The PR body says the credit return "preserves the exact final observation, including a chunk that arrived between periodic reports". Deleting the line that consumes it, callback_handler.py:362 (handler.progress.observe_streaming_content(credit_return.last_streaming_content_ns)), leaves every unit test green. test_cancelled_credit_content_survives_wire_and_phase_stats sends the same timestamp through StreamingContent and through CreditReturn (:512, :519), so the return path never decides the outcome. Suggested fix: in the credit_returns=True case, have the periodic report carry a timestamp that fails on its own (e.g. 1,709 s) and the CreditReturn carry 1,790 s, then assert that the phase passes.

2. The fallback return path is untested too. Removing last_streaming_content_ns= from the CreditReturn built in _on_credit_drop_message_task_done (worker.py:791) also breaks no new test. The normal path at :870 is covered. A worker test that drives the fallback path and asserts the field is on the sent CreditReturn would close this.

Optional

• If there is only one profiling phase and no per-phase stats match it, validation falls back to aggregate stats. Changing max to min in that aggregate (records_tracker.py:291) goes undetected. A two-stats aggregation case would cover it.
• The BasePhaseStats.last_streaming_content_ns description (credit_models.py:42) says "reported by a returned credit", but StreamingContent messages also feed it.
• The PR body and FAQ list text and reasoning as content. Tool-call deltas (ToolCallResponseData) count as well, which is correct for agentic turns; the wording could say so.

Question (not blocking)

With this change, a single request that is still streaming satisfies the gate even if the server has stopped admitting new requests and TTFT coverage is low. In the run above, TTFT coverage was 67.7% and the run passed. The body already says this is not a continuous-availability guarantee. Is that the intended scope of the stalled-server diagnosis, or should the FAQ say explicitly that admission stalls are out of scope?

For what it's worth, I checked the cost of parsing every chunk: parse_response on a typical chat chunk takes about 1 µs (versus about 0.3 µs for the existing SSEMessage.parse), and it only runs for profiling requests in coverage-enabled scenarios. I don't see a measurement concern there.

The only CI check that ran is "Validate PR title and add label". It fails with Resource not accessible by integration: the fork's token can't add the label, and the title itself is fine. No unit-test workflow has run on this head yet.

[cursor]

Bugbot is paused — your team has an unpaid invoice

Bugbot is paused because your team has an unpaid invoice.

Pay it from the billing page in the Cursor dashboard and Bugbot resumes automatically.

(requestId: cc65ef15-844f-4e1a-a66b-58bd42412b85)

[janbernloehr]

@FrankD412 Addressed in 4eda12b: the final-return test now requires the newer credit-return timestamp to pass, and fallback-return and aggregate-timestamp coverage are added. Each corresponding mutation fails its test. Also corrected the field description and documented tool-call activity.
Yes, the intended scope is recent content activity. An ongoing stream can satisfy this gate despite an admission stall; the FAQ now states that explicitly. Thanks for the end-to-end reproduction.

[FrankD412]

Re-reviewed at 4eda12b4. The source changes in this commit are behavior-neutral (callback rename, field description, comment and docstring moves), and the three test gaps from my earlier comment are closed. Each mutation now fails a test:

Mutation	Fails at 4eda12b4
Drop observe_streaming_content(credit_return.last_streaming_content_ns) in callback_handler.py	test_cancelled_credit_content_survives_wire_and_phase_stats[True]
Drop last_streaming_content_ns= from the fallback CreditReturn in worker.py	test_credit_task_fallback_preserves_last_content[12000000000]
max → min in the aggregate last_streaming_content_ns (records_tracker.py)	test_aggregate_stats_keep_latest_streaming_content[latest-second], [latest-first]

The focused suites (tests/unit/credit, tests/unit/timing, test_worker.py, test_records_manager.py, test_records_manager_process_results.py) give 1649 passed and 1 failed. The failure is test_completed_excludes_analyzer_metrics, which also fails on the merge-base 56a0cf70. ruff check and ruff format --check at the pinned 0.14.14 are clean on the changed files.

I reran the same mock-server reproduction as before against --scenario inferencex-agentx-mvp: one trace of about 200 s per request, concurrency 1, --benchmark-duration 900, --benchmark-grace-period 10, --unsafe-override. Both arms ran in parallel:

	master merge-base 56a0cf70	PR head 4eda12b4
Profiling phase	completed=4, cancelled=1, grace_period_timeout=True, 910 s	same
TTFT / ITL coverage	67.8% / 90.4%	67.8% / 90.4%
streaming_content_ratio	—	100%
Coverage gate	fails, exit 1	passes, exit 0
request_count	4	4

The cancelled request contributes coverage evidence only; request counts are unchanged. The FAQ wording on admission stalls answers my scope question. Approving.

[FrankD412]

I ran a hardware A/B of this PR through the InferenceX AgentX pipeline to check that observing streamed content costs nothing in throughput or latency.

Setup. Both arms built the harness from a git commit, with nothing else changed:

• base: e4bb2f835 (agentx-v1.0.12)
• cand: d49b63ba0 on test/pr45-on-1.0.12, which is e4bb2f835 with 4eda12b4 merged. Its tree is identical to refs/pull/45/merge.

The workload was Qwen3.5-397B-A17B-FP8 on B300 with SGLang, TP4, concurrency 32, a 3600 s profile and the semianalysis_cc_traces_weka_062126_256k dataset. I ran three repeats per arm. The agentx profile commands were identical across arms apart from the server address.

metric	base (mean of 3)	cand (mean of 3)	cand vs base
total tok/s/GPU	35,770	36,100	+0.9%
output tok/s/GPU	315.3	317.8	+0.8%
TTFT p50	0.699 s	0.687 s	−1.7%
ITL p50	6.65 ms	6.61 ms	−0.6%
E2EL p50	4.19 s	4.12 s	−1.7%
J / output token	2.276	2.272	−0.2%

• No regression. Paired by repeat, cand's total throughput is +0.9%, +0.9% and +1.0% over base. That is too small, over too few runs, to call an improvement.
• Coverage gate. All six runs passed at 100% TTFT and ITL coverage. Only the cand runs also report streaming content=100.0%, which confirms the PR code ran. No request was cancelled at the profiling boundary in any run, so this point measures the cost of the change, not the cancelled-tail case it fixes. That case is covered by the mock-server reproduction in my earlier comment.
• Run-to-run spread. Repeat 1 of both arms was about 11% lower in throughput than repeats 2–3 (44 completed sessions instead of 52), with identical commands. It affects both arms equally, so it does not bias the comparison.

Per-run results and run links

run	requests	sessions	total tok/s/GPU	output tok/s/GPU	TTFT p50 (s)	TTFT p90 (s)	ITL p50 (ms)	ITL p90 (ms)	E2EL p50 (s)	J/output tok
base-1	4,403	44	33,010	287.2	0.774	1.745	8.47	52.97	5.43	2.313
base-2	4,924	52	37,170	329.5	0.655	1.497	5.73	15.80	3.54	2.266
base-3	4,924	52	37,110	329.3	0.668	1.526	5.75	17.65	3.60	2.249
cand-1	4,432	44	33,300	289.8	0.770	1.811	8.36	51.11	5.50	2.316
cand-2	4,963	52	37,510	331.9	0.640	1.479	5.79	13.89	3.41	2.256
cand-3	4,963	53	37,500	331.6	0.651	1.449	5.68	14.94	3.44	2.244

InferenceX branches: fdinatale/agentx-pr45-base and fdinatale/agentx-pr45-cand. They differ only in the harness commit.

[FrankD412]

The tests finally went through and it looks like the fix isn't affecting performance. Looks like we're within noise. 😃