Skip to content

test(ci): a soak that can actually catch #440, since nothing else has - #700

Merged
rainmanjam merged 1 commit into
mainfrom
test/windows-soak-for-440
Sep 4, 2026
Merged

test(ci): a soak that can actually catch #440, since nothing else has#700
rainmanjam merged 1 commit into
mainfrom
test/windows-soak-for-440

Conversation

@rainmanjam

Copy link
Copy Markdown
Owner

Refs #440. Not a fix — an instrument, because there is no code fix left to
apply and the last three remedies were guesses that fit the symptom.

#440 is fourteen occurrences, not one

A census of the full retained CI history — 1,607 windows-latest job
executions
, 2026-07-29 → 2026-09-04 — finds 14 Go runtime aborts, all in
internal/engine:

message count
found pointer to free object 11
fault (0xc0000005) 1
s.allocCount != s.nelems && freeIndex == s.nelems 2

14 / 1,319 jobs that ran the suite = 1.06%, about 1 in 94. Full breakdown of
all 423 non-success jobs is on the issue.

"Reruns work" is the bug being rare, not infrastructure. 9 of the 14 abort
runs were re-run; all 9 went green; zero reproduced. Only 4 jobs in all of
history hit the 35-minute ceiling, 2 of them from the step fixed in #698 — real,
but 4 of 423 explains nothing.

Why there is nothing left to fix

The suspected unsafe.Pointeruintptr conversion was genuinely illegal —
x/sys's SetInformationJobObject is an ordinary splittable Go function with no
//go:uintptrescapes. But it was fixed in #475, and the crash outlived it:

period rate
pre-#475 8 / 623 = 1.28%
post-#475 wrapper 6 / 318 = 1.89%
post-#611 allocator upgrade 2 / 194 = 1.03%

Nothing has moved it. (The issue's own suggested remedy, runtime.KeepAlive,
was tried first and was insufficient — it's special-cased not to force escape.)
A repo-wide audit finds no remaining violation, and GOOS=windows go vet is
clean and already in CI.

Why these two packages

All fourteen dumps carry the same goroutine population: 9–11
internal/relay.(*Hub).run blocked in net.(*conn).Read
, plus one
internal/supervisor.(*Process).waitBackoff. So the soak runs internal/engine

  • internal/relay in a loop under -race, rather than the whole suite.

Three things I wrote and then had to check

Recorded because each was wrong in the direction that looks fine:

  • -race on windows/amd64 — supported. The soak would be pointless
    otherwise and I hadn't verified it.
  • -gcflags=all=-d=checkptr — redundant and wrong. cmd/compile/internal/base/flag.go
    says -race, -msan and -asan imply -d=checkptr, and ten lines later that the
    runtime can't use checkptr — so all= applied it to a package that refuses
    it. Dropped rather than kept as decoration.
  • "roughly four minutes an iteration" — invented. Measured: 72s for both
    packages (engine 68.6s, relay 2.8s) on an Apple-silicon laptop. At a Windows
    factor, 40 iterations is ~100 min against the 90-min ceiling I'd written. The
    default is now 25.

It bounds itself on time, which is this morning's lesson applied early

#698 landed today because an unbounded step let a job hit its ceiling and be
cancelled — and a cancelled job never reaches its upload step, so an
overrunning soak would lose the one artefact it exists to produce. The loop
stops at 70 minutes and leaves 20 for the upload.

Inputs are validated before use: $PKGS expands unquoted (several packages
must word-split into go test's argv), and an unquoted expansion of an input is
a command-injection shape whatever the trigger is. workflow_dispatch needs
write access so this isn't the dangerous case — it's the shape that becomes
dangerous the day someone adds a second trigger.

And it says so when it catches nothing

25 iterations at 1.06% catch one about a quarter of the time, so a clean
soak is the ordinary result. It exits 0 and prints a notice saying that is not
evidence the bug is gone — because the failure mode of a diagnostic is somebody
reading its green as an all-clear, and this issue has already had three remedies
read that way.

https://claude.ai/code/session_01A8N3W5ct9SZtHK9sCDD9cL

#440 is not "seen once". A census of the full retained CI history -- 1,607
windows-latest job executions, 2026-07-29 to 2026-09-04 -- finds FOURTEEN Go
runtime aborts, all in internal/engine: `found pointer to free object` x11,
`fault` x1, `s.allocCount != s.nelems` x2. That is 14 of the 1,319 jobs that
actually ran the suite, 1.06%, about 1 in 94.

WHY A SOAK RATHER THAN A FIX. There is no code fix left to apply. The unsafe
Pointer->uintptr conversion the issue suspected was real -- x/sys's
SetInformationJobObject is an ordinary splittable Go function with no
//go:uintptrescapes, so the conversion at the call site was illegal -- but it
was fixed in #475 with a wrapper, and the crash OUTLIVED it: 8 aborts in 623
executions before, 6 in 318 after, 2 in 194 after the allocator upgrade too.
Nothing has moved the rate. The issue's own suggested remedy, runtime.KeepAlive,
had already been tried and was insufficient, because KeepAlive is special-cased
not to force escape. Guessing at a fourth remedy for a bug nobody can reproduce
is how the first three were arrived at.

WHY THESE PACKAGES. All fourteen dumps carry the same goroutine population:
9-11 internal/relay.(*Hub).run blocked in net.(*conn).Read, plus one
internal/supervisor.(*Process).waitBackoff. So the soak runs internal/engine and
internal/relay rather than the suite, under -race, in a loop. At 1% per
full-suite run an occurrence arrives every few days on somebody else's pull
request in a job whose logs expire; a targeted loop is the difference between
that and an artefact this afternoon.

WHAT I CHECKED RATHER THAN ASSUMED, because three things I first wrote were
wrong:

  - -race IS supported on windows/amd64. The soak would be pointless otherwise
    and I had not verified it.
  - -gcflags=all=-d=checkptr was redundant AND wrong. cmd/compile's flag.go
    says "-race, -msan and -asan imply -d=checkptr for now" and, ten lines
    later, that the runtime cannot use checkptr -- so `all=` applied it to a
    package that refuses it. Dropped rather than left in as decoration.
  - "roughly four minutes an iteration" was invented. Measured: 72s for both
    packages on an Apple-silicon laptop. At a Windows factor that puts 40
    iterations at ~100 minutes against the 90-minute ceiling I had written --
    so the default is 25 and the loop bounds itself on TIME as well as count.

THAT TIME BOUND IS TODAY'S OTHER LESSON APPLIED EARLY. #698 landed this morning
because an unbounded step let a job hit its ceiling and be CANCELLED -- and a
cancelled job does not reach its upload step, so an overrunning soak would lose
the single artefact it exists to produce. The loop stops at 70 minutes and
leaves 20 for the upload.

The inputs are validated before use: $PKGS is expanded unquoted, because several
packages must word-split into go test's argv, and an unquoted expansion of an
input is a command injection shape whatever the trigger is. workflow_dispatch
needs write access so this is not the dangerous case; it is the shape that
becomes dangerous the day somebody adds a second trigger.

AND IT SAYS SO WHEN IT CATCHES NOTHING. 25 iterations at 1.06% catch one about
a quarter of the time, so a clean soak is the ORDINARY result. It exits 0 and
prints a notice saying that is not evidence the bug is gone -- because the
failure mode of a diagnostic is somebody reading its green as an all-clear, and
this issue has already had three remedies read that way.

Refs #440.

Claude-Session: https://claude.ai/code/session_01A8N3W5ct9SZtHK9sCDD9cL
Copilot AI lite review requested due to automatic review settings September 4, 2026 15:55

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

The new workflow has a few correctness/consistency issues (iteration default drift, iterations=0 validation gap, and time-budget enforcement that can still overrun due to per-iteration test timeout) that should be fixed before relying on it for diagnostics.

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Pull request overview

Adds a manual, artifact-preserving Windows “heap soak” workflow intended to increase the chance of capturing intermittent Go runtime aborts related to #440 by repeatedly running targeted packages under -race.

Changes:

  • Introduces a new workflow_dispatch workflow that loops go test -race over ./internal/engine and ./internal/relay, capturing per-iteration logs as artifacts.
  • Adds input validation and runtime-abort detection heuristics to distinguish runtime aborts from ordinary test failures.
  • Enforces an overall time budget and a job-level timeout to avoid losing artifacts due to runner cancellation.
File summaries
File Description
.github/workflows/windows-heap-soak.yml New Windows-only soak workflow to repeatedly exercise suspected packages under -race and upload iteration logs for post-mortem analysis.
Review details

Suppressed comments (1)

.github/workflows/windows-heap-soak.yml:160

  • This comment still refers to “forty iterations”, but the workflow default is 25 (and the notice below also discusses 25). Updating this keeps the rationale consistent and avoids confusing future readers about the expected ‘clean run’ probability.
          # a 1% per-run rate, forty iterations that catch nothing is the
          # expected outcome roughly two times in three.
  • Files reviewed: 1/1 changed files
  • Comments generated: 3
  • Review effort level: Lite

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment on lines +103 to +107
case "$ITERATIONS" in
''|*[!0-9]*)
echo "::error title=Refused::iterations must be a positive integer"
exit 1 ;;
esac
Comment on lines +121 to +134
for i in $(seq 1 "$ITERATIONS"); do
if [ "$SECONDS" -ge "$SOAK_BUDGET_SECS" ]; then
echo "stopping after $ran iteration(s): ${SECONDS}s spent against a"
echo "${SOAK_BUDGET_SECS}s budget, leaving room to upload the dumps."
break
fi
ran=$((ran+1))
echo "::group::iteration $i of $ITERATIONS (${SECONDS}s elapsed)"
# -count=1 defeats the test cache, or every iteration after the
# first would prove nothing at all. Output is kept per iteration so
# a dump can be read whole rather than interleaved.
out="iter-$i.log"
# shellcheck disable=SC2086 # deliberate split; validated above
go test -race -count=1 -timeout 15m $PKGS >"$out" 2>&1
- name: Soak internal/engine and internal/relay
shell: bash
env:
ITERATIONS: ${{ inputs.iterations || '40' }}
@sonarqubecloud

sonarqubecloud Bot commented Sep 4, 2026

Copy link
Copy Markdown

@rainmanjam
rainmanjam merged commit c741e80 into main Sep 4, 2026
36 checks passed
@rainmanjam
rainmanjam deleted the test/windows-soak-for-440 branch September 4, 2026 16:34
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.

2 participants