Repository navigation
test(ep-cpu): guard the blocktime deadline against a strided clock read - #1933
Conversation
#1868 removed a `spins.is_multiple_of(64)` gate from the blocktime deadline check in `worker_wait`'s yield phase, and #1825 removed the same construct from the readiness barrier before it. Neither landed with a test. Reinstating the stride at this site leaves the crate green -- 1695 passed, 0 failed -- so a third reintroduction would be caught by nothing. The obvious guard does not work. Shrink the deadline, assert the backstop fires, and it passes against the reinstated stride: an uncontended `yield_now` costs ~1.2us here, so a 64-yield stride moves the deadline ~78us, invisible against any deadline a test can afford to wait for. The defect only exists in a regime where yields are expensive, so the yield *cost* is the axis to inject, not the deadline. Injecting the deadline measures the wrong axis and looks exactly like coverage. `worker_wait` takes `blocktime` as a parameter, so a test calling it directly sidesteps the process-wide `OnceLock` blocktime latch with no plumbing. Add a `SLOW_YIELD_US` thread-local beside the knobs already there for this file, and a `YIELD_COUNT` for the observable. The observable is a yield count rather than a duration because a duration is not monotone under load. The first version of this test asked "was the worker parked when a bump landed at 400ms?"; it passed alone and failed beside 1695 siblings, because a starved thread can still be spinning at 400ms for reasons unrelated to the stride. Yield count is monotone in the safe direction: a starved thread accumulates wall time faster per yield, so it crosses the deadline in fewer yields, never more. Load can only push this test toward passing, and the one way it can go vacuous -- the deadline expiring before the yield phase, where both forms exit on yield 1 -- is asserted against rather than left to chance. Checked every yield: exits after ~BLOCKTIME/YIELD = 20 yields. Checked on a stride: exits after exactly 65, measured. `task_runtime/pool.rs`'s yield phase is the second #1868 site and remains unguarded; see the PR for why a thread-local cannot reach it. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
…phases #1919 landed a `SLOW_YIELD_US` for the readiness barrier while this branch was in flight, with an independently derived and identical rationale: the stride defect is only observable where yields are expensive, so the yield *cost* is what a test has to inject. The merge therefore produced two knobs of the same name (E0428) and two copies of that argument. Keep #1919's definition and its doc, extend it to say which thread reads it at each of the two sites, and point both injection sites at the one `slow_yield()` helper so the counter and the sleep cannot drift apart. Behaviour at the readiness barrier is unchanged -- same knob, same sleep -- plus a counter increment it does not read. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #1933 +/- ##
==========================================
+ Coverage 80.43% 80.92% +0.49%
==========================================
Files 409 424 +15
Lines 198253 207578 +9325
Branches 198253 207578 +9325
==========================================
+ Hits 159456 167981 +8525
- Misses 33355 33958 +603
- Partials 5442 5639 +197
Flags with carried forward coverage won't be shown. Click here to find out more.
🚀 New features to boost your workflow:
|
|
Post-hoc review (Holden). Merged 12:56Z with zero reviews; reviewing it now since it landed unreviewed. APPROVE — no findings at any severity. Mutation claim verified by execution, plus one observation that reflects back on #1965. Verified, not relayedReinstating the stride at Exactly one test, and it is this guard. Both legs confirmed to have actually recompiled ( A note on how I nearly patched the wrong site. My first attempt anchored on That is worth stating on this PR specifically: unifying two sites onto one helper is the right change and it also destroys the textual uniqueness that mutation tooling anchors on. Anyone mutating this file after #1933 needs a site-local anchor, not the yield idiom. The design holds up
One cross-PR observationThis test clears both knobs before it asserts, with the comment "a panic here would otherwise leave the knob set for whatever else libtest runs on this thread." That is exactly the panic-safety that #1965's new test lacks — it forces the planner gate and restores it only on the success path, so a failure leaks the gate in the one circumstance the test is built to hit. Same author, ~5 hours apart, correct here and not there. I raised it on #1965 as a nit and measured its blast radius at zero, so nothing is broken; the point of mentioning it here is that the discipline already exists in your own tree and just didn't transfer between two PRs in one evening. That is a cheaper thing to fix than either bug. Host: run under |
…he no-join contract an oracle Independent Opus review of this PR found that its headline regression test could not fail on the regression it is named for. Both defects are mine and both are the project's own false-oracle shape. 1. `the_deadline_is_checked_on_every_yield_not_on_a_stride` bounded elapsed time at 1000ms. At the injected 12ms per yield, a stride of 64 fires at ~780ms -- *under* that bound -- so the test passed with the #1933 defect reinstated. The comment even named the number and then put the bound on the wrong side of it. Fixed by discriminating on the yield count instead of elapsed time, which is the property rather than a proxy for it. A wall-clock bound has to sit above the healthy path (~110ms plus whatever the host adds) and below the strided signature (~770ms), an interval contention can close from below; at that point the test either reds on the host or gets widened past 770ms and silently stops catching the stride. The yield count has no such window: a stride of N cannot leave before its first multiple of N, and a slow host only makes each yield cost more wall clock, moving the count further from the failing value rather than towards it. Verified by reinstating the defect (`spins.is_multiple_of(CLOCK_CHECK_STRIDE) && ...` in the yield phase): the test now fails with "yielded 65 times ... not leaving before yield 64 is the signature of a strided check". 2. The no-join contract of `abandon_unready_workers` had no oracle at all. The injected held worker parks on `shared.shutdown`, the same flag the abandon path sets, so it is *cooperative*: a `join()` restored there returns promptly and every test stays green, while in production -- against the genuinely wedged worker this backstop exists for -- that join reintroduces the unbounded wait the PR removes. `HOLD_WORKER_IGNORES_SHUTDOWN_MS` models the worker that does not cooperate. Bounded rather than permanent so the thread does not leak into the rest of the binary or trip Miri's remaining-threads check; 4s against a 250ms deadline discriminates by 16x. Verified by re-adding the join: the new test fails at 4.0009s while all eight other tests still pass, which is the gap. 3. Both healthy-build negative controls now share one `PAIRED_DEADLINE_MS` constant with their positive test rather than repeating a literal. The control's whole claim is that *the same* deadline builds a healthy pool, so two independently editable numbers let it silently stop controlling for anything. Raised 250ms -> 1000ms in the same move: `mod tests` builds ~15 pools that do not take `INJECTION`, so a healthy worker could be starved past a 250ms deadline by an unrelated test -- an environmental red whose cheapest fix is to weaken the deadline. 4. The wedge diagnostic is asserted as "fewer than all of 3 announced" rather than the exact "2 of 3". Under emulation a second healthy worker can also still be short when the deadline fires; the claim that separates a wedge from a spawn failure is that the pool had its workers and they did not all announce, not the exact count. 5. `mlas-sys`' sibling module gains the `INJECTION` mutex, the shared deadline constant and the relaxed count assertion, which it was missing entirely. Verified: fmt, clippy -D warnings (x86_64 and aarch64 cross), 1751 ep-cpu + 43 mlas-sys lib tests, and the Miri task_runtime lane. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
…ils loud instead of burning cores (#2027) Closes #2067. ## What A thread-pool constructor waited for its workers to announce readiness with an **unbounded pure-spin loop**. One worker that dies or wedges before entering its loop makes the condition permanently unsatisfiable, and the builder then burns every core it holds *forever*. That is strictly worse than deadlocking quietly, because full occupancy is indistinguishable from work: an aarch64 qemu lane sat in it for **5h40m at ~1778% CPU** on a shared 32-CPU host and was noticed only by someone reading `/proc`. Two production sites had this shape: - `TaskPool::new` — `crates/onnx-runtime-ep-cpu/src/task_runtime/pool.rs` - `WorkStealingThreadPool::new` — `crates/mlas-sys/src/work_stealing_pool.rs` ### Correction to the original report The assignment named `build_with_schedule` in `decode_spmd.rs`. That barrier is **already bounded** — by #1825, with follow-ups #1845 and #1933 — and is untouched here. The two above were the genuinely unbounded ones. ## How Spin for a budget, then **yield**, then give up **loudly**, checking the deadline on **every yield**: - The stride is right for the spin phase, where an iteration costs nanoseconds and `Instant::now()` would dominate. It is wrong in the yield phase, where a yield under contention costs microseconds to milliseconds, so a stride of N multiplies the deadline's granularity by N yields of an already-starved thread. #1933 made exactly this correction to `decode_spmd`'s barrier. - On timeout, `abandon_unready_workers` publishes shutdown, bumps the epoch, wakes everyone, and drops the handles **without joining**. Joining would block on precisely the worker that is not coming, reintroducing the unbounded wait this exists to remove. - `TaskPool::new` panics; the mlas pool returns `io::ErrorKind::TimedOut`. `roy_validate.sh` step G2 gains a hard `timeout`, `taskset` confinement and bounded concurrency for the external aarch64 lane, so an unbounded wait there costs wall-clock rather than the host. Missing tools are **warned about**, never silently dropped. ## Instrumentation is free in production Every injection knob is `#[cfg(test)]` — thread-locals latched on the builder thread, and a `ready_yield()` whose entire body is `#[cfg(test)]`. Nothing new is read on a release path. ## Mutation evidence Every claim below was verified by reintroducing the defect and watching exactly one test go red. **All of these previously survived** the suite: | Mutation | Result | |---|---| | Strided clock check in the yield phase (ep-cpu) | `the_deadline_is_checked_on_every_yield_not_on_a_stride` — "yielded 65 times … not leaving before yield 64 is the signature of a strided check" | | Strided clock check (mlas-sys) | same test — "65 … more than 3x the 9 an every-yield check can take" | | `drop(handles)` → `join()` (ep-cpu) | `an_abandoned_worker_that_ignores_shutdown_does_not_delay_the_builder` | | `drop(workers)` → `join()` (mlas-sys) | same test | | Delete the `ready >= workers` race re-check (both) | `a_worker_that_announces_in_the_race_window_is_not_torn_down` — ep-cpu reports the self-contradictory "2 of 2 workers announced … never became ready" | ## Two independent reviews, and what they changed Both reviews found **false oracles in my own tests** — instruments whose failure value equalled their passing value. Fixed rather than deferred: **Opus.** The headline regression test bounded *elapsed time* at 1000 ms. At the injected 12 ms/yield a stride of 64 fires at ~780 ms — **under** that bound — so it passed with the #1933 defect reinstated. The comment even named the number and then put the bound on the wrong side of it. Now it discriminates on **yield count**, which is the property rather than a proxy: a wall-clock bound must sit above the healthy path (~110 ms plus whatever the host adds) and below the strided signature (~770 ms), an interval contention can close from below — at which point the test either reds on the host or gets widened past 770 ms and silently stops catching the stride. A stride of N cannot leave before its first multiple of N, and a slow host only makes each yield cost *more*, moving the count away from the failing value. Opus also found the **no-join contract had no oracle at all**: the injected held worker parks on `shared.shutdown`, the same flag the abandon path sets, so it is *cooperative* — a restored `join()` returns promptly and the suite stays green while production hangs. **Pris (tester).** Found that this PR closed the false oracles in **one of two identical barriers**: `mlas-sys` had no yield counter, no yield-cost injection and an unconditionally cooperative held worker, so both mutations survived its whole suite. Also found the **race re-check** (`ready >= workers`) uncovered in both, and that the no-join oracle was an absolute 2 s wall-clock bound in a test that runs under **qemu emulation** — an environmental red whose cheapest resolution is to widen it. The no-join oracle is now the worker's own **deaf flag**: correct code returns *during* the deaf window, a restored join only after it closes. Both sides scale with the host, so there is no threshold to breach. That flag is **generation-tagged**, which the first version got wrong and the test caught: a held worker from an earlier test outlives the constructor that abandoned it, and the store recording its exit can be descheduled past the next test's reset — two booleans reported the previous test's exit as this one's. ## Miri opt-outs, and why each is honest The Miri lane runs `--lib task_runtime::` **without** `-Zmiri-ignore-leaks`. - `a_pool_whose_workers_are_merely_slow_still_builds` — states a *race*: 150 ms of delay must outlast `SPIN_LOOP_BUDGET` spins. Miri's clock is virtual and a spin costs it no time, so the delay elapses inside the budget and the anti-vacuity guard fails on a healthy build. Weakening the guard would delete the only thing keeping the test from passing with the yield phase removed. The sibling tests need no opt-out and keep none: they inject a *hold*, so the builder exhausts the spin budget whatever a spin costs. - `an_abandoned_worker_that_ignores_shutdown_does_not_delay_the_builder` — leaves a deliberately deaf thread alive, which the remaining-threads check reports. - `the_live_scan_can_see_this_process` / `a_failed_build_leaves_no_workers_running` — `/proc` and a subprocess. The two properties that must stay covered under Miri **are**: wedge → fail loudly, and the every-yield check. Both run there with real spawned threads. ## Known limitation, disclosed rather than papered over The epoch bump in the abandon path is not deterministically covered. The teardown test only exercises workers already parked before `abandon`, which `wake_all` alone releases; the bump exists for a worker transitioning *into* the wait concurrently with `abandon`, which no test forces. It mirrors the established `shutdown()` publish-then-wake sequence. ## Validation `cargo fmt --check`; `clippy -D warnings` on x86_64 **and** aarch64 cross; **1752** `onnx-runtime-ep-cpu` + **46** `mlas-sys` lib tests; the **Miri** `task_runtime` lane. Run bounded (`taskset`, `-j4`) on a shared host. Full saturating qemu validation of step G2 is deliberately **not** run yet — it needs the host lock (#1806). Closes the hang described above. --------- Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Adds the regression test that #1868 should have shipped with, for the site #1868 fixed: the blocktime deadline in
SharedState::worker_wait's yield phase.The gap
#1868 removed a
spins.is_multiple_of(64)gate from that deadline check, and #1825 removed the same construct from the readiness barrier before it. Neither landed with a test. Grepping #1868's added lines for#[test]/assertreturns 0.Measured rather than assumed — with the stride reinstated at this site:
Before this PR that same mutation gives 1695 passed, 0 failed. A third reintroduction would be caught by nothing. The four adjacent tests are blind, one of them structurally:
dispatches_at_the_blocktime_boundary_keep_the_accounting_exactassertsspin_hits + parks == ops × workers, a conservation law — overshoot changes the split, never the sum, so it is invariant under the defect by construction.Why the obvious guard does not work
The natural test is "set a deadline below the injected delay, assert the backstop fires." That passes against the reinstated stride. @Gaff wrote it during review of #1868 and caught its vacuity only by mutating it.
The reason is a regime, not an assertion. An uncontended
yield_nowcosts ~1.2µs on this host, so a 64-yield stride moves the deadline by ~78µs — invisible against any deadline a test can afford to wait for. The defect's damage is proportional to the yield cost, so that is the axis this test injects. Injecting the deadline measures the wrong axis and looks exactly like coverage.worker_waittakesblocktimeas a parameter, so calling it directly sidesteps the process-wideOnceLockblocktime latch entirely — no plumbing needed.Why the observable is a yield count and not a duration
The first version of this test was flaky, and this is the substantive design point. It asked "was the worker parked when a bump landed at 400 ms?" — passed alone, failed beside 1695 siblings. A wall-clock observable is not monotone under load: a starved thread can still be in the spin phase at 400 ms for reasons unrelated to the stride.
A yield count is monotone in the safe direction: a starved thread accumulates wall time faster per yield, so it crosses the deadline in fewer yields, never more. Load can only push this test toward passing.
BLOCKTIME/YIELD= 20 yieldsSPIN_LOOP_BUDGET(4096) is a multiple of 64, so the strided form gets its first check free on yield 1 then goes blind for 64 more. That means the deadline must expire during the yield phase for this to discriminate at all — if it has already expired, both forms exit on yield 1. That vacuous regime is asserted against (yields >= 2) rather than left to chance, so it fails as "inconclusive" instead of passing as green. The release thread fires at 1200 ms, deliberately later than the defective form's own 650 ms exit, so it can never truncate the defective run and mask it.Assertion band is
2 <= yields < 64against a measured 20 (healthy) and 65 (defective) — 3.2× margin.What this does not cover
task_runtime/pool.rs's yield phase is the second #1868 site and remains unguarded. Saying so plainly so it does not look covered:worker_loopon spawned worker threads, so a thread-local knob cannot reach it;spin_windowmust first be grown past ~128µs (4096spin_loops) before the yield phase is reachable at all;DELAY_WORKER_BEFORE_READY_MScomment documents a real cross-test corruption from one.Closing it needs the blocktime made overridable per-pool and plumbed through
build_with_schedule. #1919 guards the readiness barrier (#1825's site), which is also not this one.Validation
Run under
scripts/hostlock.shwithtasksetoutermost andCARGO_INCREMENTAL=0. Not claiming an absolutely quiet host — measured efficiency is reported by the lock and the observable was chosen to be load-monotone precisely because quietness cannot be assumed.clippy --all-targets -- -D warningscargo fmt --checkOne validation trap worth repeating
The three repeat runs initially failed on restored source. Cause: restoring the backup with
mvgave the file the backup's older mtime, so cargo saw a source older than its artifacts and silently reused the mutated binary — the grep on the source said "fixed" while the binary under test was not. Proof: the test binary's mtime never advanced across all three runs.cp X X.bak; mutate X; mv X.bak Xis unsafe for mutation testing. Here it produced a false failure, which is the safe direction; the same trap on the mutate leg produces a false pass — "the test catches the defect" while running the healthy binary. Usecpback, ortouchafter restoring.Review and the regime insight: @Gaff. Closes the review item on #1868.
Update: converged with #1919's knob
#1919 merged while this was in flight and added its own
SLOW_YIELD_USfor the readiness barrier — independently derived, with an identical rationale ("injecting the yield cost makes the same regime deterministic"). Two people reaching the same conclusion from opposite ends of the file is reasonable evidence the regime argument is right.The merge produced two knobs of the same name (
E0428). Resolved by keeping #1919's definition and pointing both yield phases at the singleslow_yield()helper, so the sleep and the counter cannot drift apart. The readiness barrier's behaviour is unchanged — same knob, same sleep, plus a counter it does not read.Re-validated on the merged tree:
clippy --all-targets -- -D warningscargo fmt --check#1919's own readiness-barrier test still passes through the shared helper.
(The first version of that table reported
clippy_exit=0from a harness that captured$?after a pipe — i.e.tail's status, not clippy's. Same defect class as the one this PR guards: a check reporting more than it measured. Fixed and re-measured before publishing.)