Skip to content

tests: a budget for the strand-race case sized from what it costs, not the blanket 120 s it was never measured against (fixes #760) - #779

Merged
Yaraslaut merged 1 commit into
masterfrom
strand-race-timeout
Sep 23, 2026
Merged

Yaraslaut merged 1 commit into
masterfrom
strand-race-timeout

Conversation

@Yaraslaut

@Yaraslaut Yaraslaut commented Sep 23, 2026

Copy link
Copy Markdown
Member

fixes #760 — the strand-race case was being killed while passing, by a ceiling that was never chosen with it in mind.

The defect is the ceiling, not the test

tests/CMakeLists.txt:225
catch_discover_tests(morph_tests DISCOVERY_MODE PRE_TEST PROPERTIES TIMEOUT 120)

One blanket 120 s over all 2966 Catch2 cases in morph_tests, justified in the comment above it by "every test is sub-second in practice". That is true of 2965 of them. The longest, most load-sensitive case in the binary was governed by the same number as the cheapest.

What the case actually costs, measured

It is not slow because it computes anything. StrandExecutor never runs two tasks for one key concurrently under contention serialises 8 × 400 = 3200 tasks per iteration through one strand, and every handoff is a thread wakeup that has to wait its turn on the run queue. Its cost is therefore set by how contended the host is, not by the work.

12 cores, clang 22.1.8 Release (linux-everything), load generated with plain while :; do :; done spin loops, whole-case wall clock, one run each:

load run queue wall
none (idle) 1 0.136 s
12 spin loops 14 23.8 s
24 spin loops 27 170.5 s
36 spin loops 38 396.4 s

Steeply superlinear: 12→24 spin loops costs 7.2×, 24→36 another 2.3×. The load average at the 36-spinner measurement was 31–38, against morph#760's reported 29–48.

Every one of those runs passedAll tests passed (40 assertions in 1 test case), with inFlight 1, maxInFlight 1 in every watchdog line. The invariant the case exists to check never wavered at any load. What the 120 s cap was killing was a passing test.

The control, at the old ceiling

Same load, capped at 120 s:

load36 run 1: rc=124 wall=120.014 s
    last watchdog: iteration 5, phase 'draining (~StrandExecutor)', 10 s into
    the iteration, completed 1975/3200, inFlight 1, maxInFlight 1
load36 run 2: rc=124 wall=120.018 s   (reached iteration 6)
load36 run 3: rc=124 wall=120.021 s   (reached iteration 6)

Catch2 reports SIGTERM - Termination request signal, not a failed assertion; 12 of 12 assertions evaluated up to that point had passed. morph#760 saw four iterations in at 120 s under a heavier load average; six here. Same shape.

What this does not do

kIterations is untouched at 20.

That is the cheap fix and it is the wrong one. Twenty iterations is this case's detection power for a rare drain-and-re-arm interleaving; a strand-race detector with too few iterations approaches "would this still pass if the feature did nothing?", which AGENTS.md names first. The budget moved instead, and both constants now say so in the source rather than leaving the next reader to rediscover it.

The budget

[slow] is excluded from the blanket and registered again with its own TIMEOUT 900 — the mechanism #589/#590 already established in this file, because DISCOVERY_MODE PRE_TEST defers discovery to ctest invocation time and set_tests_properties() has nothing to name at configure time.

Why 900:

  • ~2.3× the measured 396.4 s.
  • Fitting the curve to a run queue of ~50 — the top of morph#760's reported load average — gives roughly 730 s, so ~1.2× that too.
  • It is already the number this same file uses for its other load-sensitive case, forms_schema_generation_is_not_route_count_sensitive, chosen there for the same reason ("a slow shared runner can be several times that").

What it is not: immunity. Past roughly 4.5× oversubscription this will exceed 900 s as well. A fixed ceiling cannot bound an unbounded load, and the comment says so. What it still catches is a deadlock — unbounded, not merely large — in 15 minutes instead of 2, for one test out of 3044.

The tag is load-bearing, and that was checked rather than assumed

ctest --show-only=json-v1, same tree, tag added and removed:

with    [slow]: 3044 tests, {120.0: 2966, 900.0: 2, 300.0: 2, 60.0: 2}
                strand case TIMEOUT 900.0
without [slow]: 3044 tests, {120.0: 2967, 900.0: 1, 300.0: 2, 60.0: 2}
                strand case TIMEOUT 120.0
  • Same total either way, and zero duplicate names — splitting one catch_discover_tests call into ~[slow] and [slow] neither drops a test nor registers one twice. That is the failure mode this mechanism has: a TEST_SPEC that silently selects nothing, or two that overlap.
  • Its neighbour in the same source file, StrandExecutor keeps one strand per key when a post races the drain, stays at 120 — the widening is one case, not one file.
  • Catch2 tags are never translated into ctest labels anywhere in this repository (no catch_discover_tests call passes ADD_TAGS_AS_LABELS; ci.yml states this at the TSan leg), so [slow] cannot change what any -L/-LE filter selects.

Proved where it has to hold

morph#760's close condition is that the case survive a full ctest -j $(nproc) under load comparable to the reported run. Full suite at -j 12 with 24 spin loops competing for the same 12 cores, in four foreground ranges, load average 17 → 37 across them:

-I 1,1000     CTEST_EXIT=0   60 s   100% tests passed out of 1000
-I 1001,1800  CTEST_EXIT=0  274 s   100% tests passed out of 800
-I 1801,2600  CTEST_EXIT=0  233 s   100% tests passed out of 800
-I 2601,3044  CTEST_EXIT=0   30 s   100% tests passed out of 444

and in the range that holds it:

799/800 Test #1651: StrandExecutor never runs two tasks for one key
concurrently under contention ............................ Passed  188.43 sec

188.43 s — a hard timeout at 120, comfortably inside 900. That one line is the defect and the fix together, under the load the issue asks the case to survive.

Gates

linux-everything (clang 22.1.8, Release, every optional feature on), after the final edit, exit codes captured directly and never through a pipe.

Gate Result
clang-format --dry-run -Werror, whole tree files: 796 / FORMAT_EXIT=0
clang-tidy-diff.py over git diff -U0 origin/master...HEAD TIDY_EXIT=0
Doxygen --target doc, WARN_AS_ERROR=FAIL_ON_WARNINGS DOC_EXIT=0
ctest -j 12, all 3044, under 24 competing spin loops 4/4 ranges exit 0, 100% passed
ctest --show-only=json-v1, tag present vs absent 900 vs 120 on the one case, 3044 both ways

The tidy gate is not vacuous. It is run against origin/master...HEAD (the merge base), not HEAD — see morph#776 for why that distinction cost a red CI cycle on morph#768 this week — and it was checked by injection on this branch:

--- clean ---
TIDY_EXIT=0
--- injected: `int q = 0;` on a new line ---
TIDY_EXIT=1
tests/test_strand_race.cpp:202:5: error: variable 'q' of type 'int' can be
declared 'const' [misc-const-correctness,-warnings-as-errors]
--- restored ---
TIDY_EXIT=0

Findings left for their own issues, not folded in

  • morph#780 — the superlinearity itself. 3× the competing threads costs 17× the wall clock, an exponent of ~2.1 where a scheduler-latency story predicts ~1. morph#760's own "re-frame as a StrandExecutor defect if the drain rate degrades beyond what the scheduler explains" clause points straight at it, and three data points on one machine are not enough to answer it — that wants a perf sched split, not a timeout change. Filed with the measurements, the alternatives not ruled out, and the experiment that would settle it. morph#760 is closed by this PR, so it could not stay there.
  • morph#760 also lists two other load-sensitive cases seen timing out in the same run (forms_schema_generation_is_not_route_count_sensitive, bench: RemoteServer dispatch throughput and latency). Neither is in morph_tests' blanket — the first already carries TIMEOUT 900 RUN_SERIAL TRUE — so neither is fixed or affected here.

Base

Branched from c4e21233. origin/master has since moved to ce1f6193 (morph#773), whose delta is tests/net/** only — disjoint from the two files here. No conflict, no rebase.

🤖 Generated with Claude Code

https://claude.ai/code/session_01VptDWG2fKr2vBnLSJcgzgW

@codecov

codecov Bot commented Sep 23, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.

📢 Thoughts on this report? Let us know!

… costs, instead of the blanket 120 s it was never measured against (fixes #760)

`catch_discover_tests(morph_tests ... PROPERTIES TIMEOUT 120)` applied one
ceiling to all 2966 cases in the binary. The longest, most load-sensitive case
in it was governed by the same number as the cheapest, and that number was
chosen against "every test is sub-second in practice" -- true of the other
2965.

The case is not slow because it computes anything. It serialises 3200 tasks per
iteration through one strand, and every handoff is a thread wakeup that has to
wait its turn on the run queue, so its cost is set by how contended the host is.
Measured on this tree, 12 cores, clang 22.1.8 Release, load generated with plain
spin loops, whole-case wall clock, one run each:

    run queue  1 (idle)  ->    0.136 s
    run queue 14         ->   23.8 s
    run queue 27         ->  170.5 s
    run queue 38         ->  396.4 s     (load average 31-38 at measurement)

Steeply superlinear -- 12 spin loops to 24 costs 7.2x, 24 to 36 another 2.3x --
and **every one of those runs passed**: 40 assertions, `inFlight 1,
maxInFlight 1` throughout. The invariant the case exists for never wavered at
any load. The 120 s ceiling was killing a passing test, which is a false red
and, on shared hardware, eventually a false red on somebody else's PR.

The same measurement with a 120 s cap, for the control:

    load36 run 1: rc=124 wall=120.014 s
        last watchdog: iteration 5, phase 'draining (~StrandExecutor)', 10 s
        into the iteration, completed 1975/3200, inFlight 1, maxInFlight 1
    load36 run 2: rc=124 wall=120.018 s   (reached iteration 6)
    load36 run 3: rc=124 wall=120.021 s   (reached iteration 6)

morph#760 reported four iterations in at 120 s under load average 29-48; six
here at 26-38. Same shape.

## What was not done

`kIterations` is untouched at 20. It is this case's detection power for a rare
interleaving, not a duration knob, and cutting it to fit a ceiling would make
the case cheaper and worse at the only thing it is for. The budget moved
instead. Both constants now say so in the source.

## The budget

`[slow]` is excluded from the blanket and registered again at `TIMEOUT 900` --
the mechanism #589/#590 already established here, because `DISCOVERY_MODE
PRE_TEST` defers discovery to ctest invocation time and `set_tests_properties()`
has nothing to name at configure time.

900 s is ~2.3x the measured 396 s. Extrapolating the curve to a run queue of
~50 -- the top of morph#760's reported load average -- gives roughly 730 s, so
it is ~1.2x that too. It is also the number this same file already uses for its
other load-sensitive case, `forms_schema_generation_is_not_route_count_
sensitive`, chosen there for the same reason.

It is a ceiling, not immunity: past roughly 4.5x oversubscription this will
exceed 900 s as well. What it still catches is a *deadlock*, which is unbounded
rather than merely large -- in 15 minutes instead of 2, for one test out of
3044.

## Verified

The tag is load-bearing, not decorative. `ctest --show-only=json-v1`:

    with    [slow]: 3044 tests, {120.0: 2966, 900.0: 2, 300.0: 2, 60.0: 2},
                    strand case TIMEOUT 900.0
    without [slow]: 3044 tests, {120.0: 2967, 900.0: 1, 300.0: 2, 60.0: 2},
                    strand case TIMEOUT 120.0

Same total either way and zero duplicate names, so splitting the discovery call
in two neither drops a test nor registers one twice. Its neighbour in the same
file, `StrandExecutor keeps one strand per key when a post races the drain`,
stays at 120.

Catch2 tags are never translated into ctest labels anywhere in this repository
(no `catch_discover_tests` call passes `ADD_TAGS_AS_LABELS`; ci.yml says so at
the TSan leg), so `[slow]` cannot change what any `-L`/`-LE` filter selects.

## The budget proved where it has to hold

Full `ctest -j 12` with 24 spin loops competing for the same 12 cores, in four
foreground ranges, load average 17 -> 37 across them:

    -I 1,1000     CTEST_EXIT=0   60 s   100% tests passed out of 1000
    -I 1001,1800  CTEST_EXIT=0  274 s   100% tests passed out of 800
    -I 1801,2600  CTEST_EXIT=0  233 s   100% tests passed out of 800
    -I 2601,3044  CTEST_EXIT=0   30 s   100% tests passed out of 444

and in the range that holds it:

    799/800 Test #1651: StrandExecutor never runs two tasks for one key
    concurrently under contention ... Passed  188.43 sec

188.43 s is a hard timeout at 120 and passes comfortably at 900 -- the defect
and the fix in one line, under the load the issue asks the case to survive.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VptDWG2fKr2vBnLSJcgzgW
@Yaraslaut
Yaraslaut merged commit 9030d13 into master Sep 23, 2026
24 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

tests: test_strand_race.cpp's contention case blows ctest's 120 s timeout without any sanitizer, on a loaded machine (morph#717 follow-up)

1 participant