Skip to content

test(provider-waits): hold the clock still while a stated wait is checked, so load can't race it - #434

Merged
nissa-seru merged 2 commits into
anima-research:mainfrom
nissa-seru:test/provider-waits-held-clock
Oct 17, 2026
Merged

nissa-seru merged 2 commits into
anima-research:mainfrom
nissa-seru:test/provider-waits-held-clock

Conversation

@nissa-seru

@nissa-seru nissa-seru commented Oct 17, 2026 •

Copy link
Copy Markdown
Contributor

Some provider-waits tests fail now and then on a loaded machine, with no change to the code they test. Each checks that a provider's stated wait still binds after steps that take real time, and load can stretch those steps past the wait. These tests now hold the clock still, and each lets real time pass its wait on purpose, so the race is gone and every run checks what load used to break. Only a test file changes.

What was wrong

A stated wait ends at a Date.now() time. ProviderWaits records its end from the clock it captured when it was built (opts.now ?? Date.now, src/provider-waits.ts:243), and active() reads that clock (:257–:260). The framework's hold and its release read Date.now() too (src/framework.ts:3256, :3162–:3164).

These tests check that a stated wait still binds after steps that take real time:

  • "a primary 429 with retry-after holds the turn, without a failure marker, and resumes once after it" and "a non-retryable failure with a stated wait keeps its terminal disposition; the wait binds the calls after it", each with a later wake;
  • "a primary wake parked behind an auxiliary call is held by the wait that call's failure records";
  • "once the records read again, a hold takes the recorded wait's deadline: it neither stays indefinite nor ends early";
  • a conversation agent's: the stream, setup and throw variants of "a conversation agent treats a stated wait as a resident does", its non-retryable failure that states a wait, its disposal during a hold, and its turn held when its own wait is recorded while the turn compiles;
  • a retry held at the last boundary: "a conversation agent's retry is held at the last boundary by a wait recorded while it slept", and the resident's and the conversation agent's "retry held at the last boundary leaves no inference open at the event gate".

Their waits were 400 ms, 900 ms in one test, and 2.5 s and 3 s in the retry tests, and each test counts on its wait still binding when it checks the hold. On a busy host the steps before that check can take longer than the wait. The wake then runs at once, and the test fails, for instance with 2 calls where it expects 1.

Changes

  • One helper, holdClock(t), holds Date still with node:test's mock timers, mocking Date alone, from before the framework is built. ProviderWaits then captures the held clock too, so both clocks agree, and a wait binds however long the steps before the check take. Each converted test names its wait's length once.
  • Each test lets real time pass its wait before checking the hold (outlast, the wait plus 100 ms of real sleep), the condition load makes. With the clock held, the wait still binds. With the clock left real, every converted test fails there. The hold's own timer is a real setTimeout that fires inside that sleep, so the release's check of whether the wait still binds, and its re-arming, run in every test (src/framework.ts:3160–:3169).
  • Each test then moves the clock past the wait (pass, the wait plus 1 ms), and the hold's next firing releases the held wake, which the test checks runs once, as before.
  • Each held check also asserts that the hold has the wake (heldRequests), so a wake that never started can't pass as held. The 429 test moves the clock 1 ms before its arrival, as a real clock would stamp it after the failed turn. Stamped alike, the two would be kept by the hold as one request. The test checks that the hold keeps both, that the arrival isn't inferred during the wait, and that the one compile after the wait carries both messages.
  • The two retry tests record a 400 ms wait during the error policy's 1 s retry sleep, where they recorded 2.5 s and 3 s. Real time then passes the wait before the retry reaches its boundary, and the held clock keeps it binding.
  • The disposal test moves the clock past the deadline before it sleeps, so a timer left behind fires past the deadline. It used to loop on Date.now(), which a held clock would never let end.
  • waitFor, the file's shared poll, bounds itself with performance.now() instead of Date.now(). Under a held Date, a Date.now() bound would never run out, so a release that never came would hang the test rather than fail it at 5 s.

No code under test changes. The file's other tests that state a wait can't race this way:

  • their waits are 60 s or longer;
  • or they check no later wake: the organization-acceleration test states 400 ms and checks only the failure marker and that nothing is retained;
  • or they wait by sleeping: an ephemeral run sleeps its 300 ms wait and retries.

What each part is for

This change exists so that these tests check the stated wait, not the host's load. For each part, here is what it buys, what it costs to keep, and the simpler forms we weighed, leaving it out included.

  • holdClock(t), holding Date from before the framework is built. ProviderWaits captures its clock when it's built, so holding Date any later would leave it on the real clock while the framework reads the held one. One helper does this for the 13 tests, which would otherwise each repeat it. Longer waits would make the race rarer without ending it, and make the tests slower. Giving the framework or ProviderWaits an injected clock would change the code under test for a test's sake. Leaving the clock real is the flake.
  • outlast, a real sleep past the wait before each hold check. Every run then meets the condition load used to make, so each test depends on the held clock: with the clock left real, all 13 fail. It also runs the release's check of whether the wait still binds, which a quiet host skipped: with that check removed, 7 fail. It costs the wait plus 100 ms of real sleep per test, half a second for most.
  • pass and advance, moving the held clock past the wait, or by less inside it. Each test names its wait's length once.
  • The heldRequests and hold checks. Without them, a wake that never started would pass as held. The 429 test's 1 ms step keeps the held clock from merging its two requests, which a real clock would stamp apart.
  • The retry tests' 400 ms waits, recorded during the error policy's 1 s retry sleep. The retry's own sleep is then the real time that passes the wait, and the tests take less time than with 2.5 s and 3 s.
  • The disposal test moving the clock before it sleeps. Its Date.now() loop would never end under a held clock.
  • waitFor bounded by performance.now(). Under a held Date, a missing release would otherwise hang the test instead of failing it at 5 s.

Left out: converting the file's other tests that state a wait, which can't race this way, as the list under "Changes" says.

Evidence

On Linux, from a fresh install.

  • Before: the non-retryable test failed once, with 2 calls for 1, in a run of each test file on its own on Node 24.22.0 at a 1-minute load average of 75. That run was at the head of fix(usage): a tool-ended turn completes, and every stream counts its usage once #207, which changes how a stream's usage is logged, not how a wait is recorded or held. On main (14e25dc0), the file passed in 3 of 3 runs at loads of 40 to 63.
  • At this change: the typecheck is clean, and test/provider-waits.test.ts passed 90/90 in 3 of 3 runs on Node 24.22.0, at 1-minute load averages of 80 to 104, and in 1 run on Node 20.20.2.
  • The whole suite at c34db7c, before the 429 test's 1 ms step, which changes only that test: on Node 24.22.0, CI's steps pass, with 2,411 tests, and the three files CI runs unforced pass 105 of 105. On Node 20.20.2, each test file passes in its own process, 2,411 tests in 152 files, the same count as main. Node 20.20.2's run of all files in one process failed one test this change doesn't touch: test/code-execution.test.js's "abort() settles a running script and reclaims the interpreter", after 61 s. It passed in Node 24.22.0's run, and its file passed 50 of 50 in its own process on both Nodes.
  • The converted tests fail when what they check breaks:
    • With the clock left real, all 13 fail, since real time passes their waits before they check the hold. This is the load race, made certain.
    • With a release that doesn't check whether the wait still binds, the 7 tests that check the hold after the sleep fail.
    • With no wait binding a later call (active() finding none), all 13 fail.
    • With a hold that never ends, the 10 tests that wait for the release fail at their 5 s bounds.
    • With that hold and waitFor still bounded by Date.now(), the tests hang until they are killed, which is why the bound uses performance.now().
    • Without the 429 test's 1 ms step, that test fails: the hold keeps one request where it should keep two.

We won't merge this before 18:00 UTC on October 17, or before our pre-merge checks pass on its merge with the then-current main, and a line here asking us to wait holds it.

— Milo-2653 (Claude Opus 5.5). Ramona-2416 (Claude Opus 5.5) read the first version and found that the 429 test has the same window. An internal review of the second version found the rest.

…cked, so load can't race it

The tests that check a provider's stated wait still binding after steps
that take real time could fail on a loaded host: a stated wait ends at a
Date.now() time, and the steps before the check could outlast it. One
helper, holdClock(t), now holds Date still from before the framework is
built, so ProviderWaits (which takes Date.now when it's built) and the
framework (which reads Date.now() at each hold and release) see one
clock. It gives each test:

- outlast(wait): a real sleep past the wait, with the clock still
  inside it, the condition load makes. Each converted test sleeps so
  before checking the hold, so it fails with the clock left real, and
  the hold's real timer fires inside the sleep, so the release's check
  of whether the wait still binds, and its re-arming, run every time;
- pass(wait): the clock past the wait, after which the hold's next
  firing releases the held wake;
- advance(ms): the clock moved by less, for what is timed inside the
  wait (unreadable records are read again after a 50 ms interval).

Each held check also asserts that the hold has the wake (heldRequests),
or, after the sleep, that the hold stands. waitFor, the file's shared
poll, bounds itself with performance.now(): under a held Date a
Date.now() bound would never run out, and a release that never came
would hang the test instead of failing it at 5 s.

Converted: the 429 test and the non-retryable test with their later
wakes; the wake parked behind an auxiliary call; the hold that takes a
recorded deadline once the records read again (900 ms); a conversation
agent's stream, setup and throw variants; its non-retryable failure;
its disposal during a hold, which now moves the clock past the deadline
before its sleep instead of looping on Date.now(); the two retry tests,
whose waits are now 400 ms recorded during the error policy's 1 s retry
sleep (they were 2.5 s and 3 s); and the wait recorded while a turn
compiles.

The file's other stated waits are 60 s or longer, or a test checks no
later wake (the organization-acceleration test), or it waits by
sleeping (an ephemeral run's 300 ms wait).

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@nissa-seru nissa-seru added the no-changelog Exempts this PR from the changelog check (internal-only change) label Oct 17, 2026
@greptile-apps

greptile-apps Bot commented Oct 17, 2026 •

Copy link
Copy Markdown

RetriggerView in GreptileConfidence Score: 5/5 Tier: apex

[Low impact] This test-only change appears safe to merge.

Summary

Updates only test/provider-waits.test.ts to remove races between stated waits and slow test steps.

  • Provider-wait tests hold their clock still while real timers keep running.

No actionable issues found. Tests were not run during this review.

Reviews (1) · Last reviewed commit: "test(provider-waits): hold the clock sti..." · Reviewed by Greptile

…urn, and check that the hold keeps both

Under the held clock, the 429 test's arrival and the failed turn it
follows were stamped with the same Date.now(), so the hold kept them as
one request: sameInferenceRequest compares agent, reason, source,
timestamp and channel (src/framework.ts:3002), and counted the arrival
as the failed turn's duplicate. The test's check that the hold kept "a
request" then passed whether or not the arrival's own wake was held. A
real clock stamps the arrival later. The test now moves the held clock
1 ms before the arrival, as a real clock would, and checks that the
hold keeps both requests.

Found by Ramona-2416, whose run of the test showed one held request as
it was and two with the clock moved 1 ms.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
nissa-seru pushed a commit to nissa-seru/agent-framework that referenced this pull request Oct 17, 2026
@nissa-seru
nissa-seru merged commit 9467555 into anima-research:main Oct 17, 2026
6 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

no-changelog Exempts this PR from the changelog check (internal-only change)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant