Repository navigation
test(perf): the process-offload heartbeat asserts a 7.5ms absolute ceiling, so runner load and a real regression are indistinguishable #15221
Description
Activity
Verified in merged
Dev_new_gui— closingPR #15248 merged as
9f08f7950.Closesdoes not fire on this branch, so closing by hand against code read from the merged base.Criterion Verdict Evidence No absolute millisecond ceiling MET process_offload_test.py:130_TICK_BUDGET_VS_IDLE = 1.5, a ratio against the heartbeat's own idle baseline; the oldin_process < 0.005 * 1.5survives only in the docstring at:27recording what it replacedA genuine regression still fails MET Forcing the scan in-process gives 1.994x its own idle baseline (budget 1.5). Traced independently in review: three separate paths catch it, and:123_MIN_TICKS_PER_WINDOW = 10fails loudly rather than skipping if the loop is starvedDoes not fail under runner load MET, bounded Five runs read 0.992–1.012 against 1.5 Vacuity probe MET Zero, negative, absent measurement and zero baseline all fail; a positive control proves the assertion is not one that always fails Sweep the file and the tree MET Exactly one absolute wall-clock assertion existed in code_intelligence/, the one replacedWhy the #15207 calibration could not be reused, measured rather than assumed
A CPU work unit fails this quantity twice. Timed during the scan it is starved by the very contention under test, so numerator and denominator inflate together and the detector cancels itself. Timed outside it, six consecutive samples swung 1.43–3.27 ms — a 2.3× spread in the denominator alone, wider than the 2.0× signal it must resolve. The heartbeat's own idle baseline held to ±1.4% over the same samples.
So the calibration transfers in form — ratio, recorded every run, vacuity-guarded, down-only — but not in yardstick.
The claim was corrected before merge
The first version argued a false failure was impossible: under external delay
Lthe ratio is1 + tax/(5+L), strictly decreasing inL. An independent review found the premise unstated and not guaranteed — the baseline and measurement windows are temporally disjoint over a second or two, on a machine that is also the CI runner, so a burst confined to the measurement window inflates the numerator alone.perf_work_budget.py:174-183now states that premise and names the residual case, closing with the honest bound: "much less likely", not "impossible", and a red here is not on its own proof of a regression. Two caller caveats live in the shared helper where the next contention site will read them — the settling gap, and that a median answers "did the typical sample move", so a minority-delaying regression will not move it.One thing it found on the way
pytest.skip("process pool unavailable here")could never fire: the helper reset_pool_unavailable_reasontoNonebefore the caller read it, so on a host forbidding process creation the test reported a regression that was really an environment — the same confusion this issue is about, one layer down. The reason is now captured before the reset, and the fix was verified to skip only for a genuinely unavailable pool, never for a real regression.Reopening — I closed this on evidence that did not cover the path it actually fails on
Second sighting, independently identified while investigating unrelated red checks on PR #15265 (
python-suite shard 10/12, job 99064521827):AssertionError: the heartbeat produced 1 ticks while the scan ran — fewer than 10, so there is no median to compare and the measurement is meaninglessWhat I got wrong
I marked the criterion "does not fail under runner load" as MET, citing five runs reading 0.992–1.012 against a 1.5 budget. That evidence was about the ratio, and the ratio is holding — it is not producing false regressions. But the test still goes red under load, through
_MIN_TICKS_PER_WINDOW = 10(process_offload_test.py:123), a precondition I added in the same PR and described in the closure as failing loudly rather than skipping.So I measured the half I had changed and reported the criterion met, when the criterion is about the test's behaviour as a whole. A starved event loop on a shared runner still turns this red, which is the same class of confusion this issue was filed about — an environment condition presenting as a code failure. Different mechanism, same outcome for whoever reads the check.
An earlier failure on PR #15260 was probably also this test; I could not retrieve the log then and correctly declined to attribute it. This one is attributable.
The design question, which is not obvious
"Fail loudly rather than skip" was a deliberate choice and I still think skipping is wrong — a skip on a starved runner is how a real regression hides, and
pytest.skipwas already found to be unreachable here once (fixed in #15248). But failing on starvation is also wrong, because starvation is not evidence of a regression.Both branches of the obvious dichotomy are wrong, which suggests the dichotomy is. A measurement that could not be taken is neither a pass nor a failure — it is a retry. Bounded re-measurement (take the window again, a small fixed number of times, fail only if every attempt starves) distinguishes "this runner is momentarily busy" from "this loop is persistently starved", and the latter is worth a red.
Concrete fix tracked in #15266, which has the failure detail. This issue stays open until the criterion holds in fact, not by argument.
Not closing again without
- A run where the loop is deliberately starved and the test still reaches a verdict rather than erroring on the precondition.
- The distinction stated in the test itself, so the next reader does not have to reconstruct why a retry is neither a skip nor a pass.
Closing again — this time the criterion holds in code, not by argument
PR #15279 merged as
b85fc0331. I reopened this because I had reported "does not fail under runner load" as met on evidence that only covered the ratio. Verified per condition this time.Condition I set when reopening Verdict Evidence A deliberately starved loop reaches a verdict rather than erroring on the precondition MET, with a stated limit test_scan_only_starvation_fails_on_the_first_attempt_without_retrying(process_offload_test.py:446) starves the scan window and the test reaches a verdict — a regression, on attempt 1The distinction stated in the test itself MET :240"raises MeasurementStarved instead: retried, not failed outright", and:252"this failure is not retried."What actually fixed it
Not a retry alone — a discriminator. The two measurement windows mean opposite things, and the code now uses that:
if busy_starved and not idle_starved: # process_offload_test.py:246- Idle window healthy, scan window starved → the loop was fine until the scan ran, so the scan is what stopped it. Raises a plain
AssertionError, whichmeasure_with_starvation_retry(catching onlyMeasurementStarved) structurally cannot intercept. Scored on attempt 1, like any ratio failure. - Both starved → nothing pins it on the scan. Raises
MeasurementStarved, retried to_MAX_STARVATION_RETRIES = 3, then fails with wording naming contention.
That is the distinction this issue was filed to establish: runner load and a real regression are no longer indistinguishable.
The honest limit
For genuine both-window starvation the test still ends on the precondition rather than a ratio verdict — it must, because no measurement was taken. What changed is that this outcome is now distinguishable: it takes three attempts and says so, where a regression fails once and says something different. My reopening condition, read literally, asked for a verdict in every starvation case; that is not achievable and would not be desirable, since inventing a ratio from an unmeasurable window is exactly the vacuity this test guards against.
Found by review, and fixed rather than documented
The first version had the retry wrap the measurement while the ratio assertions sat outside it — correct for ordinary regressions. But a total-blockage regression (a scan running synchronously on the loop) starves the busy window before any measurement exists, so it tripped the starvation branch, retried three times, and failed with "starved on all 3 attempts" — the message that most reads like contention, produced by the most severe regression. CI still went red, so nothing could merge on it, but a triager would have been sent the wrong way. The discriminator above is what closed that.
Not weakened to pass
_MIN_TICKS_PER_WINDOW = 10(:128),_TICK_BUDGET_VS_IDLE = 1.5(:142) and the window lengths are byte-identical to base. Only the response to a failed precondition changed. Nothing was quarantined, no window was widened, and nopytest.skipwas introduced — a skip is how a real regression hides, andpytest.skipin this very file was already found unreachable once and fixed in #15248.- Idle window healthy, scan window starved → the loop was fine until the scan ran, so the scan is what stopped it. Raises a plain
Found blocking PR #15158. Same defect class as #15055, in a file that PR #15207's sweep did not cover.
What
autobot-backend/code_intelligence/shared/process_offload_test.py::test_a_scan_in_a_process_does_not_delay_the_event_loopasserts an absolute wall-clock budget:A 7.5 ms ceiling on a 5 ms heartbeat — 1.5× headroom — measured on a machine that is also the CI runner and routinely has several suites in flight.
Evidence that it is load, not the diff
autobot-backend/api/chat_sessions_enforcement_degrade_test.pyandautobot-backend/security/session_ownership_enforcement_mode_test.py. Neither touches process offload, the event loop, or anything the test exercises.Why this one is worse than an ordinary tight budget
The test's own failure message is "something is still contending for this process", and that is precisely what it exists to detect: that the scan really was offloaded rather than blocking the loop. A genuine regression and a busy runner produce the same symptom, so the test cannot distinguish the defect it guards from the environment it runs in. That is the same structural problem #15055 described, expressed as a contention measure rather than a startup measure.
1.5× headroom makes it worse than #15055's, which had ~7% and still flaked. This one flakes at any real load.
The remedy already exists in base
PR #15207 (
021219a21,Refs #15055) converted 20 absolute budgets insystem_benchmarks_performance_test.pyinto ratios against a work unit — a fixed slice of pure-Python work timed in the same process at the same moment — so a uniformly slow runner scales both sides. The harness isautobot_shared/perf_work_budget.py. Its regression sensitivity was demonstrated: after calibration a 1.8 ms addition to a constructor still fails.This site needs the same treatment, with one wrinkle worth thinking about: the quantity here is contention, not duration. The heartbeat's delay relative to a calibrated unit is the natural measure, but confirm that a real offload regression still fails once calibrated — the point is to keep the detector, not to widen it.
Acceptance criteria
code_intelligencetree, for other absolute wall-clock assertions. Report the count. test(perf): startup benchmarks assert absolute wall-clock budgets and fail on runner load — passed and failed on the same code minutes apart #15055's file held 20 where one was suspected.Refs #15055, PR #15207, PR #15158.