Conversation
test-dup-setfl-race races a dup against an F_SETFL sweep for 700 rounds, which takes about 10s under ASAN on an idle host. The lane capped each test at 30s, and the CI runner shares its machine with a second runner, so contention pushed the test past the cap and the suite reported a hang that was not one. Raise the cap to 60s, which is what the TSAN leg already uses. The number lives in two places because CI never reaches the check-asan target: it sets TEST_TIMEOUT itself and calls check-sanitizer, so the makefile default governs only a local run. They are policy for two different machines and may legitimately differ. Leave job_timeout at 30 minutes. The failing job ran for 1m42s, so raising it would buy nothing and would only delay the report of a real deadlock.
![cubic-dev-ai[bot]](https://avatars.githubusercontent.com/in/1082092?s=60&v=4){kind=small}
There was a problem hiding this comment.
1 issue found across 6 files
Prompt for AI agents (unresolved issues)
Check if these issues are valid — if so, understand the root cause of each and fix them. If appropriate, use sub-agents to investigate and fix each issue separately.
<file name="tests/driver.sh">
<violation number="1" location="tests/driver.sh:420">
P2: The mark is a single load snapshot taken before the test starts, so the retry decision still misses the exact case this PR targets: contention that begins after the mark, mid-run (e.g. a neighbor job or build starting while the test is in flight), and decays below the threshold before the post-timeout check. That spike is invisible to the start snapshot and, once decayed, also fails the `|| test_host_is_busy` half, so rc==124 is reported as a hang with no retry. For a now-60s ASAN test the start reading is increasingly stale by watchdog time. Sample the load again during the timed region (not only at the start) so a spike that arrives after the mark is still captured.</violation>
</file>
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
| # "${array[@]}". Host-limit annotations live in the manifest. Keep this | ||
| # execution path generic so adding another constrained test does not require | ||
| # a name-qualified branch here. | ||
| test_host_busy_mark |
There was a problem hiding this comment.
P2: The mark is a single load snapshot taken before the test starts, so the retry decision still misses the exact case this PR targets: contention that begins after the mark, mid-run (e.g. a neighbor job or build starting while the test is in flight), and decays below the threshold before the post-timeout check. That spike is invisible to the start snapshot and, once decayed, also fails the || test_host_is_busy half, so rc==124 is reported as a hang with no retry. For a now-60s ASAN test the start reading is increasingly stale by watchdog time. Sample the load again during the timed region (not only at the start) so a spike that arrives after the mark is still captured.
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At tests/driver.sh, line 420:
<comment>The mark is a single load snapshot taken before the test starts, so the retry decision still misses the exact case this PR targets: contention that begins after the mark, mid-run (e.g. a neighbor job or build starting while the test is in flight), and decays below the threshold before the post-timeout check. That spike is invisible to the start snapshot and, once decayed, also fails the `|| test_host_is_busy` half, so rc==124 is reported as a hang with no retry. For a now-60s ASAN test the start reading is increasingly stale by watchdog time. Sample the load again during the timed region (not only at the start) so a spike that arrives after the mark is still captured.</comment>
<file context>
@@ -417,6 +417,7 @@ for i in "${filtered_idx[@]}"; do
# "${array[@]}". Host-limit annotations live in the manifest. Keep this
# execution path generic so adding another constrained test does not require
# a name-qualified branch here.
+ test_host_busy_mark
if host_nofile=$(elfuse_test_host_nofile "$TEST_LIST" "$name"); then
run_test_binary "$binary" "$host_nofile" \
</file context>
There was a problem hiding this comment.
Declining the mid-run sample, with the arithmetic.
For the gap to be real, a spike has to start after the mark and decay below
the threshold before the check. The 1-minute average has a 60s time constant,
so crossing back under the threshold takes roughly 24s of decay from 1.5x the
threshold, 42s from 2x, 66s from 3x. Inside a 60s watchdog that places the end
of the spike at or before the mark, which is precisely the case the mark was
added for. A spike brief enough to hide from both readings is also too brief
to have consumed the headroom the test had left.
The reasoning now sits in the comment above the pair in
tests/lib/bash-compat.sh so the next reader does not have to redo it.
Reviewing this did turn up a real error, though in the commit message rather
than the code. The body claimed the change closed run 33440761454. It does
not: under the 30s watchdog in force on that run, the mark and the check
average over windows that overlap by half, so the mark would most likely have
agreed with the check. The cap raised in f925a43 is the fix for that run, and
this is a second gap found beside it. Corrected in c22431d.
The per-test watchdogs re-run a timed-out test when the host is busy, so a run starved by a neighbour is not reported as a hang. The gate only ever read the load after the watchdog had fired. That reading is a 1-minute average, so contention that was already easing when the test started has decayed out of it by the time the test gives up, and the re-run never happens. Mark the load as the timed region starts and let the check afterwards accept either end. Two readings cover the window: the average decays with a 60s time constant, so a spike must end roughly 40s before a reading to fall under the threshold, which inside a 60s watchdog puts it at or before the mark. All three retry sites carried the same gap and now go through the pair. This is not what broke run 33440761454. No load figures survive from that runner, and under the 30s watchdog in force there the mark and the check average over windows that overlap by half, so the mark would most likely have agreed with the check. The cap raised in the previous commit is the fix for that run. This is a second gap the investigation turned up beside it. The state is lowercase and module-prefixed, matching hang_sample_out next door. Uppercase in these libraries means a caller-tunable knob, so reading one as internal state let a stray TEST_HOST_WAS_BUSY in the environment re-run every timeout. The mark runs before every test, so fold the predicate's two sysctl calls into one: sysctl takes several keys at once, which cuts six process creations per call to two.
1 participant
The ASAN leg went red on
https://github.com/sysprog21/elfuse/actions/runs/33440761454 with
test-dup-setfl-race reported as a hang after 30s. It was not hanging. The test
races a dup against an F_SETFL sweep for 700 rounds, which costs about 10s
under ASAN, and the self-hosted runner shares its machine with a second runner
(the workspace path is actions-runner-2), so contention carried it past the
cap.
The cap
30s left no margin for a test that needs 10s on an idle host, so it is now
60s, which is what the TSAN leg already uses. mk/tests.mk carries the matching
default for a local
make check-asan. job_timeout stays at 30 minutes, sincethe job ran for 1m42s.
This commit is the fix for the failing run.
The load gate beside it
The per-test watchdogs re-run a timed-out test when the host is busy, so a run
starved by a neighbour is not reported as a hang. That gate only ever read the
load after the watchdog had fired. Since the reading is a 1-minute average,
contention that was already easing when the test started has decayed out of it
by the time the test gives up, and the re-run never happens. The load is now
marked when the timed region starts and the check accepts either end. All
three retry sites (tests/driver.sh, tests/lib/test-runner.sh,
tests/test-sharun.sh) carried the same gap.
To be clear about what this does not claim: it is not the fix for run
33440761454. No load figures survive from that runner, and under the 30s
watchdog in force there the two readings average over windows that overlap by
half, so the mark would most likely have agreed with the check. It is a second
gap the investigation turned up, not the cause.
Since the mark runs before every test, the predicate's two sysctl calls are
folded into one, which cuts six process creations per call to two.
Reproduction
The CI failure is in the run linked above. Locally the test is slow rather
than stuck:
Host: macOS 26.6.2 (25G83), SDK 26.5, Apple clang 21.0.0, MacBookAir10,1
(Apple M1, 8 cores).
Status
make checkis otherwise green. Its one red, test-sharun's probe arm, failsidentically on an unmodified checkout of this tree: the toolchain sysroot on
this machine cannot resolve the probe's /lib/ld-linux-aarch64.so.1. That arm
passes on the release leg in CI.