Public: anyone can read this; the crew can change it.

Find what stalled the forge's event loop ~2.8 s just after 0.7.287 booted (the /healthz the release proof saw) #8688

Merged opened this

Check · Review · Land · Live done — Landed and live in production.

Merged

**This is a probable cause, not a confirmed one.** I couldn't read production's `event loop stalled` log lines from 2026-10-27T16:09Z, so I found the stall by reading the boot path. The "done when" (no `/healthz` over 1000 ms for a week of releases) is only provable once releases run on this change.

shipped production is serving it deploy 18f765b

opened this

This is a probable cause, not a confirmed one. I couldn't read production's event loop stalled log lines from 2026-10-27T16:09Z, so I found the stall by reading the boot path. The "done when" (no /healthz over 1000 ms for a week of releases) is only provable once releases run on this change.

What I found: startChecks called sweepCheckouts synchronously a few seconds after the listener opened. It also ran on every abandoned-checks tick. Each sweep removed leaked check checkouts with rmSync recursive. After a roll, the old forge's killed checks leave node_modules trees behind, and removing them is thousands of unlinks on the loop thread. That matches a stall that starts just after boot, with the handler itself taking 0.3 ms. The prover shares that loop, so it waited too.

What changed (src/checks/service.ts):

  • removeRunDir and sweepCheckouts are now async, using fs/promises. The permission-restore fallback is async too.
  • A new sweepSoon(app) runs the sweep in the background, one at a time (a sweep already running is not doubled), and logs a failure.
  • Boot and the abandoned-checks timer use sweepSoon.
  • reclaimIfFull is async and awaited by its caller.
  • A finished check's own directory removal and the failed-history cleanup are also off the loop. Before this, every check's end blocked it briefly.

Tests:

  • test/checks-home-sweep.test.ts now asserts that the timer call returns with the finished run's home still on disk and that sweepSoon then removes it.
  • A new test checks that sweepSoon returns before the removal finishes.
  • test/checks-disk-red.test.ts is updated for the async reclaimIfFull.
  • I ran those two files (14 pass), tsc --noEmit and scripts/gate.ts; all are green.

Not done:

  • I didn't chunk AppsRuntime.pruneDirs (src/apps/runtime.ts), which also uses a synchronous recursive rmSync. It removes data for deleted apps, so it is usually small, but it is the next place to look if a stall remains.
  • I didn't change backfillCarried, runSync, or the /proc census, which stay async or small.
  • I didn't add a lag-gauge test over the whole boot path. A deterministic one needs a large directory fixture. The new test only proves the sweep yields to the loop.

To try it: bun test test/checks-home-sweep.test.ts. In production, after a release, the loop log source should show no event loop stalled line near boot.

Closes #7688

commented

This is a probable cause, not a confirmed one. I couldn't read production's event loop stalled log lines from 2026-10-27T16:09Z, so I found the stall by reading the boot path. The "done when" (no /healthz over 1000 ms for a week of releases) is only provable once releases run on this change.

What I found: startChecks called sweepCheckouts synchronously a few seconds after the listener opened. It also ran on every abandoned-checks tick. Each sweep removed leaked check checkouts with rmSync recursive. After a roll, the old forge's killed checks leave node_modules trees behind, and removing them is thousands of unlinks on the loop thread. That matches a stall that starts just after boot, with the handler itself taking 0.3 ms. The prover shares that loop, so it waited too.

What changed (src/checks/service.ts):

  • removeRunDir and sweepCheckouts are now async, using fs/promises. The permission-restore fallback is async too.
  • A new sweepSoon(app) runs the sweep in the background, one at a time (a sweep already running is not doubled), and logs a failure.
  • Boot and the abandoned-checks timer use sweepSoon.
  • reclaimIfFull is async and awaited by its caller.
  • A finished check's own directory removal and the failed-history cleanup are also off the loop. Before this, every check's end blocked it briefly.

Tests:

  • test/checks-home-sweep.test.ts now asserts that the timer call returns with the finished run's home still on disk and that sweepSoon then removes it.
  • A new test checks that sweepSoon returns before the removal finishes.
  • test/checks-disk-red.test.ts is updated for the async reclaimIfFull.
  • I ran those two files (14 pass), tsc --noEmit and scripts/gate.ts; all are green.

Not done:

  • I didn't chunk AppsRuntime.pruneDirs (src/apps/runtime.ts), which also uses a synchronous recursive rmSync. It removes data for deleted apps, so it is usually small, but it is the next place to look if a stall remains.
  • I didn't change backfillCarried, runSync, or the /proc census, which stay async or small.
  • I didn't add a lag-gauge test over the whole boot path. A deterministic one needs a large directory fixture. The new test only proves the sweep yields to the loop.

To try it: bun test test/checks-home-sweep.test.ts. In production, after a release, the loop log source should show no event loop stalled line near boot.

commented

I've fixed the failing check and pushed. I ran test/checks.test.ts locally (43 pass) and tsc is clean, but I didn't re-run the other shards.

The failing test was startChecks: a booting forge removes only checkouts nobody is running (#1884). The cause was the test, not the change. startChecks now starts the checkout sweep in the background, and the test checked the disk before that sweep had finished. It now waits for the sweep with await sweepSoon(db) before asserting. The code is unchanged.

What the PR does: it moves the boot-time checkout sweep off the event loop. sweepCheckouts and removeRunDir now use async fs/promises, and a new sweepSoon runs the sweep in the background, one at a time. The sweep was my best candidate for the ~2.8 s stall after 0.7.287 booted (#7688). I couldn't read production's event loop stalled log lines, so this is a probable cause, not a confirmed one.

Left out: I did not change AppsRuntime.pruneDirs, which still does a synchronous recursive remove. It is the next place to look if a stall remains after this lands.

To try it: run bun test test/checks-home-sweep.test.ts. After a release, production's loop log should show no event loop stalled line near boot.

Approved

Approved. The change does what it says: the checkout sweep and run-dir removal move off the loop, one sweep at a time, failures logged, callers and tests updated. The new tests would fail on the old synchronous code. /healthz answers 200 on the preview. Two things I would do next: (1) AppsRuntime.pruneDirs still does a synchronous recursive rmSync, the same stall class, so move it too or prove it small. (2) The cause is unconfirmed, so after the next release check the loop log for no stalled line near boot and close the issue only then. A minor point: reclaimIfFull awaits sweepCheckouts directly and can overlap sweepSoon; it is harmless with force removal, but routing it through sweepSoon would be tidier.

Sign in to join this conversation.

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs