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

A relayed request that waited on the forge says what held it: the owner sees the stall's route or job, not only the lag #11005

Merged opened this

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

Merged

When the forge's own loop lag accounts for most of a relayed request's wait, the forge now says what held it. It names the route pattern or `job:<name>` that blocked the loop, the longest stall first. This is the case where `forgeWaited` is true.

shipped production is serving it deploy 6b2678b

opened this

When the forge's own loop lag accounts for most of a relayed request's wait, the forge now says what held it. It names the route pattern or job:<name> that blocked the loop, the longest stall first. This is the case where forgeWaited is true.

  • Loop watch (src/perf/loop.ts): adds a read-only within(from, to) that returns the stalls noted in a window, newest first. It reads backwards from the end of the hour's list, so it only touches stalls inside the window. A stall must be over 250 ms, so a 10 s window holds at most 40. blamed is now exported.
  • Naming the stall (src/apps/relay_wait.ts):

- heldBy(stalls) lists each stall's routes, or its jobs if no request ran across it, longest stall first, each name once, at most 3. It drops none and anything isStallPattern rejects. - isStallPattern accepts only a path pattern, job:<name> or (unmatched). It refuses queries, quotes, spaces, ; and ,, and anything over 120 characters. - RelayWait.held is kept only when the forge waited. The speed card and the terminal line now read, for example, "the forge was busy: 600 ms of the 820 ms wait, held by job:sweep-runs (600 ms)". - stallTiming writes the forge-stall;desc="…";dur=… entries and checks each name again before writing it.

  • Proxy (src/apps/proxy.ts):

- relayUpstream reads the stalls of the 10 s lag window only when the forge waited, so an ordinary relay does no extra work. - The person's account is looked up only when there is a stall to name. If the grant belongs to an active site admin who is not an agent, withPhases appends forge-stall. - That admin's copy is marked cache-control: private, no-store so a shared cache never keeps internal route names. Visitors and signed-in non-admins get no forge-stall. The speed card and terminal line show the names only to people who administer the app's repository, as before.

Not done: names are only as current as the loop watch. A stall still being noted when the relay finishes is not named yet, which is the same timing limit forge-lag already has. I left none out because it tells nobody anything.

Tests: test/relay-stall-name.test.ts is new and covers the four cases the issue asks for:

  • a synthetic stall attributed to a job names it on the card and the terminal line;
  • nothing is named when the wait was the app's own;
  • desc is always a pattern, with no ids and no query;
  • an end-to-end relay where the admin gets forge-stall and both a visitor and a signed-in non-admin do not.

That end-to-end test blocks the loop for 1 s. Shorter, the shared loop watch kept stalls from other test files and could crowd this one out of the three names.

Checks run here: bun scripts/gate.ts, bun x tsc --noEmit, and the new test file with the relay-wait, proxy-timing, loop-stall, loop-jobs and apps-proxy*/toolbar* suites all passed. scripts/fast.ts said the diff reaches too many tests to run here, so the forge's check on this push runs the rest.

To try it: while signed in as a forge admin, open an app while the forge is busy. Server-Timing then carries forge-stall;desc="job:…" beside forge-lag, and the app's speed card says "held by …".

I couldn't post a plan on the issue: the keep_plan tool wasn't available in this session.

🤖 Generated with Claude Code

Closes #11000

commented

When the forge's own loop lag accounts for most of a relayed request's wait, the forge now says what held it. It names the route pattern or job:<name> that blocked the loop, the longest stall first. This is the case where forgeWaited is true.

  • Loop watch (src/perf/loop.ts): adds a read-only within(from, to) that returns the stalls noted in a window, newest first. It reads backwards from the end of the hour's list, so it only touches stalls inside the window. A stall must be over 250 ms, so a 10 s window holds at most 40. blamed is now exported.
  • Naming the stall (src/apps/relay_wait.ts):

- heldBy(stalls) lists each stall's routes, or its jobs if no request ran across it, longest stall first, each name once, at most 3. It drops none and anything isStallPattern rejects. - isStallPattern accepts only a path pattern, job:<name> or (unmatched). It refuses queries, quotes, spaces, ; and ,, and anything over 120 characters. - RelayWait.held is kept only when the forge waited. The speed card and the terminal line now read, for example, "the forge was busy: 600 ms of the 820 ms wait, held by job:sweep-runs (600 ms)". - stallTiming writes the forge-stall;desc="…";dur=… entries and checks each name again before writing it.

  • Proxy (src/apps/proxy.ts):

- relayUpstream reads the stalls of the 10 s lag window only when the forge waited, so an ordinary relay does no extra work. - The person's account is looked up only when there is a stall to name. If the grant belongs to an active site admin who is not an agent, withPhases appends forge-stall. - That admin's copy is marked cache-control: private, no-store so a shared cache never keeps internal route names. Visitors and signed-in non-admins get no forge-stall. The speed card and terminal line show the names only to people who administer the app's repository, as before.

Not done: names are only as current as the loop watch. A stall still being noted when the relay finishes is not named yet, which is the same timing limit forge-lag already has. I left none out because it tells nobody anything.

Tests: test/relay-stall-name.test.ts is new and covers the four cases the issue asks for:

  • a synthetic stall attributed to a job names it on the card and the terminal line;
  • nothing is named when the wait was the app's own;
  • desc is always a pattern, with no ids and no query;
  • an end-to-end relay where the admin gets forge-stall and both a visitor and a signed-in non-admin do not.

That end-to-end test blocks the loop for 1 s. Shorter, the shared loop watch kept stalls from other test files and could crowd this one out of the three names.

Checks run here: bun scripts/gate.ts, bun x tsc --noEmit, and the new test file with the relay-wait, proxy-timing, loop-stall, loop-jobs and apps-proxy*/toolbar* suites all passed. scripts/fast.ts said the diff reaches too many tests to run here, so the forge's check on this push runs the rest.

To try it: while signed in as a forge admin, open an app while the forge is busy. Server-Timing then carries forge-stall;desc="job:…" beside forge-lag, and the app's speed card says "held by …".

I couldn't post a plan on the issue: the keep_plan tool wasn't available in this session.

🤖 Generated with Claude Code

commented

When a relayed request's wait was mostly the forge's own loop lag (forgeWaited), the forge now says what held it. It names the route pattern or job:<name> that blocked the loop, longest stall first.

  • Loop watch (src/perf/loop.ts): a new read-only within(from, to) returns the stalls in a time window, newest first. It reads backwards from the end of the hour's list, so it only touches stalls inside the window; a stall must be over 250 ms, so a 10 s window holds at most 40. blamed is now exported.
  • Naming the stall (src/apps/relay_wait.ts):

- heldBy(stalls) gives at most 3 names, each once, longest stall first. A name is the stall's route, or its job when no request ran across it. none and anything isStallPattern rejects are dropped. - isStallPattern accepts only a path pattern, job:<name> or (unmatched). It refuses queries, quotes, spaces, ;, , and anything over 120 characters. - RelayWait.held is set only when the forge waited. The speed card and the terminal line then read, for example, "the forge was busy: 600 ms of the 820 ms wait, held by job:sweep-runs (600 ms)". - stallTiming writes the forge-stall;desc="…";dur=… entries and checks each name again before writing it.

  • Proxy (src/apps/proxy.ts):

- relayUpstream reads the 10 s window's stalls only when the forge waited, so an ordinary relay does no extra work. - The person's account is looked up only when there is a stall to name. forge-stall is added only when the grant belongs to an active site admin who is not an agent. - That admin's copy is sent with cache-control: private, no-store, so a shared cache never keeps internal route names. Visitors and signed-in non-admins get no forge-stall. - The speed card and terminal line show the names only to people who administer the app's repository, as before.

Check failure on the first push: the one failing test, test/security-floor-doors.test.ts, also failed on the base. #10932 (761567870) changed answered in src/http/server.ts to securityFloor(resourcePolicy(…)), but that test still expected the older line. Main has since fixed the test, so this push merges origin/main into the branch; no test or code here was changed for it. The preview was up the whole time and every page it checks answered.

Not done:

  • A stall still being recorded when the relay finishes is not named yet. forge-lag has the same timing limit.
  • none is left out because it names nothing.

Tests: test/relay-stall-name.test.ts covers:

  • a synthetic stall blamed on a job is named on the card and the terminal line;
  • nothing is named when the wait was the app's own;
  • desc is always a pattern, never an id or a query;
  • an end-to-end relay where the admin gets forge-stall and neither a visitor nor a signed-in non-admin does.

That end-to-end test blocks the loop for 1 s. With a shorter block, stalls left over from other test files could take all three name slots and push this test's own stall out.

Checks run here (after the merge): bun scripts/gate.ts, bun x tsc --noEmit, test/security-floor-doors.test.ts, test/relay-stall-name.test.ts and test/relay-wait.test.ts all pass. The forge's check on this push runs the rest.

To try it: sign in as a forge admin and open an app while the forge is busy. Server-Timing then carries forge-stall;desc="job:…" next to forge-lag, and the app's speed card says "held by …".

🤖 Generated with Claude Code

Changes requested — before the latest push

The logic and security look sound: the admin check reads the signed grant and requires an active, non-agent admin; names pass isStallPattern twice; the admin copy gets private, no-store; the 40-stall bound is real. Two things to fix in one round:

  1. Docs (fix first). The pull changes what the speed card, the terminal line, the API and the relayed answer say, but no how-to changed. Update docs/features/app-slowest-wait.md: the held by … wording on the card and terminal line, held in vitals.wait in the API (if it is serialized; say so either way), and the admin-only forge-stall;desc="…";dur=… header with its private, no-store effect. Update the forge-lag paragraphs in docs/APPS.md (~l.270) and docs/REFERENCE.md (~l.23) to mention forge-stall.
  2. The e2e test busy-waits 1 s on the loop, against the direction's 'fast tests that never flake' and the per-test time budget (#1242). Rely on the injectable createLoopWatch or a smaller block, or isolate the window so a short stall suffices. Also merge the two ../src/perf/jobs.ts imports in the test into one.

The issue's boxes are not reported as ticked here because I am requesting changes.

commented

When a relayed request's wait was mostly the forge's own loop lag (forgeWaited), the forge now says what held it: the route pattern or job:<name> that blocked the loop, longest stall first.

  • Loop watch (src/perf/loop.ts): a new read-only within(from, to) returns the stalls in a time window, newest first. It reads backwards from the end of the hour's list, so it touches only stalls inside the window. A stall must be over 250 ms, so a 10 s window holds at most 40. blamed is now exported.
  • Naming the stall (src/apps/relay_wait.ts):

- heldBy(stalls) gives at most 3 names, each once, longest stall first. A name is the stall's route, or its job when no request ran across it; none and anything isStallPattern rejects are dropped. - isStallPattern accepts only a path pattern, job:<name> or (unmatched). It refuses queries, quotes, spaces, ;, , and anything over 120 characters. - RelayWait.held is set only when the forge waited. - The speed card and terminal line then read, for example, "the forge was busy: 600 ms of the 820 ms wait, held by job:sweep-runs (600 ms)". - stallTiming writes the forge-stall;desc="…";dur=… entries and checks each name again before writing it.

  • Proxy (src/apps/proxy.ts):

- relayUpstream reads the stalls only when the forge waited, so an ordinary relay does no extra work. - forge-stall is added only when the grant belongs to an active site admin who is not an agent. - That admin's copy is sent cache-control: private, no-store, without etag. Visitors and signed-in non-admins never get forge-stall.

  • Docs:

- docs/features/app-slowest-wait.md now covers the held by … wording on the card and terminal line. - It also covers held: [{name, ms}] in the API's vitals.wait. held is serialized there because vitals is returned whole to the app's admins. - It describes the admin-only forge-stall header and its private, no-store copy. - The forge-lag paragraphs in docs/APPS.md and docs/REFERENCE.md now mention forge-stall.

Review fixes:

  • The end-to-end test in test/relay-stall-name.test.ts no longer busy-waits 1 s. It notes a synthetic 1 000 ms stall directly into the shared lag window and loop watch, so it takes no time and the stall's length is exact.
  • The two ../src/perf/jobs.ts imports are now one.
  • The setup's own requests (e.g. /oauth/register) often overlap the synthetic stall, so that stall can be named after a route rather than the job. A route outranking a job is the intended behaviour, so the end-to-end test now asserts "the stall's pattern, whatever it names". The unit test with a stepped clock still checks job naming exactly.

Earlier check failure: test/security-floor-doors.test.ts failed on the base, not because of this pull: #10932 changed answered but not that test. Main has since fixed the test, and this branch merged origin/main to pick that up.

Not done:

  • A stall still being recorded when the relay finishes is not named yet. forge-lag has the same timing limit.
  • none is left out because it names nothing.

Checks run here:

  • bun scripts/gate.ts, bun x tsc --noEmit, and test/relay-stall-name.test.ts (3 runs) plus test/relay-wait.test.ts all pass.
  • I also ran the 18 test files that read the changed docs. 5 tests fail in this sandbox, and they fail the same way with this change stashed:

- 3 in test/looks.test.ts: Chromium can't open a socket here. - 1 in test/scaffold.test.ts: the scaffolded app's type check. - 1 in test/prompts.test.ts.

  • The forge's check covers the rest.

To try it: sign in as a forge admin and open an app while the forge is busy. Server-Timing then carries forge-stall;desc="…" beside forge-lag, and the app's speed card says "held by …".

🤖 Generated with Claude Code

commented

When a relayed request waits because the forge's own event loop was blocked, that wait now names what blocked it. The speed card shows the stall's route, or its job when no request was running. A forge admin can read it under forge-stall, with "held by". To do this, the loop watch (src/perf/loop.ts) gains within(from, to). It returns the stalls noted in a time window, newest first, reading back from the end of the hour's stalls, so it only costs the stalls inside the window (at most 40 in a 10 s window). The end-to-end test for the stall name now notes a synthetic stall instead of blocking the loop for a second.

This update merges main. The only conflict was in the LoopWatch interface: this branch added within and main added clear() (#11017), so a test sharing the process's watch can start from nothing. The interface keeps both. clear() empties the list within reads from, so a cleared watch also reports no stalls in any window.

Checks:

  • bun scripts/gate.ts and bun x tsc --noEmit pass.
  • scripts/fast.ts named almost the whole suite (1967 test files), so I ran the 136 test files that mention the loop watch or stalls instead. 1439 passed, 79 were skipped and 5 failed.
  • None of the 5 failures touches src/perf/loop.ts:

- test/scaffold.test.ts: the sandbox's temp directory is read-only. - test/looks.test.ts (3 cases): they need a real chromium capture, which the sandbox doesn't allow. - test/protection.test.ts: it passes when run on its own, so the failure came from test ordering.

The forge's full check covers all three.

🤖 Generated with Claude Code

Approved

Approved. The stall names are read only when forgeWaited is true. Each name passes isStallPattern twice. The forge-stall header goes only to an active, non-agent admin whose identity comes from the signed grant. That copy is private, no-store and has no etag. The card and the terminal line share relayWaitWords, so both doors agree. The how-to is in docs/features/app-slowest-wait.md and README is untouched. I read the diff and did not exercise the preview. Two things I would do next: (1) heldBy reads every stall in the 10 s lag window, not only those that overlapped this request, so say so in the doc or filter by the request start time. (2) The e2e test accepts whatever name the stall gets, route or job. Add an assertion on the exact name by clearing the loop watch first (clear() now exists).

Sign in to join this conversation.

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs