Skip to content

fix(timing): hold the trace idle cap while a grouped timer is still running - #1614

Open
FrankD412 wants to merge 7 commits into
fdinatale/aip-2293-integration-flakefrom
fdinatale/aip-2293-idle-cap-running-guard
Open

FrankD412 wants to merge 7 commits into
fdinatale/aip-2293-integration-flakefrom
fdinatale/aip-2293-idle-cap-running-guard

Conversation

@FrankD412

@FrankD412 FrankD412 commented Oct 26, 2026 •

Copy link
Copy Markdown
Contributor

Why

Stacked on #1602. Base is fdinatale/aip-2293-integration-flake. Retarget to main once #1602 merges.

The per-root trace idle watchdog in ReplayBarrierCoordinator treats a replay tree as idle whenever in_flight == 0. Some grouped timers have already started but haven't reached observe_issued() yet. For example, a timer can be waiting on acquire_prefill_slot() or send_credit() in credit/issuer.py. Those timers aren't counted. If the watchdog fires while one is in that state, it moves the tree's later timers forward and collapses the recorded replay spacing.

The watchdog gets there by two paths:

coderabbit and dynamo-review-agent flagged the first path on #1602:

Repro

Three timers in one root fire at 1.00 s (A), 1.05 s and 1.40 s (E), so the recorded gap from A to E is 0.40 s. A waits on an event that stands in for a prefill slot. Both trees gave the same result on 10 of 10 runs:

Second timer main (98d8e53) #1602 (ad2b581) This PR
Barrier-blocked (submit() rearm) 0.050 s 0.050 s 0.402 s
Issues nothing (_on_root_timer_done) 0.402 s 0.050 s 0.402 s

What

  • src/aiperf/common/loop_scheduler.py:
    • Records the group of each running task started through execute_async(group_id=...). That covers fired grouped timers and zero-delay grouped schedules. The record is removed in _done_callback and cleared by cancel_all_running().
    • running_count_for_group() counts a group's running tasks. It is the counterpart of pending_count_for_group().
  • src/aiperf/timing/replay_dependencies.py: _enforce_root_idle_cap() shifts nothing while the root still has a running grouped task, and leaves idle_cap_expired set. One check covers both paths. The cap still gets applied later:
    • If the running timer issues a request, observe_issued() clears the cap.
    • If it returns without issuing, _on_root_timer_done() applies the cap again. The scheduler has already stopped counting the task by the time the observer runs.

Why not the suggested guard

The reviews suggested adding running_count_for_group(root_id) == 0 to the rearm in submit(). That doesn't work, because the task calling submit() is itself a running grouped task, so the count never reaches zero. On this base, both test_idle_cap_waits_for_started_timer_that_has_not_issued cases (barrier_blocked and issues_nothing) still fail with that guard in place. test_idle_watchdog_retries_when_advanced_turn_is_barrier_blocked still passes with it, because #1602's completion observer re-enforces the cap; without that observer, it fails because the cap stalls. Excluding the calling task fixes submit(), but the _on_root_timer_done() path from #1602 never goes through submit(), so it stays broken.

Verification

  • 6 new tests. All 6 fail without the source change and pass with it. test_idle_cap_resumes_when_started_timer_returns_without_issuing now holds one grouped timer while a second returns, so the cap is re-enforced and must defer:
    • test_idle_cap_waits_for_started_timer_that_has_not_issued[barrier_blocked|issues_nothing]
    • test_idle_cap_resumes_when_started_timer_returns_without_issuing
    • test_running_count_for_group_counts_started_unfinished_tasks
    • test_running_count_for_group_excludes_task_in_group_observer
    • test_cancel_all_running_clears_group_running_counts
  • Existing tests that use a MagicMock scheduler now set running_count_for_group.return_value = 0. A bare MagicMock attribute is truthy, so without this the cap would never apply in those tests.
  • Local runs, Python 3.13:
    • tests/unit/timing/test_replay_barrier_coordinator.py and tests/unit/common/test_loop_scheduler.py: 71 passed, on each of 10 runs.
    • tests/unit/{timing,common,credit} and the overlap-barrier component test, with -n 8: 5061 passed, 1 failed. The failure was test_bootstrap_parent_death::test_parent_death_signal_real_kill_reaps_child. That test doesn't use this code, and it passes when run alone, both with and without this change.
    • -m integration Weka idle-cap, agentic_replay drops post-child delay on parent resume #1231 and spawn-join tests: 7 passed. test_runtime_idle_cap_handles_independent_stream_clock_drift passed 5 of 5.
    • -m component_integration, filtered to replay, barrier, agentic and idle tests: 26 passed, 3 skipped.
  • pre-commit run --from-ref ad2b5816 --to-ref HEAD: all hooks passed.
  • Python 3.11, 3.12 and Windows haven't been run yet. That's left to CI.

…unning

The per-root idle watchdog treated a replay tree as idle whenever
in_flight was zero. A grouped timer whose coroutine has started but
not yet reached observe_issued() (for example, while it waits for a
prefill slot or the credit send) was not counted. If the watchdog
fired in that window, it moved the tree's later timers forward and
collapsed the recorded replay spacing.

Two paths reached it:
- the zero-delay rearm in submit(), from 80662af (#1413), when a
  second timer lands on a barrier-blocked turn;
- _on_root_timer_done(), from #1602, when a second timer returns
  without issuing a request.

LoopScheduler now records the group of each running task, and
running_count_for_group() counts them. _enforce_root_idle_cap()
shifts nothing while the root still has a running grouped task, and
leaves the cap expired. If that task issues a request,
observe_issued() clears the cap. If it returns without issuing,
_on_root_timer_done() applies the cap again. The scheduler stops
counting the task before the observer runs.

Guarding the submit() rearm with running_count_for_group() == 0, as
the #1602 review suggested, does not work: the task calling submit()
is itself a running grouped task, so the count never reaches zero and
the cap stalls.

Signed-off-by: Frank Di Natale <3429989+FrankD412@users.noreply.github.com>
@copy-pr-bot

copy-pr-bot Bot commented Oct 26, 2026

Copy link
Copy Markdown

This pull request requires additional validation before any workflows can run on NVIDIA's runners.

Pull request vetters can view their responsibilities here.

Contributors can view more details about this message here.

@github-actions

github-actions Bot commented Oct 26, 2026 •

Copy link
Copy Markdown

Try out this PR

Quick install:

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

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@2f7a11a51df4e31b34d02aa4b68f96e2d789e0ff

Last updated for commit: 2f7a11a • Browse code

@github-actions github-actions Bot added the fix label Oct 26, 2026
@FrankD412 FrankD412 self-assigned this Oct 26, 2026
@FrankD412
FrankD412 marked this pull request as ready for review October 26, 2026 18:22
@FrankD412
FrankD412 requested a review from a team as a code owner October 26, 2026 18:22
@FrankD412
FrankD412 requested review from ajcasagrande and removed request for a team October 26, 2026 18:22

@ajcasagrande ajcasagrande left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I reviewed this PR at 90fc62a11 against fdinatale/aip-2293-integration-flake (merge-base 3c024b39d). Checking running tasks in shared enforcement covers both watchdog entry paths without collapsing replay spacing. The remaining feedback concerns test coverage and one statement in the PR description; neither blocks merging.

Verified

  • Scheduler/coordinator and adjacent agentic-replay tests passed: 149 passed.
  • Real mock-server integration checks passed: 2 passed, covering independent-stream drift and system-idle advancement without bypassing the child join.
  • Independent probes confirmed that a deferred cap resumes after non-issuing work finishes (0.0001 s) and clears when work issues. Python 3.11/3.12 and Windows were not run locally.

Not addressable to a diff line

Low: The description's “Why not the suggested guard” names a test that passes with the submit-only guard on this stacked base: test_idle_watchdog_retries_when_advanced_turn_is_barrier_blocked. The completion observer at replay_dependencies.py:193–216 rescues it; disabling that observer reproduces the stated stall. Qualify that explanation as applying without #1602's observer, or cite the two new overlapping-timer regressions, which do fail with the suggested alternative. This is description-only, not a source change.

🤖 Keeping watch until every timer clocks out.

loop = asyncio.get_running_loop()
while scheduler.running_count_for_group("root") == 0:
await asyncio.sleep(0.005)
await asyncio.sleep(0.05) # watchdog retries are deferred while it runs

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Low: This test never exercises deferral: the initial watchdog fires before slow_noop starts, and nothing retries enforcement while it runs; replacing enforcement with the complete base implementation still yields 1 passed. The autouse fixture also turns this sleep(0.05) into sleep(0) (tests/unit/conftest.py:150–164). Add a second grouped no-op whose completion triggers enforcement while slow_noop is held, assert the distant timer remains pending, then release it and check advancement.

🤖 The timing agent needs a deferred appointment.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Good catch, thanks. Fixed in d8d797d along the lines you suggested: a second grouped no-op at 1.05 s returns while slow_noop is still held, so the observer re-enforces the expired cap and has to defer. The test asserts the far timer is still pending and hasn't fired, then releases slow_noop and checks that the far timer fires within 0.2 s. The sleep(0.05) is gone. With the running-task guard removed from _enforce_root_idle_cap, the test now fails (pending_count_for_group is 0, expected 1).

I also updated the "Why not the suggested guard" section of the description: the barrier-blocked test only fails without #1602's observer, and the two test_idle_cap_waits_for_started_timer_that_has_not_issued cases are now cited as the ones that fail with the submit-only guard.

The resume test never deferred: the watchdog fired before slow_noop
started and nothing re-enforced the cap while it ran, and the autouse
no_sleep fixture turned its sleep(0.05) into sleep(0). A second grouped
no-op now returns while slow_noop is held, so the group-task observer
re-enforces and must defer; the test asserts the far timer is still
pending before releasing slow_noop.

Signed-off-by: Frank Di Natale <3429989+FrankD412@users.noreply.github.com>
Comment thread tests/unit/common/test_loop_scheduler.py Outdated
Comment thread tests/unit/common/test_loop_scheduler.py Outdated
Say what the idle cap relies on in each test instead of restating the
test name.

Signed-off-by: Frank Di Natale <3429989+FrankD412@users.noreply.github.com>
The test only checked the count after gathering the cancelled tasks, by
which point _done_callback had already dropped them, so removing the
clear() in cancel_all_running() still passed. Assert right after the
cancel as well.

Signed-off-by: Frank Di Natale <3429989+FrankD412@users.noreply.github.com>
Comment thread tests/unit/timing/test_replay_barrier_coordinator.py Outdated

@ajcasagrande ajcasagrande left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I reviewed this PR at d7521164d against fdinatale/aip-2293-integration-flake (merge-base 3c024b39d). The shared enforcement guard preserves replay spacing across both entry paths, and the strengthened regression now exercises deferral while another grouped timer runs. No correctness blocker remains; the existing helper-docstring nit is tracked below.

Verified

  • Scheduler/coordinator tests passed: 71 passed, on Python 3.13/Linux.
  • Real mock-server integration checks passed: 2 passed, covering independent-stream drift and system-idle advancement without bypassing the child join.
  • Restoring base enforcement in memory collapsed both overlap-test gaps to approximately 0.0503 s; HEAD passes their ≥0.35 s requirement. A separate asyncio probe confirmed issuance clears the expired cap and leaves another root's deadline unchanged.
  • Python 3.11/3.12 and Windows were not run locally.

Resolved while reviewing

Raised by others

🤖 On watch until the last grouped operative clocks out.

@ajcasagrande ajcasagrande left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I reviewed this PR at d7521164d against fdinatale/aip-2293-integration-flake (merge-base 3c024b39d). No correctness blocker remains; the only additional feedback is the wording nit below. The earlier review on this HEAD remains applicable.

Verified

  • Scheduler/coordinator tests passed with locked dependencies: 71 passed, Python 3.13/Linux; the real mock-server integration checks also passed: 2 passed.
  • Restoring base enforcement in memory reduced the overlap gaps to 0.05050 s and 0.05043 s, below the tests' 0.35 s minimum; HEAD preserves the required spacing.
  • Python 3.11/3.12 and Windows were not tested locally. Initial timing-test attempts encountered clock/import-order failures; the controlled run passed all 71.

Raised by others

🤖 The timing agent keeps every operative on the clock.

Comment thread src/aiperf/common/loop_scheduler.py Outdated
…docstring wording

The overlap regressions never submit conversation e, so
_started_unissued_metadata() only added a turn nothing reads; use
_metadata() directly. running_count_for_group is the counterpart of
pending_count_for_group, not its complement: grouped execute_async()
calls and nonpositive-delay schedules start without ever being pending.

Signed-off-by: Frank Di Natale <3429989+FrankD412@users.noreply.github.com>
Comment thread tests/unit/common/test_loop_scheduler.py Outdated
Signed-off-by: Frank Di Natale <3429989+FrankD412@users.noreply.github.com>

@ajcasagrande ajcasagrande left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I reviewed this PR at 2f7a11a51 against fdinatale/aip-2293-integration-flake (merge-base 3c024b39d). The shared enforcement guard preserves grouped-timer spacing across both watchdog entry paths while allowing the expired cap to resume after non-issuing work finishes. Nothing blocks merging.

Verified

  • Scheduler/coordinator tests passed: 71 passed, Python 3.13.12/Linux; the broader timing/common/credit suite passed 5,062 tests.
  • Real mock-server integration checks passed: 2 passed, covering independent-stream drift and system-idle advancement without bypassing child completion.
  • Restoring base enforcement in memory collapsed the overlap gaps to 0.05052 s and 0.05050 s, below the tests’ 0.35 s minimum; HEAD passes. An asyncio probe confirmed issuance clears the deferred cap without moving either root’s pending deadline.
  • Python 3.11/3.12 and Windows were not tested locally.

Resolved while reviewing

🤖 Keeping grouped operatives on their recorded schedule.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants