Merge pull request #20 from thelastbackspace/feat/baseline

run: count-based baselines for a deterministic PR check

Author: thelastbackspace

CHANGELOG.md

@@ -7,6 +7,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+### Added
+- **A PR check that isn't flaky:** `traceperf run --save-baseline perf-baseline.json` records how many calls of each kind every route makes per request; `--baseline perf-baseline.json` compares and exits 1 when a route makes more (`GET /orders: pg SELECT items 1 → 12 per request (an N+1?)`) or a new N+1 / error appears. Counts, not timings, so the result is the same on any machine.
+
 ### Added
 - **Fastify route labels:** with `traceperf/auto` or `traceperf run`, Fastify (3–5) requests are labelled by route, `GET /api/articles/:slug`, instead of one label per URL. `traceperf/auto` wraps the `fastify()` factory to add an `onRequest` hook (`wrapFastifyFactory` for doing it by hand). Any framework can do the same by setting the `ROUTE` symbol on the raw request.
 - **Koa route labels:** with `@koa/router` or `koa-router`, Koa requests are labelled by the matched route (`GET /api/users/:id`), auto-detected; `labelKoaRoutes(require('koa'))` by hand.

README.md

@@ -106,6 +106,30 @@ Checked on real apps, not only on the planted ones: Prisma's REST example, the R
 - `--no-profile`: don't sample the CPU.
 - Any start command works: `npx traceperf run -- npm start`.
 
+### In CI: fail a PR that adds queries
+
+Timings are too noisy to gate a PR on (the same run can be twice as fast on an idle machine), but how many queries a route makes per request is exact. Save a baseline once, commit it, and compare on every PR:
+
+<!-- docs:skip -->
+```bash
+npx traceperf run server.js --path /orders --path /users/1 --save-baseline perf-baseline.json
+npx traceperf run server.js --path /orders --path /users/1 --baseline perf-baseline.json   # exit 1 on regressions
+```
+
+```
+Compared with perf-baseline.json:
+  ✖ GET /orders: pg SELECT items 1 → 12 per request (an N+1?)
+  ✖ new problem: N+1 in GET /orders
+```
+
+It fails when a route makes more calls of any kind per request (database queries, HTTP calls, Redis commands) or an N+1 or error appears; fewer calls are reported as improvements. Counts come from the one-at-a-time requests, so they don't depend on the machine. In GitHub Actions, with a service container for the database:
+
+<!-- docs:skip -->
+```yaml
+- run: npm ci && npm run db:seed
+- run: npx traceperf run dist/server.js --path /orders --path /users/1 --baseline perf-baseline.json
+```
+
 `examples/slow-apps/` has small apps with one planted problem each (blocking in your code, blocking in built-ins, sequential awaits, N+1, a slow dependency, errors); CI checks that `run` names each one.
 
 The same naming works without `run`: `TRACEPERF_PROFILE_BLOCKING=1 node --require traceperf/auto server.js` adds the function names to the exit summary (sampling costs a few percent CPU, so use it while investigating). In code: `profileSlowCalls({ select: root => blockingRanges(root), mergeInlined: true, onProfile })`, then `explain(roots, { hotspots })`.

src/__tests__/run.test.ts

@@ -259,6 +259,32 @@ describe('naming blocking code from CPU profiles', () => {
   });
 });
 
+describe('baselines (calls per request per route)', () => {
+  const { baselineOf, compareBaseline } = jest.requireActual('../run');
+  const n = (label: string, children: any[] = []) => ({ label, children });
+  const orders = (items: number) => n('GET /orders', [n('pg SELECT orders'), ...Array.from({ length: items }, () => n('pg SELECT items'))]);
+
+  it('takes the median count of each call per request', () => {
+    const b = baselineOf([orders(1), orders(1), orders(3), n('GET /health')], []);
+    expect(b.routes).toEqual({
+      'GET /health': { requests: 1, calls: {} },
+      'GET /orders': { requests: 3, calls: { 'pg SELECT items': 1, 'pg SELECT orders': 1 } },
+    });
+    const withN1 = baselineOf([orders(12)], [{ kind: 'repeated', root: 'GET /orders', ms: 50, message: '' }, { kind: 'blocking', root: 'GET /x', ms: 20, message: '' }]);
+    expect(withN1.problems).toEqual(['N+1 in GET /orders']); // blocking is timing, not in the baseline
+  });
+
+  it('flags more calls per request and new problems; reports improvements', () => {
+    const before = baselineOf([orders(1), n('GET /old')], []);
+    const after = baselineOf([orders(12), n('GET /new')], [{ kind: 'repeated', root: 'GET /orders', ms: 50, message: '' }]);
+    const r = compareBaseline(before, after);
+    expect(r.regressions).toEqual(['GET /orders: pg SELECT items 1 → 12 per request (an N+1?)', 'new problem: N+1 in GET /orders']);
+    expect(r.notes).toEqual(['GET /new: new route (not in the baseline)', 'GET /old: not requested in this run']);
+    expect(compareBaseline(after, before).improvements).toEqual(['GET /orders: pg SELECT items 12 → 1 per request', 'fixed: N+1 in GET /orders']);
+    expect(compareBaseline(before, before)).toEqual({ regressions: [], improvements: [], notes: [] });
+  });
+});
+
 describe('statusFinding', () => {
   const { statusFinding } = jest.requireActual('../run');
   const load = (statuses: Record<string, number>, errors = 0) => ({ requests: 10, errors, statuses, durationMs: 1, latency: {} });

src/run.ts

@@ -34,6 +34,10 @@ export interface RunArgs {
   /** Request headers, e.g. { authorization: 'Bearer ...' } */
   headers?: Record<string, string>;
   html?: string;
+  /** Write call counts per route here (a baseline for --baseline) */
+  saveBaseline?: string;
+  /** Compare call counts per route with this baseline; exit 1 on more calls or new problems */
+  baseline?: string;
   output?: string;
   json: boolean;
   max: number;
@@ -59,6 +63,10 @@ export const RUN_USAGE = `  traceperf run <app.js> [app args] [options]
       --html out.html  write an HTML report
       --output f.jsonl keep the raw request trees
       --json           print stats and findings as JSON
+      --save-baseline f.json   save calls per request for each route (commit it)
+      --baseline f.json        compare with it; exit 1 if a route makes more calls
+                               (e.g. an N+1) or a new problem appears. Counts, not
+                               timings: deterministic, safe for CI
       --no-profile     don't sample the CPU (blocking code is then named
                        only by its tracked call)`;
 
@@ -134,6 +142,8 @@ export function parseRunArgs(argv: string[]): RunArgs | string {
         break;
       }
       case '--json': args.json = true; break;
+      case '--save-baseline': if (!(args.saveBaseline = argv[++i])) return '--save-baseline expects a file'; break;
+      case '--baseline': if (!(args.baseline = argv[++i])) return '--baseline expects a file'; break;
       case '--no-profile': args.profile = false; break;
       case '--probe': {
         const n = Number(argv[++i]);
@@ -344,6 +354,76 @@ export function statusFinding(load: LoadResult): Finding | undefined {
   };
 }
 
+/** Calls per request for each route, and the kinds of problem found: deterministic, unlike timings */
+export interface Baseline {
+  version: 1;
+  routes: Record<string, { requests: number; calls: Record<string, number> }>;
+  /** "kind route" of repeated-call (N+1) and error findings: counts, so deterministic (blocking is timing, so not here) */
+  problems: string[];
+}
+
+interface CountNode { label: string; children: CountNode[] }
+
+/** Median number of each call label per request, per route */
+export function baselineOf(trees: CountNode[], findings: Finding[]): Baseline {
+  const byRoute = new Map<string, Array<Map<string, number>>>();
+  for (const tree of trees) {
+    const counts = new Map<string, number>();
+    const walk = (n: CountNode) => n.children.forEach(c => {
+      counts.set(c.label, (counts.get(c.label) || 0) + 1);
+      walk(c);
+    });
+    walk(tree);
+    const list = byRoute.get(tree.label) ?? [];
+    list.push(counts);
+    byRoute.set(tree.label, list);
+  }
+  const routes: Baseline['routes'] = {};
+  [...byRoute.keys()].sort().forEach(route => {
+    const list = byRoute.get(route)!;
+    const labels = [...new Set(list.flatMap(m => [...m.keys()]))].sort();
+    const calls: Record<string, number> = {};
+    for (const label of labels) {
+      const values = list.map(m => m.get(label) || 0).sort((a, b) => a - b);
+      const median = values[Math.floor((values.length - 1) / 2)];
+      if (median > 0) calls[label] = median;
+    }
+    routes[route] = { requests: list.length, calls };
+  });
+  const problems = [...new Set(findings
+    .filter(f => (f.kind === 'repeated' || f.kind === 'error') && f.root !== 'load')
+    .map(f => `${f.kind === 'repeated' ? 'N+1' : 'errors'} in ${f.root}`))].sort();
+  return { version: 1, routes, problems };
+}
+
+/** Differences that make a PR worse: more calls per request on a route, or a new problem */
+export function compareBaseline(before: Baseline, now: Baseline): { regressions: string[]; improvements: string[]; notes: string[] } {
+  const regressions: string[] = [];
+  const improvements: string[] = [];
+  const notes: string[] = [];
+  for (const route of Object.keys(now.routes).sort()) {
+    const b = before.routes[route];
+    const a = now.routes[route];
+    if (!b) {
+      notes.push(`${route}: new route (not in the baseline)`);
+      continue;
+    }
+    const labels = [...new Set([...Object.keys(b.calls), ...Object.keys(a.calls)])].sort();
+    for (const label of labels) {
+      const x = b.calls[label] || 0;
+      const y = a.calls[label] || 0;
+      if (y > x) regressions.push(`${route}: ${label} ${x} → ${y} per request${x <= 1 && y >= 5 ? ' (an N+1?)' : ''}`);
+      else if (y < x) improvements.push(`${route}: ${label} ${x} → ${y} per request`);
+    }
+  }
+  for (const route of Object.keys(before.routes)) {
+    if (!now.routes[route]) notes.push(`${route}: not requested in this run`);
+  }
+  for (const p of now.problems) if (!before.problems.includes(p)) regressions.push(`new problem: ${p}`);
+  for (const p of before.problems) if (!now.problems.includes(p)) improvements.push(`fixed: ${p}`);
+  return { regressions, improvements, notes };
+}
+
 export interface RunSummary {
   stats: string;
   findings: Finding[];
@@ -584,11 +664,25 @@ export async function runApp(args: RunArgs, deps: RunDeps): Promise<number> {
     const after = summary.findings.filter(f => f.kind === 'error' || f.kind === 'blocking').length;
     summary.findings.splice(after, 0, ...queued);
   }
+  // Baselines use the one-at-a-time probe when there is one (the same requests every run)
+  let baselineReport: { regressions: string[]; improvements: string[]; notes: string[] } | undefined;
+  let baselineError: string | undefined;
+  if ((args.saveBaseline || args.baseline) && summary.trees) {
+    const current = baselineOf(deps.parseTrees(probeText.trim() ? probeText : text), summary.findings);
+    if (args.saveBaseline) fs.writeFileSync(args.saveBaseline, JSON.stringify(current, null, 2) + '\n');
+    if (args.baseline) {
+      try {
+        baselineReport = compareBaseline(JSON.parse(fs.readFileSync(args.baseline, 'utf8')), current);
+      } catch (e) {
+        baselineError = `traceperf: could not read the baseline ${args.baseline}: ${e instanceof Error ? e.message : String(e)}`;
+      }
+    }
+  }
   if (args.html && summary.trees) {
     fs.writeFileSync(args.html, deps.report(text, { html: true, findings: summary.findings, title: `traceperf run: ${args.command.join(' ')}` }));
   }
   if (args.json) {
-    deps.out(JSON.stringify({ load, trees: summary.trees, findings: summary.findings }, null, 2));
+    deps.out(JSON.stringify({ load, trees: summary.trees, findings: summary.findings, ...(baselineReport ? { baseline: baselineReport } : {}) }, null, 2));
   } else if (!summary.trees) {
     deps.out('\ntraceperf: no requests were tracked.');
   } else {
@@ -600,10 +694,21 @@ export async function runApp(args: RunArgs, deps: RunDeps): Promise<number> {
     lines.push('', summary.stats, '', 'Why it was slow:', formatFindings(summary.findings));
     if (args.html) lines.push('', `HTML report: ${args.html}`);
     if (args.output) lines.push(`Request trees: ${args.output}`);
+    if (args.saveBaseline) lines.push(`Baseline saved: ${args.saveBaseline}`);
+    if (baselineReport) {
+      const { regressions, improvements, notes } = baselineReport;
+      lines.push('', `Compared with ${args.baseline}:`);
+      regressions.forEach(r => lines.push(`  ✖ ${r}`));
+      improvements.forEach(r => lines.push(`  ✔ ${r}`));
+      notes.forEach(r => lines.push(`  · ${r}`));
+      if (!regressions.length && !improvements.length) lines.push('  ✔ same calls per request on every route');
+    }
     deps.out(lines.join('\n'));
   }
+  if (baselineError) deps.err(baselineError);
   if (!args.output) fs.rmSync(dir, { recursive: true, force: true });
   // Interactive runs end with Ctrl-C; that is success. A crash before any traffic is not.
+  if (baselineError || (baselineReport && baselineReport.regressions.length)) return 1;
   return !summary.trees && exitCode ? 1 : 0;
 }