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
Check · Review · Land · Live done — Landed and live in production.
torque/forge:torque/8145-every-get-api-v1-route-the-timing-walk-e → main 2 commits fork 2 threads · 2 unresolved
1 file
changed +60
−9
test/route-timing-coverage.test.ts +60 −9
| @@ -106,23 +106,74 @@ async function timed(pattern: string): Promise<Answer> { | ||
| 106 | 106 | const walked = (): string[] => getPatterns().filter((p) => !(p in UNEXERCISED)); |
| 107 | 107 | const WALK_MS = Math.ceil(walked().length / BATCH) * REQUEST_MS + 5_000; |
| 108 | 108 | |
| 109 | test("no GET route answers 200 without a session phase unless the allowlist names it", async () => { | |
| 109 | /** One walked route's whole allowance on the fixture (#8145): over it, the route is the finding. */ | |
| 110 | const ROUTE_MS = 1_000; | |
| 111 | ||
| 112 | type Row = { pattern: string; answer: Answer }; | |
| 113 | ||
| 114 | /** One row as `pattern -> status in ms`: the form every finding and the report print. */ | |
| 115 | const line = ({ pattern, answer }: Row): string => `${pattern} -> ${answer.status} in ${answer.ms}ms`; | |
| 116 | ||
| 117 | /** The five slowest walked routes, slowest first. */ | |
| 118 | const slowest = (rows: Row[], n = 5): string[] => | |
| 119 | [...rows].sort((a, b) => b.answer.ms - a.answer.ms).slice(0, n).map(line); | |
| 120 | ||
| 121 | /** | |
| 122 | * The walk, run once and shared: each test that reads it awaits it, so either | |
| 123 | * passes alone under --test-name-pattern. The five slowest are printed green or | |
| 124 | * red, so the next slow route shows before it times out. | |
| 125 | */ | |
| 126 | let walking: Promise<Row[]> | undefined; | |
| 127 | const walk = (): Promise<Row[]> => walking ??= (async () => { | |
| 110 | 128 | const patterns = walked(); |
| 111 | const results: Answer[] = []; | |
| 112 | for (let i = 0; i < patterns.length; i += BATCH) { | |
| 113 | results.push(...(await Promise.all(patterns.slice(i, i + BATCH).map((p) => timed(p))))); | |
| 129 | const rows: Row[] = []; | |
| 130 | try { | |
| 131 | for (let i = 0; i < patterns.length; i += BATCH) { | |
| 132 | const batch = patterns.slice(i, i + BATCH); | |
| 133 | const answers = await Promise.all(batch.map((p) => timed(p))); | |
| 134 | batch.forEach((pattern, j) => rows.push({ pattern, answer: answers[j]! })); | |
| 135 | } | |
| 136 | } finally { | |
| 137 | console.log(`five slowest walked routes:\n ${slowest(rows).join("\n ")}`); | |
| 114 | 138 | } |
| 139 | return rows; | |
| 140 | })(); | |
| 141 | ||
| 142 | test("no GET route answers 200 without a session phase unless the allowlist names it", async () => { | |
| 143 | const rows = await walk(); | |
outdated
Depends on the previous test having filled |
||
| 115 | 144 | // A throttled or failing route is not a route that was checked. |
| 116 | 145 | // Each finding names its pattern, status (0 = timed out) and elapsed ms, so a red run says which route. |
| 117 | const unchecked = patterns | |
| 118 | .map((p, i) => `${p} -> ${results[i]!.status} in ${results[i]!.ms}ms`) | |
| 119 | .filter((_, i) => results[i]!.status === 0 || results[i]!.status === 429 || results[i]!.status >= 500); | |
| 146 | const unchecked = rows | |
| 147 | .filter(({ answer: a }) => a.status === 0 || a.status === 429 || a.status >= 500) | |
| 148 | .map(line); | |
| 120 | 149 | expect(unchecked).toEqual([]); |
| 121 | expect(results.filter((r) => r.status === 200).length).toBeGreaterThan(0); | |
| 122 | const untimed = patterns.filter((_, i) => results[i]!.status === 200 && !results[i]!.session); | |
| 150 | expect(rows.filter((r) => r.answer.status === 200).length).toBeGreaterThan(0); | |
| 151 | const untimed = rows.filter((r) => r.answer.status === 200 && !r.answer.session).map((r) => r.pattern); | |
| 123 | 152 | expect(untimed.filter((p) => !(p in UNTIMED))).toEqual([]); |
| 124 | 153 | }, WALK_MS); |
| 125 | 154 | |
| 155 | /** | |
| 156 | * A batched answer's ms includes queueing behind its seven neighbours, so a | |
| 157 | * route that reaches ROUTE_MS in the walk is asked again alone, and only a | |
| 158 | * route still slow by itself is the finding. | |
| 159 | */ | |
| 160 | test("every walked route answers under 1 s on the fixture", async () => { | |
| 161 | const rows = await walk(); | |
| 162 | expect(rows.length).toBeGreaterThan(0); | |
| 163 | const slow: Row[] = []; | |
| 164 | for (const { pattern, answer } of rows) { | |
| 165 | if (answer.ms < ROUTE_MS) continue; | |
| 166 | const alone = await timed(pattern); | |
| 167 | if (alone.ms >= ROUTE_MS) slow.push({ pattern, answer: alone }); | |
| 168 | } | |
| 169 | expect(slow.map(line)).toEqual([]); | |
| 170 | }, WALK_MS * 2); | |
| 171 | ||
| 172 | test("the slowest-five report orders by elapsed ms and names pattern, status and ms", () => { | |
| 173 | const rows = [10, 900, 40, 1200, 5, 300, 70].map((ms, i) => ({ pattern: `/r${i}`, answer: { status: 200, session: true, ms } })); | |
| 174 | expect(slowest(rows)).toEqual(["/r3 -> 200 in 1200ms", "/r1 -> 200 in 900ms", "/r5 -> 200 in 300ms", "/r6 -> 200 in 70ms", "/r2 -> 200 in 40ms"]); | |
| 175 | }); | |
| 176 | ||
| 126 | 177 | test("an allowlisted route that now names session leaves the list", async () => { |
| 127 | 178 | const patterns = new Set(getPatterns()); |
| 128 | 179 | const stale: string[] = []; |
new above
offline
Batch wall time includes queueing behind 7 concurrent requests; under a loaded check machine this can exceed 1 s without any route being slow. Re-time offenders serially before failing.