Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
24 changes: 24 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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 })`.
Expand Down
26 changes: 26 additions & 0 deletions src/__tests__/run.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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: {} });
Expand Down
107 changes: 106 additions & 1 deletion src/run.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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)`;

Expand Down Expand Up @@ -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]);
Expand Down Expand Up @@ -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[];
Expand Down Expand Up @@ -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 {
Expand All @@ -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;
}

Expand Down
Loading