Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
164 changes: 132 additions & 32 deletions .github/workflows/ci.yml
Original file line number Diff line number Diff line change
Expand Up @@ -315,7 +315,7 @@ jobs:
# THAT GUARANTEE COVERS THE FIRST GATED STEP ONLY, and saying otherwise would be a control resting
# on a false premise. `Web console tests (pytest)` carries the SAME `step_timeout` but runs after
# `Tests (pytest)`, so reaching it has already spent setup + `Tests`; its own cap cannot fire first
# at any job_timeout worth setting (it would take ~39 min on ubuntu, ~73 min on Windows). A hang
# at any job_timeout worth setting (it would take ~55 min on ubuntu, ~114 min on Windows). A hang
# THERE is still an unattributed job-level kill. Measured under `Tests (pytest)` below; the
# structural fix is BACKLOG #344 proposal 5.
#
Expand All @@ -336,15 +336,41 @@ jobs:
# durations as step durations while triaging this (c53f752b's JOB ran 28:41 and PASSED, because
# job cap 30 vs step cap 26).
#
# POOL: every run of THIS workflow created on 2026-08-01 UTC -- 70 runs. Enumerated with
# `gh api --paginate` over a deliberately WIDER window and filtered locally on `created_at`, then
# cross-checked against the narrow `?created=` query (same 70 ids, symmetric difference 0). Rows
# are each leg's `Tests (pytest)` step, kept when THAT STEP concluded success. n is per leg.
# POOL: every run of THIS workflow created 2026-08-01T00:00Z .. 2026-08-09T00:00Z UTC -- 688 runs.
# Enumerated with `gh api` over a deliberately WIDER page range (1,000 runs, back to 2026-07-26) and
# filtered locally on `created_at`. Jobs fetched with `?filter=all`, so an attempt killed at the cap
# is not hidden behind its passing re-run. Rows are each leg's `Tests (pytest)` STEP, kept when THAT
# STEP concluded, executions under 60s dropped (a docs-only PR skips the leg). 1,618 leg-executions;
# n below is per leg, passing rows only. Measured 2026-08-08 (BACKLOG #1096).
#
# leg max passing step n old cap old margin
# ubuntu-latest 12:31 42 19:00 1.518x
# windows-2022 21:34 39 26:00 1.206x
# windows-2025 25:51 36 26:00 1.006x <- NINE SECONDS
# leg max passing step n old cap old margin new cap new margin
# ubuntu-latest 16:08 441 19:00 1.178x 25:00 1.550x
# windows-2022 29:23 399 36:00 1.225x 55:00 1.872x
# windows-2025 35:47 CENSORED 360 36:00 1.006x 55:00 1.537x
#
# ONLY THE WINDOWS-2025 ROW IS CENSORED, AND THAT IS MEASURED, NOT ASSUMED. Largest ubuntu step
# FAILURE in 535 leg-executions is 14:21; largest windows-2022 failure in 542 is 25:48. Neither leg
# has ever touched its cap, so 16:08 and 29:23 are true maxima. windows-2025 was killed at the cap
# SEVEN times in this window -- 36:08 (31189317409, main b78214f5), 36:08 (31199321840, main
# 7ecff8ae), 36:08 (31202372465, PR #253), 36:07 (30955150892, 2026-08-04, the earliest), 36:07
# (31094875320, main fdec72ca), 36:07 (31192717684, PR #249), 36:01 (31149117314, PR #261) -- THREE
# of them push runs on main. So 35:47 is the largest step that FIT in 36:00, and 36:08 is a lower
# bound on the largest the suite wants. Smaller pools give smaller counts and each is right for its
# own pool: BACKLOG #1096's day pool has five, a 3-day pool has six. State the pool with the count.
#
# THE KILLS WERE SLOWNESS, NOT A WEDGE -- CHECKED, NOT ASSUMED. Run 31149117314's pytest finished
# GREEN and the step was killed 4.85 seconds later:
# 05:37:53.777Z 10666 passed, 831 skipped, 22 warnings in 2148.75s (0:35:48)
# 05:37:58.624Z ##[error]The action 'Tests (pytest)' has timed out after 36 minutes.
# No faulthandler native-stack dump appears in any kill log. That settles the hang-versus-slow
# question the #55 note above would otherwise leave open, and it has a second consequence that is
# easy to miss: the killed rows are genuine population members, so "max passing" is CENSORED, not
# conservative. Every ratio taken against it flatters itself.
#
# SUPERSEDED READING, kept because a number without its pool cannot be rechecked: the 2026-08-01
# pool (70 runs, pre-#131) read ubuntu 12:31 / W22 21:34 / W25 25:51 against the then-current
# 26:00 Windows cap. Those figures are correct for that pool and that code state. They are not
# comparable to the rows above, which are post-#131 and span eight days.
#
# THESE MAXIMA ARE LOWER BOUNDS, BECAUSE THE POOL IS RIGHT-CENSORED. Every run in it predates #131
# (28d186b5, landed 2026-08-02T00:35:28Z), so Windows ran under step 26:00 / job 30:00 and ubuntu
Expand Down Expand Up @@ -395,22 +421,54 @@ jobs:
# see" is not a diagnosis here. A green re-run at 26:00 does not mean the suite fits; it means
# that runner was fast enough that time.
#
# 36:00 is 1.393x over the 25:51 that fit under the old cap, and 1.364x over 26:23, the largest
# windows-2025 execution actually observed. Use the second number: a ratio against a censored
# maximum flatters itself.
# THE CAP IS SIZED ON THE POST-#1027 POPULATION, NOT ON WHAT RUNS TODAY. PR #253 (BACKLOG #1027) is
# open and MERGEABLE and sets testpaths = ["tests", "packaging/messagefoundry-webconsole/tests"],
# while keeping the `Web console tests (pytest)` step -- so once it lands the web console suite runs
# inside `Tests (pytest)` AS WELL. Sizing on the current population would let #253 land and re-break
# the cap on contact, which is the "three PRs each adding a minute" death recorded at the foot of
# this note. The one windows-2025 execution of that branch is one of the seven kills above, so the
# post-#1027 windows-2025 duration HAS NEVER BEEN OBSERVED UNCENSORED -- and windows-2022's sizing
# maximum (29:23) IS a post-#1027 row. One shared value, two code states, until this is fixed.
#
# leg largest observed Tests + largest observed web-console = post-#1027 anchor
# ubuntu 16:08 (uncensored) 2:22 (n=441) 18:30
# W22 29:23 (uncensored; already a post-#1027 row) 29:23
# W25 36:08 (RIGHT-CENSORED) 3:59 (n=360) 40:07 lower bound
#
# BE HONEST ABOUT THE SPREAD RULE -- 36:00 DOES NOT MEET IT. An earlier revision argued "headroom
# must exceed observed spread". Against real values that rule FAILS here: headroom is 36:00 - 26:23
# = 9:37, and the windows-2025 spread is 26:23 - 15:56 = 10:27. It would need roughly 37:00 to hold.
# 36:00 is kept anyway, and the reason is stated rather than dressed up: this cap exists to catch a
# whole-process DEADLOCK, not slowness (see the paragraph below), so 1.364x over the worst observed
# run is ample for its actual job, and #131 already set this value. What the spread rule is good
# for is telling you the margin is thinner than the ratio suggests. RE-DERIVE IF a windows-2025
# `Tests (pytest)` step is ever seen above 28:00 -- that is the trigger, not a calendar reminder.
# SIZING RULE: step_timeout = ceil_minute(1.35 x that leg's post-#1027 anchor). 1.35 is the multiple
# #131 used when it set 36:00 (1.364x over 26:23, the largest execution then observed).
# ubuntu 18:30 x 1.35 = 24:59 -> 25:00 (1.351x over the anchor, 1.550x over max passing)
# W22 29:23 x 1.35 = 39:40 -> 40:00 (takes the shared Windows value below)
# W25 40:07 x 1.35 = 54:09 -> 55:00 (1.371x over the anchor, 1.537x over max passing)
#
# UBUNTU IS CHANGED IN THE SAME ACT BECAUSE IT IS THE NEXT INSTANCE, NOT AS TIDYING. At 19:00 against
# its post-#1027 anchor of 18:30 it stands at 1.027x -- within seconds of where windows-2025 is now --
# and its job cap is ALREADY NEGATIVE on measured maxima (see the job paragraph below). Publishing
# "ubuntu unchanged, still positive" beside a corrected Windows row would be a compensating control
# resting on a false premise, which is the defect this repo names specifically.
#
# THE SPREAD RULE NOW HOLDS, WHERE AT 36:00 IT DID NOT. The rule is "headroom must exceed observed
# spread". At 36:00 it FAILED on windows-2025 (headroom 9:37 against a 10:27 spread) and the old
# revision kept the value anyway and said so. At 55:00, on the eight-day pool:
# windows-2025 headroom 55:00 - 35:47 = 19:13 spread 35:47 - 24:48 = 10:59 HOLDS (+8:14)
# windows-2022 headroom 55:00 - 29:23 = 25:37 spread 29:23 - 18:42 = 10:41 HOLDS (+14:56)
# The 24:48 low is same-suite runner variance, not a smaller suite: three consecutive push-to-main
# runs inside 2h42m gave windows-2025 34:15 / 24:48 / 34:29 while windows-2022 held a 1:00 band.
#
# RE-DERIVE IF a windows-2025 `Tests (pytest)` STEP is ever seen above 40:00, or if any Windows
# `test` JOB is ever seen above 50:00 -- those are the triggers, not a calendar reminder. Both are
# the 1.2x decay point of their cap (55:00 / 1.2 = 45:50, floored to 40:00 for margin against the
# measured drift; 66:00 / 1.2 = 55:00, floored to 50:00). The OLD trigger of 28:00 is retired
# because it was already universally exceeded: 58 of 59 passing steps on the day pool cleared it and
# the median itself sat above it, so it had become a permanently-tripped alarm, which is
# indistinguishable from no alarm at all.
#
# A ratio against one run says nothing about a distribution, and #119's leg was killed by the
# distribution, not by its own duration. Both Windows legs take the same number: windows-2022 is the faster, so
# sizing on windows-2025 only leaves it more room, and one value is one thing to re-derive.
# distribution, not by its own duration. Both Windows legs take the same values, but they are sized
# from DIFFERENT legs and that asymmetry is deliberate: the STEP cap is sized on windows-2025 (the
# slower step, 35:47 censored against 29:23), while the JOB cap is sized on windows-2022 (the worse
# non-step addends, setup 4:05 against 2:32). An earlier revision said "sized on windows-2025 as the
# worse of the pair" without qualification -- that is FALSE for the job cap.
#
# THE JOB CAP IS NOT A ROUNDING-UP OF THE STEP CAP, AND IT HAS FIRED. Two steps in this job carry
# `step_timeout` -- `Tests (pytest)` and `Web console tests (pytest)` -- so the job can contain
Expand Down Expand Up @@ -440,14 +498,56 @@ jobs:
# revisions used a 0:41 setup (the MEDIAN), web-console values that were each only third-highest
# on their leg, and a 1:04 Windows setup that the exhibit above contradicts on its face:
#
# leg step_timeout + web-console(max) + setup(max) old job new job
# ubuntu 19:00 + 2:00 + 1:20 = 22:20 22:00 -> -0:20 26:00 -> +3:40 (1.16x)
# W22 36:00 + 2:33 + 1:09 = 39:42 40:00 -> +0:18 46:00 -> +6:18 (1.16x)
# W25 36:00 + 3:33 + 1:20 = 40:53 40:00 -> -0:53 46:00 -> +5:07 (1.13x)
# THE BAND MOVED OFF step_timeout AND ONTO THE OVERHEAD, 2026-08-08 (BACKLOG #1096). The earlier
# formula multiplied the WHOLE sum (step_timeout + addends) by ~1.13-1.16. That applies a safety
# band to `step_timeout`, which is a HARD BOUND the runner enforces -- the largest step overrun in
# 1,618 measured executions is EIGHT SECONDS (36:08 against a 36:00 cap). Banding it is slack for an
# event that cannot happen, it grows with the cap (4:41 at 36:00, 7:09 at 55:00), and it makes the
# published ratio pool-dependent because the step term dominates it. Corrected rule:
#
# job_timeout = step_timeout + ceil_minute(1.5 x that leg's worst measured job OVERHEAD)
#
# where overhead = job wall clock minus the `Tests (pytest)` step, taken as the larger of (a) the
# worst SAME-ROW overhead on non-cancelled rows and (b) that leg's setup(max) + web-console(max).
# The 1.5 band is on the overhead only, and is 1.5 rather than 1.35 because setup is hosted-runner
# provisioning outside this repo's control: `Set up job` alone has been observed at 4:30 (ubuntu run
# 31109989006, inside a 5:22 setup).
#
# leg worst same-row setup(max)+wc(max) overhead used x1.5 room job
# ubuntu 7:12 (n=451) 5:22 + 2:22 = 7:44 7:44 11:36 12:00 25+12 = 37
# W22 6:16 (n=413) 4:05 + 2:51 = 6:56 6:56 10:24 11:00 55+11 = 66
# W25 6:29 (n=372) 2:32 + 3:59 = 6:31 6:31 9:47 10:00 (takes W22's 66)
#
# INSTRUMENT PRESERVATION, the whole point of the pairing -- worst-case job wall built from
# independent maxima with `Tests` passing one second under its cap, new values against old:
#
# ubuntu 5:22 + 24:59 + 2:22 = 32:43 vs 37:00 +4:17 | old: 26:43 vs 26:00 -0:43 NEGATIVE
# W22 4:05 + 54:59 + 2:51 = 61:55 vs 66:00 +4:05 | old: 42:55 vs 46:00 +3:04
# W25 2:32 + 54:59 + 3:59 = 61:30 vs 66:00 +4:30 | old: 42:30 vs 46:00 +3:30
#
# UBUNTU WAS THE LEG ACTUALLY BROKEN, at -0:43, and nobody had measured it: BACKLOG #1096 was filed
# as a Windows problem. A negative row here means the JOB cap can fire before the STEP cap, and a
# job-level kill reports NO step conclusion -- so the instrument this item was measured with is
# destroyed exactly when it is needed. Max measured post-step teardown is 0:24, so all three new
# rows stay positive with room.
#
# NESTING INVARIANT, first gated step -- setup(max) + step_timeout must stay under job_timeout, so a
# `Tests` kill is a NAMED STEP failure rather than an unattributed job cancellation:
# ubuntu 5:22 + 25:00 = 30:22 < 37:00 (gap 6:38)
# W22 4:05 + 55:00 = 59:05 < 66:00 (gap 6:55)
# W25 2:32 + 55:00 = 57:32 < 66:00 (gap 8:28)
#
# 66 IS DERIVED, NOT ROUNDED UP FROM 55. The bare minimum whole minute that clears the worst sum is
# 61:00; it is rejected as thinner than any row this file has ever carried, and thinner than the
# three-addend model's own known error -- the worst observed single row sums to 40:16 against a real
# job wall clock of 40:22, so inter-step gaps make the model an UNDER-estimate by ~6s, not a
# conservative one.
#
# SUPERSEDED, kept because a number without its pool cannot be rechecked. The previous table read:
# ubuntu 19:00 + 2:00 + 1:20 = 22:20 (26:00, +3:40) | W22 36:00 + 2:33 + 1:09 = 39:42 (46:00,
# +6:18) | W25 36:00 + 3:33 + 1:20 = 40:53 (46:00, +5:07). Correct for its pool; superseded above.
#
# ubuntu and windows-2025 were ALREADY NEGATIVE -- ubuntu too, which an earlier revision had the
# wrong way round; windows-2022 was the one row genuinely in the black. Windows takes one value,
# sized on windows-2025 as the worse of the pair. The `+4` habit that produced 40 was Windows-only
# The `+4` habit that produced 40 was Windows-only
# and was carried through two cap changes unchecked (30/26 then 40/36); ubuntu has never been +4 --
# it went 15/13 to 22/19, so +2 then +3. Either way the number was derived from the OTHER BOUND
# rather than from the work, which is the defect, not the particular constant.
Expand Down Expand Up @@ -634,9 +734,9 @@ jobs:
# $GITHUB_REPOSITORY is a built-in runner env var, read here as plain shell (NOT a workflow-
# expression interpolation into the run body), so it is zizmor-safe and cannot be misparsed as
# an Actions expression the way a literal double-brace token in a run: block would be.
U='{"os":"ubuntu-latest","python-version":"3.14","hosted":["ubuntu-latest"],"job_timeout":26,"step_timeout":19,"pytest_timeout":60,"fault_timeout":90}'
W22='{"os":"windows-2022","python-version":"3.14","hosted":["windows-2022"],"job_timeout":46,"step_timeout":36,"pytest_timeout":120,"fault_timeout":150}'
W25='{"os":"windows-2025","python-version":"3.14","hosted":["windows-2025"],"job_timeout":46,"step_timeout":36,"pytest_timeout":120,"fault_timeout":150}'
U='{"os":"ubuntu-latest","python-version":"3.14","hosted":["ubuntu-latest"],"job_timeout":37,"step_timeout":25,"pytest_timeout":60,"fault_timeout":90}'
W22='{"os":"windows-2022","python-version":"3.14","hosted":["windows-2022"],"job_timeout":66,"step_timeout":55,"pytest_timeout":120,"fault_timeout":150}'
W25='{"os":"windows-2025","python-version":"3.14","hosted":["windows-2025"],"job_timeout":66,"step_timeout":55,"pytest_timeout":120,"fault_timeout":150}'
if [ "${GITHUB_REPOSITORY:-}" = "MEFORORG/MessageFoundry" ]; then
echo "matrix={\"include\":[$U,$W22,$W25]}" >> "$GITHUB_OUTPUT"
else
Expand Down
Loading
Loading