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

Every GET /api/v1 route the timing walk exercises answers in under 1 s on the fixture, and the walk names its five slowest on every run #8148

Merged opened this

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

Merged

The route-timing walk now prints its five slowest routes on every run, and a new test fails if any walked route takes 1 s or more. No walked route is over 1 s locally, so no route module changed: this pull adds only the report and the 1 s guard, as the issue's Risk line allows.

shipped production is serving it deploy f9c1fcc

opened this

The route-timing walk now prints its five slowest routes on every run, and a new test fails if any walked route takes 1 s or more. No walked route is over 1 s locally, so no route module changed: this pull adds only the report and the 1 s guard, as the issue's Risk line allows.

What changed (all in test/route-timing-coverage.test.ts):

  • The walk keeps every answer it gets. A finally block prints the five slowest as pattern -> status in ms, slowest first, so the list appears whether the walk passes or fails.
  • New test, "every walked route answers under 1 s on the fixture": it checks each walked route against ROUTE_MS = 1_000 and lists any that reach it as pattern -> status in ms, so a regression names its route.
  • New unit test for the report: given seven made-up timings, the report must return the right five in the right order, worked out by hand.
  • REQUEST_MS, UNEXERCISED and UNTIMED are unchanged. Requests still run in batches of 8.

Five slowest, from three local runs of bun test test/route-timing-coverage.test.ts:

RouteRun 1Run 2Run 3
/api/v1/repos/:owner/:name/waves92 ms133 ms120 ms
/api/v1/repos/:owner/:name/map91 ms133 ms120 ms
/api/v1/map91 ms133 ms120 ms
/api/v1/asked91 ms133 ms—
/api/v1/flags90 ms——
/api/v1/repos/:owner/:name/waves/:version (404)—133 ms—
/api/v1/telemetry/home——98 ms
/api/v1/telemetry/sources——98 ms

All statuses were 200 except the one marked 404. Because the 8 requests in a batch run at once, these times include waiting behind the rest of the batch. That is why routes in the same batch show the same number. The slowest route took about an eighth of the 1 s limit.

Not done: I didn't change any route's code, since none was slow. I didn't fix a specific number of batches into the guard.

Checks: bun scripts/gate.ts and bun x tsc --noEmit passed. The 13 test files named by bun scripts/fast.ts passed (178 tests). The full suite was not run here; the forge runs it on this push.

To try it: run bun test test/route-timing-coverage.test.ts and read the "five slowest walked routes" block at the top of the output.

🤖 Generated with Claude Code

Closes #8145

commented

The route-timing walk now prints its five slowest routes on every run, and a new test fails if any walked route takes 1 s or more. No walked route is over 1 s locally, so no route module changed: this pull adds only the report and the 1 s guard, as the issue's Risk line allows.

What changed (all in test/route-timing-coverage.test.ts):

  • The walk keeps every answer it gets. A finally block prints the five slowest as pattern -> status in ms, slowest first, so the list appears whether the walk passes or fails.
  • New test, "every walked route answers under 1 s on the fixture": it checks each walked route against ROUTE_MS = 1_000 and lists any that reach it as pattern -> status in ms, so a regression names its route.
  • New unit test for the report: given seven made-up timings, the report must return the right five in the right order, worked out by hand.
  • REQUEST_MS, UNEXERCISED and UNTIMED are unchanged. Requests still run in batches of 8.

Five slowest, from three local runs of bun test test/route-timing-coverage.test.ts:

RouteRun 1Run 2Run 3
/api/v1/repos/:owner/:name/waves92 ms133 ms120 ms
/api/v1/repos/:owner/:name/map91 ms133 ms120 ms
/api/v1/map91 ms133 ms120 ms
/api/v1/asked91 ms133 ms—
/api/v1/flags90 ms——
/api/v1/repos/:owner/:name/waves/:version (404)—133 ms—
/api/v1/telemetry/home——98 ms
/api/v1/telemetry/sources——98 ms

All statuses were 200 except the one marked 404. Because the 8 requests in a batch run at once, these times include waiting behind the rest of the batch. That is why routes in the same batch show the same number. The slowest route took about an eighth of the 1 s limit.

Not done: I didn't change any route's code, since none was slow. I didn't fix a specific number of batches into the guard.

Checks: bun scripts/gate.ts and bun x tsc --noEmit passed. The 13 test files named by bun scripts/fast.ts passed (178 tests). The full suite was not run here; the forge runs it on this push.

To try it: run bun test test/route-timing-coverage.test.ts and read the "five slowest walked routes" block at the top of the output.

🤖 Generated with Claude Code

Changes requested — before the latest push

The report and the 1 s guard are the right shape, but the guard as written can flake and depends on test order. The direction is fast tests that never flake. Two changes, both in test/route-timing-coverage.test.ts:

  1. The 1 s guard measures wall time inside an 8-wide concurrent batch. Each route's ms includes queueing behind its seven neighbours, and the forge check runs many suites at once. A loaded machine can push an honest route past 1000 ms, and the guard then goes red on an unrelated pull. Make it measure the route, not the queue: re-time only the routes that reach 1 s, one at a time, and fail only if they are still slow; or read the server's own Server-Timing total.
  1. The guard test reads walk, which the previous test fills. Under --test-name-pattern, or if the first test fails before the finally block runs, walk.length is 0 and the guard fails for a reason that is not a slow route. Do the 1 s check inside the walk test, or share one beforeAll walk that both tests read.

Smaller: slowest and the slow mapping build the same string twice; extract one helper.

commented

The route-timing walk now prints its five slowest routes on every run, green or red. A new test checks that every walked route answers in under 1 s on the fixture. No walked route is over 1 s locally, so no route module changed: this pull lands only the report and the 1 s guard, as the issue's Risk line allows.

All changes are in test/route-timing-coverage.test.ts:

  • One shared walk: the walk runs once, in batches of 8 as before, and both the session-phase test and the 1 s guard wait for it. Either test now passes on its own under --test-name-pattern. The five slowest print as pattern -> status in ms even when the walk fails partway.
  • No flaking on a busy machine: a walk answer's time includes waiting behind the other seven requests in its batch. So a route that takes 1 s or more in the walk is asked again on its own, and only a route still slow by itself fails the guard, named with its pattern, status and ms.
  • One line helper formats a result as pattern -> status in ms. The report, the failure lists and the guard all use it. A unit test checks the slowest-five order and format against seven made-up timings.
  • REQUEST_MS, UNEXERCISED and UNTIMED are unchanged.

Five slowest in the latest local run (all 200, about 1.4 s for the whole file). Routes in the same batch show the same time because they were sent together:

  • /api/v1/flags — 63 ms
  • /api/v1/telemetry/system — 63 ms
  • /api/v1/telemetry/flow — 63 ms
  • /api/v1/telemetry/home — 63 ms
  • /api/v1/telemetry/sources — 63 ms

Earlier runs put /api/v1/repos/:owner/:name/waves, /api/v1/repos/:owner/:name/map, /api/v1/map and /api/v1/asked on top, at 90–133 ms.

I chose re-timing slow routes one at a time over reading the server's own Server-Timing total. Re-timing measures what a client actually waits for, and the guard does not depend on every route reporting a total. The re-timing branch has no test of its own, because the fixture has no slow route to drive it.

Checks: the full file passes, the guard passes when run alone, and bun x tsc --noEmit and bun scripts/gate.ts pass. I did not run the full suite; the forge runs it on this push.

To try it: bun test test/route-timing-coverage.test.ts, then add --test-name-pattern "under 1 s" to run the guard alone.

🤖 Generated with Claude Code

Approved

Both earlier asks are met. Slow routes are now re-timed alone before they fail, so queueing behind the batch no longer flakes the guard. The walk is shared through one memoized promise, so each test passes alone under --test-name-pattern. The five slowest print in a finally block on green and red, and the slowest-five order has a unit test. This is test-only, with no dependency or security surface. Two next steps, both non-blocking: (1) Non-blocking: the re-time branch has no test. Inject the timer into a small helper so a fake slow route can drive it. (2) Non-blocking: the walk's time and the alone time are both wall-clock, so print the alone time next to the walk time in the failure line to make a real regression obvious.

Sign in to join this conversation.

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs