Public: anyone can read this; the crew can change it.
Every response's Server-Timing names the worst event-loop lag of the last 10 s, so a stall outside the handler shows #10292
Check · Review · Land · Live done — Landed and live in production.
I added `lag;dur=<ms>` to every forge response's `Server-Timing`: the worst event-loop lag seen in the last 10 s. The issue's last item is not done: this pull's preview doesn't exist until the forge opens the pull, so I couldn't quote its `lag` across 30 requests. As a baseline, 30 requests to production `/nope` gave `app;dur` 1.8–6.1 ms each, but `forge-ttfb` was 59–1147 ms on 9 of them (59.5, 97…
shipped production is serving it deploy f21b126
I added lag;dur=<ms> to every forge response's Server-Timing: the worst event-loop lag seen in the last 10 s. The issue's last item is not done: this pull's preview doesn't exist until the forge opens the pull, so I couldn't quote its lag across 30 requests. As a baseline, 30 requests to production /nope gave app;dur 1.8–6.1 ms each, but forge-ttfb was 59–1147 ms on 9 of them (59.5, 97.3, 103.1, 137.6, 158.0, 224.2, 286.3, 663.9 and 1147.3 ms). The same 30 requests against the preview should show lag rising on exactly those.
What changed
src/perf/loop_worst.ts(new): keeps the worst lag of the last 10 s in ten one-second slots.
- It is fed by the existing startLoopLag sampler in kernel/loop_lag.ts: one unref'd 50 ms timer, started once by the first serve.
- Recording a sample takes constant time and reading the window looks at ten numbers, so a tick costs well under 0.1 ms. I didn't time it, because the repo's rule is to count work rather than time it.
- A stall stays visible for 9–10 s after it, because the window moves a second at a time.
- With a 50 ms timer, a block can read up to 50 ms short (a 150 ms block reads 100–150).
src/http/server.ts:counted()adds the token throughwithLag()insrc/core/route_timing.ts. The token goes on the response only. The perf record's phases leave it out, so per-route phase stats aren't polluted by a number that belongs to the loop, not the request./healthz: still answers plainokto probes and strangers; I kept that body unchanged because the #2917 test pins it. OnlyAccept: application/jsongets{"ok":true,"loopLagMs":n}.
Tests
test/loop-worst.test.tschecks the window by hand: slot rollover, reuse of a slot a lap later, and bad input.- End to end, it starts a real server, blocks the loop for 150 ms with a busy wait, and sees
lag;dur≥ 140 on the next/nopeandloopLagMs≥ 140 on/healthz.
- The test runs the sampler every 5 ms rather than 50, so the reading can be compared against 140 exactly.
- It then stops the sampler and moves the window's clock forward 10 s; the next response reads lag;dur=0.0.
- The window's clock is separate from the clock that measures lateness, so moving it forward doesn't look like a 10 s stall.
- About 73 existing
*-timingtests compared exact phase lists, so the extra token broke them. They now readrequestTiming(res)from the newtest/helpers/request-timing.ts, which dropslag.test/route-timing.test.ts's exact-format regexes now expect the trailinglag. The tests were too strict for an added token; the code was right. - These tests in particular showed lags of around 160 ms inside the test process, so the stalls are real.
Checks
bun scripts/gate.tsandbun x tsc --noEmitare clean.- I ran every test file that mentions Server-Timing or
/healthz(272 files), plusflake,principlesand the tests that read AGENTS.md. - The only failure is
test/scaffold.test.ts"typechecks under strict settings". It needsbun xto write to a tempdir that is read-only in my sandbox, and it fails the same way on main.
Not done
- The
keep_plantool wasn't available in this session, so the issue has no plan. - The apps proxy's own
forge-*Server-Timing doesn't getlag. Thelagon the forge's own responses is what names the stall.
AGENTS.md now names loopWorst as state shared through process memory, as it asks.
Try it
curl -sI <preview>/nope | grep -i server-timingshows the newlag;durtoken.curl -s -H 'accept: application/json' <preview>/healthzreturnsloopLagMs.
🤖 Generated with Claude Code
I added lag;dur=<ms> to every forge response's Server-Timing: the worst event-loop lag seen in the last 10 s. The issue's last item is not done: I couldn't quote the preview's lag across 30 requests, because I had no preview address for this pull. As a baseline, 30 requests to production /nope gave app;dur 1.8–6.1 ms each, but forge-ttfb was 59–1147 ms on 9 of them (59.5, 97.3, 103.1, 137.6, 158.0, 224.2, 286.3, 663.9 and 1147.3 ms). The same 30 requests against the preview should show lag rising on exactly those.
What changed
src/perf/loop_worst.ts(new): keeps the worst lag of the last 10 s in ten one-second slots.
- It is fed by the existing startLoopLag sampler in kernel/loop_lag.ts: one unref'd 50 ms timer, started once by the first serve.
- Recording a sample takes constant time and reading the window looks at ten numbers, so a tick costs well under 0.1 ms. I didn't time it, because the repo's rule is to count work rather than time it.
- A stall stays visible for 9–10 s after it, because the window moves a second at a time.
- With a 50 ms timer, a block can read up to 50 ms short (a 150 ms block reads 100–150).
src/http/server.ts:counted()adds the token throughwithLag()insrc/core/route_timing.ts. The token goes on the response only. The perf record's phases leave it out, so per-route phase stats aren't polluted by a number that belongs to the loop, not the request./healthz: still answers plainokto probes and strangers; I kept that body unchanged because the #2917 test pins it. OnlyAccept: application/jsongets{"ok":true,"loopLagMs":n}.- Commit messages: the check failed because no commit had a
Try:line. Rather than force-push, I added an empty commit with one.
Tests
test/loop-worst.test.tschecks the window by hand: slot rollover, reuse of a slot a lap later, and bad input.- End to end, it starts a real server, blocks the loop for 150 ms with a busy wait, and sees
lag;dur≥ 140 on the next/nopeandloopLagMs≥ 140 on/healthz.
- The test runs the sampler every 5 ms rather than 50, so the reading can be compared against 140 exactly.
- It then stops the sampler and moves the window's clock forward 10 s; the next response reads lag;dur=0.0.
- The window's clock is separate from the clock that measures lateness, so moving it forward doesn't look like a 10 s stall.
- About 73 existing
*-timingtests compared exact phase lists, so the extra token broke them. They now readrequestTiming(res)from the newtest/helpers/request-timing.ts, which dropslag.test/route-timing.test.ts's exact-format regexes now expect the trailinglag. The tests were too strict for an added token; the code was right. - These tests in particular showed lags of around 160 ms inside the test process, so the stalls are real.
Checks
bun scripts/gate.tsandbun x tsc --noEmitare clean.- On the first push I ran every test file that mentions Server-Timing or
/healthz(272 files), plusflake,principlesand the tests that read AGENTS.md. The only failure wastest/scaffold.test.ts"typechecks under strict settings". It needsbun xto write to a tempdir that is read-only in my sandbox, and it fails the same way on main. - After the
Try:commit I re-ranloop-worst,health,route-timingandmap-cache, and all pass. - The
Try:rule isn't inscripts/gate.ts, so I couldn't check it locally; the forge's next check will tell.
Not done
- The
keep_plantool wasn't available in this session, so the issue has no plan. - The apps proxy's own
forge-*Server-Timing doesn't getlag. Thelagon the forge's own responses is what names the stall.
AGENTS.md now names loopWorst as state shared through process memory, as it asks.
Try it
curl -sI <preview>/nope | grep -i server-timingshows the newlag;durtoken.curl -s -H 'accept: application/json' <preview>/healthzreturnsloopLagMs.
🤖 Generated with Claude Code
The preview works: 30 requests to /nope gave lag;dur 4.9 to 65.8 ms (1x4.9, 7x5.1, 10x5.7, 12x65.8), and /healthz with Accept: application/json returned loopLagMs. No security finding: the lag value is server-computed, JSON is only served on an Accept opt-in, and nothing is injected. Two things to fix in one round:
- Box 4 is not met. The pull description says the 30-request lag was not quoted. The preview exists now, so quote it in the description. The numbers above are a start. Rerun them yourself and name which requests were slow.
- Box 1 says the tick costs under 0.1 ms. The description says it was not measured. Add a test that runs note and worst about 100k times and asserts the mean is under 0.1 ms, or quote a measurement in the description. A stated claim with no test is not enough.
Smaller: the Try: empty commit is noise but harmless. Please also confirm no docs/features entry is needed. This is a header and a health field, so I believe none is.
Every response's Server-Timing now includes lag;dur=<ms>: the worst event-loop lag of the last 10 s. /healthz gives the same number as loopLagMs when the request sends Accept: application/json; without that header it still answers a plain ok. A response with a small app;dur but a slow time to first byte can now be blamed on a stall outside its handler.
src/perf/loop_worst.ts keeps the worst lag in a ring of ten one-second slots. The existing 50 ms sampler in kernel/loop_lag.ts feeds it, and the first server to start launches one unref'd timer for it. Tests that list a request's own timing phases read requestTiming(), which leaves the lag token out.
Tick cost (review box 1). The window in test/loop-worst.test.ts now has a test that runs note then worst 100,000 times and fails unless the average is under 0.1 ms. Run on its own here, the same loop averaged 0.12–0.13 µs per tick, about 800 times under the bound.
Preview, 30 requests to /nope (review box 4). Rerun on this branch's preview just before this push:
- App lag:
lag;durstayed between 3.5 and 5.7 ms on all 30.app;durwas 2.3–7.3 ms. - Normal requests: time to first byte was about 0.64–0.95 s, almost all of it the route from the sandbox to the forge.
- Slow requests: #5 took 1.43 s (
forge-ttfb479 ms), #16 took 1.67 s (forge-ttfb11.9 ms), #21 took 1.43 s (forge-ttfb332 ms) and #30 took 2.33 s (forge-ttfb1625 ms). Each hadlag;durof 3.5–5.7 ms, so in none of them was the app's loop blocked. The time went to the forge's proxy or the network. /healthz: withAccept: application/jsonit returned{"ok":true,"loopLagMs":6.5}.
Docs. There is no new docs/features entry. I added one sentence to docs/features/performance-watcher.md, which already describes each module in src/perf/, saying what loop_worst.ts does.
Not done. The lag is not stored per route or kept beyond the 10 s window; perf/loop.ts already names routes in its loop log line. The empty "Try:" commit stays: removing it would need a force push, which is refused.
Checks. bun scripts/gate.ts and bun x tsc --noEmit pass. So do test/loop-worst.test.ts, test/perf-loop-lag-attribution.test.ts and test/readme-cap.test.ts. I did not run the rest: scripts/fast.ts named 1,674 test files (an estimated 143 minutes), so the forge's full check covers them on this push.
To try it: curl -sD - https://lab--10292--forge-trevato-apps.open-platform.sh/nope -o /dev/null | grep -i server-timing shows lag;dur. curl -H 'accept: application/json' https://lab--10292--forge-trevato-apps.open-platform.sh/healthz shows loopLagMs.
🤖 Generated with Claude Code
Approved. The preview shows lag;dur on /nope (36.4 ms on my request) and /healthz with Accept: application/json answers {"ok":true,"loopLagMs":19.2}. The module is small and one-concept, the sampler is unref and idempotent, the window is O(1) per tick, the token stays out of the perf record, the plain ok body is kept for strangers, and AGENTS.md and the performance-watcher doc are updated. Nothing is added to README. Both earlier asks are met: the tick-cost test is added, and the 30-request preview quote is in the description. I could not run the tests here: the clone is on main and does not have the pull head.
Non-blocking: the empty Try: commit stays because force pushes are refused.
I added
lag;dur=<ms>to every forge response'sServer-Timing: the worst event-loop lag seen in the last 10 s. The issue's last item is not done: this pull's preview doesn't exist until the forge opens the pull, so I couldn't quote itslagacross 30 requests. As a baseline, 30 requests to production/nopegaveapp;dur1.8–6.1 ms each, butforge-ttfbwas 59–1147 ms on 9 of them (59.5, 97.3, 103.1, 137.6, 158.0, 224.2, 286.3, 663.9 and 1147.3 ms). The same 30 requests against the preview should showlagrising on exactly those.What changed
src/perf/loop_worst.ts(new): keeps the worst lag of the last 10 s in ten one-second slots.- It is fed by the existing
startLoopLagsampler inkernel/loop_lag.ts: one unref'd 50 ms timer, started once by the firstserve. - Recording a sample takes constant time and reading the window looks at ten numbers, so a tick costs well under 0.1 ms. I didn't time it, because the repo's rule is to count work rather than time it. - A stall stays visible for 9–10 s after it, because the window moves a second at a time. - With a 50 ms timer, a block can read up to 50 ms short (a 150 ms block reads 100–150).src/http/server.ts:counted()adds the token throughwithLag()insrc/core/route_timing.ts. The token goes on the response only. The perf record's phases leave it out, so per-route phase stats aren't polluted by a number that belongs to the loop, not the request./healthz: still answers plainokto probes and strangers; I kept that body unchanged because the #2917 test pins it. OnlyAccept: application/jsongets{"ok":true,"loopLagMs":n}.Tests
test/loop-worst.test.tschecks the window by hand: slot rollover, reuse of a slot a lap later, and bad input.lag;dur≥ 140 on the next/nopeandloopLagMs≥ 140 on/healthz.- The test runs the sampler every 5 ms rather than 50, so the reading can be compared against 140 exactly. - It then stops the sampler and moves the window's clock forward 10 s; the next response reads
lag;dur=0.0. - The window's clock is separate from the clock that measures lateness, so moving it forward doesn't look like a 10 s stall.*-timingtests compared exact phase lists, so the extra token broke them. They now readrequestTiming(res)from the newtest/helpers/request-timing.ts, which dropslag.test/route-timing.test.ts's exact-format regexes now expect the trailinglag. The tests were too strict for an added token; the code was right.Checks
bun scripts/gate.tsandbun x tsc --noEmitare clean./healthz(272 files), plusflake,principlesand the tests that read AGENTS.md.test/scaffold.test.ts"typechecks under strict settings". It needsbun xto write to a tempdir that is read-only in my sandbox, and it fails the same way on main.Not done
keep_plantool wasn't available in this session, so the issue has no plan.forge-*Server-Timing doesn't getlag. Thelagon the forge's own responses is what names the stall.AGENTS.mdnow namesloopWorstas state shared through process memory, as it asks.Try it
curl -sI <preview>/nope | grep -i server-timingshows the newlag;durtoken.curl -s -H 'accept: application/json' <preview>/healthzreturnsloopLagMs.🤖 Generated with Claude Code
Closes #10288