Skip to content

Capture thread stacks when the nightly's Bloom hangs (BL-16612) - #8114

Merged
andrew-polk merged 1 commit into
masterfrom
BL-16612-nightly-hang-watchdog
Jul 27, 2026
Merged

Capture thread stacks when the nightly's Bloom hangs (BL-16612)#8114
andrew-polk merged 1 commit into
masterfrom
BL-16612-nightly-hang-watchdog

Conversation

@andrew-polk

@andrew-polk andrew-polk commented Jul 27, 2026

Copy link
Copy Markdown
Contributor

CI-only instrumentation so that the next time the nightly's visual-regression suite hangs, we learn why. No product code — nothing here can change Bloom's behavior for users, or the behavior of the run it is watching.

The problem it solves

The suite hangs intermittently (BL-16612) — 2 of the 4 scheduled nightlies so far. Bloom stops making progress, stops writing to its log, and all 12 cases then time out at 120s each. Every one of those runs has told us only that something stopped, never what.

What would identify it is each thread's stack while it was stuck. We cannot get that after the fact: the suite's own afterAll kills Bloom with taskkill /T /F before any later workflow step could look at the process.

What this adds

A watchdog that runs alongside the tests (build/ci/watch-for-hung-bloom.ps1), started just before the visual-regression step. It polls for a Bloom.exe that has been alive far longer than a healthy run needs — ~5 minutes healthy versus 20+ when hung — and captures dotnet-stack report for it while it is still wedged. On the observed failures Bloom sat stuck for about 24 minutes, so there is a wide window to catch it.

It takes up to 3 captures a few minutes apart, plus a 30-second process sample line (CPU, thread count, working set). Both matter:

  • identical stacks minutes apart prove it is genuinely stuck rather than crawling;
  • the CPU trend distinguishes a starved-but-idle server from a spinning renderer.

dotnet-stack, deliberately not dotnet-dump. This repo is public and workflow artifacts are widely downloadable, so we must not publish a memory dump of a process that holds CI secrets. dotnet-stack emits text call stacks only — no heap contents.

Diagnostics are now collected and uploaded on success too, not only on failure. Chasing an intermittent fault means the healthy runs are evidence as well: without a known-good log and sample to compare against, a failing run's numbers mean little on their own. Discarding everything from the green runs is a large part of why this has been so hard to pin down.

Safety

  • No product code. Only the workflow, a new CI script, and two .gitignore lines for the scratch folders those steps create.
  • Purely observational. The watchdog reads process state; it never signals, kills, or otherwise touches Bloom.
  • Cannot fail the nightly. Every operation is best-effort and swallowed; the step ends in exit 0. If the watchdog does not start, the step says so loudly in the log rather than being discovered as an empty artifact the next day.

Why this lands ahead of the actual fix

There is a fix for this hang on a separate branch (#8110). It is deliberately not in this PR. The fix suppresses the failure — so if it lands first, the hang may simply stop happening and the root cause stays unknown, leaving mitigation in place justified by a hypothesis we could never test. The diagnostic opportunity is perishable; the fix can wait a few days.

Verified locally

  • The script parses cleanly, and its no-process and polling paths were exercised.
  • The detached Start-Process launch writes where expected — worth checking, because Start-Process resolves relative paths against the process working directory rather than PowerShell's location, so a wrong path would mean a watchdog that silently never starts.
  • dotnet-stack report against a live .NET process returns real per-thread managed stacks (exit 0, 4.7 KB of text, no memory contents).

Ref: https://issues.bloomlibrary.org/youtrack/issue/BL-16612

Devin review


This change is Reviewable

The nightly visual-regression suite hangs intermittently: Bloom stops
making progress, stops writing to its log, and all 12 cases then time out.
Two of the four scheduled nightlies have failed this way. Every such run
tells us only that something stopped — never what — because the one thing
that would identify it is what each thread was doing while stuck, and we
have never captured that.

We cannot collect it after the fact: the suite's afterAll kills Bloom with
`taskkill /T /F` before any later workflow step could look at the process.
So this adds a watchdog that runs ALONGSIDE the tests, notices a Bloom.exe
that has been alive far longer than a healthy run needs (~5 min healthy vs
20+ hung), and captures `dotnet-stack report` for it while it is still
wedged. On the observed failures Bloom stayed stuck about 24 minutes, so
there is a wide window. It takes up to 3 captures a few minutes apart:
identical stacks minutes apart prove it is genuinely stuck rather than
crawling.

Deliberately dotnet-stack (text call stacks) and NOT dotnet-dump: this
repo is public and workflow artifacts are widely downloadable, so we must
not publish a memory dump of a process that holds CI secrets. Text stacks
carry no heap contents.

Also collects and uploads the diagnostics on SUCCESS, not just failure.
Chasing an intermittent fault means the healthy runs are evidence too:
without a known-good log and sample to compare against, a failing run's
numbers mean little on their own.

This is CI-only and purely observational — no product code, and the
watchdog never signals or kills anything — so it cannot change the
behavior of the run it is watching, or of Bloom for users. It is
deliberately separate from, and lands ahead of, the actual fix for this
hang: the fix suppresses the failure, so landing it first risks the hang
never recurring and the root cause staying unknown.

Verified locally: the script parses, the detached launch writes where
expected, and `dotnet-stack report` against a live .NET process returns
real per-thread managed stacks (exit 0, text only).

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@andrew-polk
andrew-polk marked this pull request as ready for review July 27, 2026 23:18
@andrew-polk
andrew-polk merged commit c59ee22 into master Jul 27, 2026
3 of 7 checks passed
@andrew-polk
andrew-polk deleted the BL-16612-nightly-hang-watchdog branch July 27, 2026 23:18
andrew-polk added a commit that referenced this pull request Jul 27, 2026
The first green nightly on this branch was uninformative, and that is a
flaw in the instrumentation rather than good news. None of the diagnostics
fired at all: the page-checks navigation succeeded first try, so the retry
never ran, the backstop never ran, and no worker-pool snapshot was logged.
With 2 of the 4 scheduled nightlies having failed this way, a single pass
would happen about half the time even with no fix, so it was worth roughly
2:1 as evidence — and it said nothing about the starvation hypothesis.

The underlying problem: every diagnostic added so far speaks only AFTER
something has gone wrong. If the free-worker guard is quietly doing its
job, that looks exactly like a bug that quietly went away, so the root
cause could stay unproven forever. So
RegisterThreadBlockingAndEnsureAFreeWorker now logs when it actually has
to add a worker, with the pool snapshot. That is POSITIVE evidence: if it
appears in a passing run's log, the starvation condition was real and this
is what kept requests moving. Logged outside the queue lock so we never
hold it while writing a file.

This commit originally also made the nightly collect and upload Bloom's
log on success rather than only on failure, which is what let any of this
be read on a green run. That half has since landed on master separately
(#8114, together with the hung-Bloom stack-capture watchdog), so the
rebase drops it from here.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
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