Asked the wait abort test for three windows, and failed a run that reached none (#649)

Four CI runs of the same tree, twenty configuration-runs in total, show this
test's budget being reached far more often than the first green run suggested,
and a pass being reported every time it was:

    trace_build            3 of 10 windows in 121 seconds
    disable_notify         3 of 10 windows in 121 seconds
    default_coverage       4 of 10 windows in 121 seconds
    stack_checking         7 of 10 windows in 121 seconds
    trace_build            0 of 10 windows in 121 seconds
    disable_notify         7 of 10 windows in 121 seconds
    stack_checking         3 of 10 windows in 121 seconds

Seven of twenty, and the shortfall message only ever reaches an artifact:
ctest is run with --output-on-failure, so a passing test's output is not in the
job log at all. The suite has been quietly losing most of this test's coverage
in whole configurations and reporting green.

The loop runs in two modes, not one. A window arrives in milliseconds in the
fast mode, and costs between 17 and 40 seconds in the slow one, with nothing in
between across those twenty runs. Ten windows are therefore unreachable inside
any budget worth having: at 40 seconds each that is 400 seconds, and the
unbounded runs measured before any of this took up to 726. Raising the budget
to cover the slow mode would trade a quiet loss of coverage for five
configurations approaching the sixty minute step timeout.

So ask for what a run can reach. Three windows cost 51 to 120 seconds in the
slow mode and under a second in the fast one, and the later hits repeat what
the first ones establish, so what is given up is small. The budget goes to 180
seconds because three windows at the worst rate measured is exactly the 120 it
was, which would have truncated at two.

The count is printed on every run rather than only on a short one. A number
that appears only on shortfall cannot be told apart from a number nobody
recorded.

Reaching the window no times at all is a different matter, and was the worst of
the seven. The check after the loop compares semaphore bookkeeping that a
window has to have touched to mean anything, so a run that reached none of them
compares a counter against the value it was initialised to and reports a pass
having verified nothing. That run now keeps trying to a 300 second ceiling, and
fails if it still has not reached the window. A genuine resonance that holds
for five minutes is worth a failure; the old behaviour was worth nothing.

The SMP copy keeps its count of twenty. It reaches them in under half a second
in all five of its configurations, in all four runs, so the slow mode has never
been observed there and the coverage is free. Both copies get the ceiling and
the unconditional report, so the logic stays identical between them.

Verified locally on all five configurations: the test reaches 3 of 3 in 5 to 14
seconds, and the full suites pass 96 of 96 and 110 of 110 run one test at a
time. With the handler's window made unreachable and the ceiling lowered to 5
seconds, the test stops after 6 seconds, prints the count it reached, and
reports ERROR #8 with the harness recording a failure rather than a pass. With
the count raised past what the budget allows, a run that reaches two windows
still passes, so falling short and reaching nothing stay distinct. The
TX_NOT_INTERRUPTABLE branch, which no configuration in either suite builds, was
compile-checked in both copies with the configurations' own compile commands.

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Frédéric Desbiens
2026-08-20 11:11:31 -04:00
committed by GitHub
co-authored by Claude Opus 5
parent c8d27c4e25
commit e46b1b0787
2 changed files with 124 additions and 21 deletions
@@ -191,9 +191,39 @@ UINT status;
when the port's timer thread gets to run, so under load, or under coverage
instrumentation, ticks fall behind and never catch up. A budget of 20000
ticks, nominally 200 seconds, failed to stop a run that took 726 seconds,
because fewer than 20000 ticks had passed. time() does not drift that way. */
because fewer than 20000 ticks had passed. time() does not drift that way.
How many windows to ask for is set by what a run can actually reach. Four CI
runs of the same tree measured this loop in two modes: one where a window
arrives in milliseconds and every window asked for costs under a second in
total, and one where a single window costs around forty seconds. Seven of
twenty configuration-runs landed in the slow mode and ran out of budget,
reaching 0, 3, 3, 3, 4, 7 and 7 of the ten then asked for, every one of them
still reporting a pass. Asking for three keeps the count reachable in both
modes. The later hits repeat what the first ones establish, so the coverage
given up is small, and what is recorded is honest. This copy reaches its
twenty windows in under half a second in all five of its configurations, so
it keeps that count; the non-SMP copy, where the slow mode was measured, asks
for three.
Reaching the window no times at all is different in kind, which is what the
ceiling below is for. The check after the loop compares semaphore bookkeeping
that a window has to have touched to mean anything, so a pass with a count of
zero claims coverage the run did not have. One of those twenty runs did
exactly that, and said so only in an artifact nobody reads. A run that has not
reached the window once keeps trying up to the ceiling, and fails if it still
has not.
The budget is 180 seconds rather than 120 because of what the slow mode costs
per window. The seven truncated runs reached their windows at between 17 and
40 seconds each, so three of them can need 120 seconds, which is exactly what
the old budget allowed and would have truncated at two. 180 leaves margin at
the worst rate measured, and bounds five configurations at 15 minutes against
a 60 minute step timeout. Locally, where a window costs 2 to 5 seconds, three
of them take 5 to 14 seconds and the budget is never approached. */
#define WAIT_ABORT_WINDOWS_WANTED ((ULONG) 20)
#define WAIT_ABORT_SECOND_BUDGET ((ULONG) 120)
#define WAIT_ABORT_SECOND_BUDGET ((ULONG) 180)
#define WAIT_ABORT_ZERO_WINDOW_CEILING ((ULONG) 300)
time_t start_wall;
@@ -248,24 +278,46 @@ time_t start_wall;
}
/* Out of budget? */
/* Out of budget? A run that has not reached the window even once has
verified nothing yet, so it gets the higher ceiling before giving up. */
#ifdef TX_NOT_INTERRUPTABLE
if (((ULONG) (time(TX_NULL) - start_wall)) > WAIT_ABORT_SECOND_BUDGET)
break;
#else
if (condition_count == 0)
{
if (((ULONG) (time(TX_NULL) - start_wall)) > WAIT_ABORT_ZERO_WINDOW_CEILING)
break;
}
else if (((ULONG) (time(TX_NULL) - start_wall)) > WAIT_ABORT_SECOND_BUDGET)
break;
#endif
}
/* Clear ISR dispatch. */
test_isr_dispatch = TX_NULL;
if (condition_count < WAIT_ABORT_WINDOWS_WANTED)
/* Say what this run reached, on every run and not only a short one. A count
printed only on shortfall cannot be told apart from a count nobody
recorded, and this line is what the CI artifacts carry. Falling short is a
gap in what was exercised rather than a fault in the code under test, so
the check below still runs and still means what it did. */
printf("(reached %lu of %lu windows in %lu seconds) ",
(ULONG) condition_count, WAIT_ABORT_WINDOWS_WANTED,
(ULONG) (time(TX_NULL) - start_wall));
#ifndef TX_NOT_INTERRUPTABLE
/* Reached it no times? Then the check below compares bookkeeping no window
ever touched, and a pass would report coverage this run did not have. */
if (condition_count == 0)
{
/* Say what this run reached. Falling short is a gap in what was
exercised rather than a fault in the code under test, so the check
below still runs and still means what it did. */
printf("(reached %lu of %lu windows in %lu seconds) ",
(ULONG) condition_count, WAIT_ABORT_WINDOWS_WANTED,
(ULONG) (time(TX_NULL) - start_wall));
/* Test error! */
printf("ERROR #8\n");
test_control_return(4);
}
#endif
#ifdef TX_NOT_INTERRUPTABLE
/* At this point, check to see if we got all the semaphores! */
@@ -190,9 +190,38 @@ UINT status;
when the port's timer thread gets to run, so under load, or under coverage
instrumentation, ticks fall behind and never catch up. A budget of 20000
ticks, nominally 200 seconds, failed to stop a run that took 726 seconds,
because fewer than 20000 ticks had passed. time() does not drift that way. */
#define WAIT_ABORT_WINDOWS_WANTED ((ULONG) 10)
#define WAIT_ABORT_SECOND_BUDGET ((ULONG) 120)
because fewer than 20000 ticks had passed. time() does not drift that way.
How many windows to ask for is set by what a run can actually reach. Four CI
runs of the same tree measured this loop in two modes: one where a window
arrives in milliseconds and every window asked for costs under a second in
total, and one where a single window costs around forty seconds. Seven of
twenty configuration-runs landed in the slow mode and ran out of budget,
reaching 0, 3, 3, 3, 4, 7 and 7 of the ten then asked for, every one of them
still reporting a pass. Asking for three keeps the count reachable in both
modes. The later hits repeat what the first ones establish, so the coverage
given up is small, and what is recorded is honest. The SMP copy asks for
twenty and reaches them in under half a second in all five of its
configurations, so it keeps its count.
Reaching the window no times at all is different in kind, which is what the
ceiling below is for. The check after the loop compares semaphore bookkeeping
that a window has to have touched to mean anything, so a pass with a count of
zero claims coverage the run did not have. One of those twenty runs did
exactly that, and said so only in an artifact nobody reads. A run that has not
reached the window once keeps trying up to the ceiling, and fails if it still
has not.
The budget is 180 seconds rather than 120 because of what the slow mode costs
per window. The seven truncated runs reached their windows at between 17 and
40 seconds each, so three of them can need 120 seconds, which is exactly what
the old budget allowed and would have truncated at two. 180 leaves margin at
the worst rate measured, and bounds five configurations at 15 minutes against
a 60 minute step timeout. Locally, where a window costs 2 to 5 seconds, three
of them take 5 to 14 seconds and the budget is never approached. */
#define WAIT_ABORT_WINDOWS_WANTED ((ULONG) 3)
#define WAIT_ABORT_SECOND_BUDGET ((ULONG) 180)
#define WAIT_ABORT_ZERO_WINDOW_CEILING ((ULONG) 300)
time_t start_wall;
@@ -247,24 +276,46 @@ time_t start_wall;
}
/* Out of budget? */
/* Out of budget? A run that has not reached the window even once has
verified nothing yet, so it gets the higher ceiling before giving up. */
#ifdef TX_NOT_INTERRUPTABLE
if (((ULONG) (time(TX_NULL) - start_wall)) > WAIT_ABORT_SECOND_BUDGET)
break;
#else
if (condition_count == 0)
{
if (((ULONG) (time(TX_NULL) - start_wall)) > WAIT_ABORT_ZERO_WINDOW_CEILING)
break;
}
else if (((ULONG) (time(TX_NULL) - start_wall)) > WAIT_ABORT_SECOND_BUDGET)
break;
#endif
}
/* Clear ISR dispatch. */
test_isr_dispatch = TX_NULL;
if (condition_count < WAIT_ABORT_WINDOWS_WANTED)
/* Say what this run reached, on every run and not only a short one. A count
printed only on shortfall cannot be told apart from a count nobody
recorded, and this line is what the CI artifacts carry. Falling short is a
gap in what was exercised rather than a fault in the code under test, so
the check below still runs and still means what it did. */
printf("(reached %lu of %lu windows in %lu seconds) ",
(ULONG) condition_count, WAIT_ABORT_WINDOWS_WANTED,
(ULONG) (time(TX_NULL) - start_wall));
#ifndef TX_NOT_INTERRUPTABLE
/* Reached it no times? Then the check below compares bookkeeping no window
ever touched, and a pass would report coverage this run did not have. */
if (condition_count == 0)
{
/* Say what this run reached. Falling short is a gap in what was
exercised rather than a fault in the code under test, so the check
below still runs and still means what it did. */
printf("(reached %lu of %lu windows in %lu seconds) ",
(ULONG) condition_count, WAIT_ABORT_WINDOWS_WANTED,
(ULONG) (time(TX_NULL) - start_wall));
/* Test error! */
printf("ERROR #8\n");
test_control_return(4);
}
#endif
#ifdef TX_NOT_INTERRUPTABLE
/* At this point, check to see if we got all the semaphores! */