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
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
- `traceperf/auto` wrote each request tree with its own `appendFileSync`, and under load that showed up as the app's "CPU cost" (`writeFileUtf8`). Writes are batched every 20 ms.

### Added
- `traceperf run` reads `traceperf.config.json` (or `--config file`); command-line options win. A `login` step logs in before the traffic and sends the returned token or cookies with every request; `${NAME}` in the file is read from the environment.
- `npm run eval` scores `traceperf run` on 20 apps in `examples/slow-apps`: 12 with a planted problem, 8 clean ones where the right answer is "no issues". CI fails on any missed problem or false alarm. Before these fixes: 17/17 found, 15 false alarms; after: 17/17, 0.

### Added
Expand Down
21 changes: 20 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -105,6 +105,25 @@ Checked on real apps, not only on the planted ones: Prisma's REST example, the R
- `--warmup 3`: untimed requests per path first, so cold-start work doesn't look like a problem.
- `--no-profile`: don't sample the CPU.
- Any start command works: `npx traceperf run -- npm start`.
- `--config file.json`: read the options from a file (`traceperf.config.json` is read automatically when present). Options given on the command line win.

**Config file and login.** Put the routes in `traceperf.config.json` so the command is just `npx traceperf run`. A `login` step runs once before the traffic, and its token (or cookie) is sent with every request, so an expired token can't silently turn the run into a benchmark of 401 pages. `${NAME}` is read from the environment:

<!-- docs:skip -->
```json
{
"app": "dist/server.js",
"paths": ["/api/articles", "/api/user"],
"login": {
"path": "/api/users/login",
"body": { "user": { "email": "${TEST_EMAIL}", "password": "${TEST_PASSWORD}" } },
"token": "user.token",
"prefix": "Token "
}
}
```

`token` is the dotted path of the token in the JSON response, sent as `authorization: Bearer <token>` unless `header` / `prefix` say otherwise. Leave `token` out to use the cookies the login sets. `method` defaults to POST.

### In CI: fail a PR that adds queries

Expand All @@ -130,7 +149,7 @@ It fails when a route makes more calls of any kind per request (database queries
- 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.
`examples/slow-apps/` has 20 small apps: 12 with one planted problem each (blocking in your code and in built-ins, sequential awaits, N+1 over SQL and over HTTP, a slow or flaky dependency, failing requests…) and 8 clean ones where the right answer is "no issues". `npm run eval` scores `run` on them, and CI fails on a missed problem or a false alarm.

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
49 changes: 49 additions & 0 deletions src/__tests__/run.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -363,3 +363,52 @@ describe('queueFindings', () => {
expect(busy.fix).toMatch(/throughput limit/);
});
});

describe('config file and login', () => {
const read = (text: string) => (file?: string) => (file === 'missing.json' ? undefined : text);

it('reads options from the file; the command line wins and its --path replaces the file paths', () => {
const config = JSON.stringify({ app: 'server.js', paths: ['/a', '/b'], concurrency: 4, duration: '2s', headers: { 'X-Key': '${KEY}' }, probe: 0 });
const fromFile = parseRunArgs([], read(config), { KEY: 'secret' }) as RunArgs;
expect(fromFile).toMatchObject({ command: ['server.js'], paths: ['/a', '/b'], concurrency: 4, durationMs: 2000, headers: { 'x-key': 'secret' }, probe: 0 });
const overridden = parseRunArgs(['-c', '8', '--path', '/c'], read(config), {}) as RunArgs;
expect(overridden).toMatchObject({ command: ['server.js'], paths: ['/c'], concurrency: 8 });
expect((parseRunArgs(['other.js'], read(config), {}) as RunArgs).command).toEqual(['other.js']);
expect(parseRunArgs([], read('{'), {})).toMatch(/not valid JSON/);
expect(parseRunArgs(['--config', 'missing.json', 'x.js'], read(''), {})).toMatch(/could not read missing.json/);
expect(parseRunArgs([], read('{}'), {})).toMatch(/"app" in the config file/);
});

it('logs in first and sends the token from the JSON response with every request', async () => {
const seen: Array<string | undefined> = [];
const server = http.createServer((req, res) => {
let body = '';
req.on('data', c => { body += c; });
req.on('end', () => {
if (req.url === '/login') {
const { password } = JSON.parse(body);
if (password !== 'pw') { res.statusCode = 401; return res.end('bad password'); }
return res.end(JSON.stringify({ user: { token: 'abc' } }));
}
if (req.url === '/cookie-login') { res.setHeader('set-cookie', ['sid=42; HttpOnly', 'theme=dark']); return res.end('{}'); }
seen.push(req.headers.authorization || req.headers.cookie);
res.end('ok');
});
});
await new Promise<void>(r => server.listen(0, '127.0.0.1', () => r()));
const port = (server.address() as AddressInfo).port;
try {
const args = parseRunArgs(['x.js']) as RunArgs;
const { login } = await import('../run');
expect(await login(http, args, port, { path: '/login', body: { password: 'pw' }, token: 'user.token' })).toEqual({ authorization: 'Bearer abc' });
expect(await login(http, args, port, { path: '/login', body: { password: 'pw' }, token: 'user.token', header: 'X-Token', prefix: '' })).toEqual({ 'x-token': 'abc' });
expect(await login(http, args, port, { path: '/cookie-login' })).toEqual({ cookie: 'sid=42; theme=dark' });
expect(await login(http, args, port, { path: '/login', body: { password: 'no' }, token: 'user.token' })).toMatch(/answered 401: bad password/);
expect(await login(http, args, port, { path: '/login', body: { password: 'pw' }, token: 'missing.path' })).toMatch(/no "missing.path"/);
await sendLoad(http, { ...args, paths: ['/x'], requests: 2, concurrency: 1, headers: { authorization: 'Bearer abc' } }, port);
expect(seen).toEqual(['Bearer abc', 'Bearer abc']);
} finally {
server.close();
}
});
});
14 changes: 12 additions & 2 deletions src/cli.ts
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,16 @@ import { renderHtmlReport } from './report-html';
import { createWatcher, WatchOptions } from './watch';
import { parseRunArgs, runApp, RUN_USAGE } from './run';

/** --config FILE, or traceperf.config.json in the working directory when there is one */
function readRunConfig(file?: string): string | undefined {
/* eslint-disable @typescript-eslint/no-require-imports */
const fs = require('fs');
const target = require('path').resolve(file || 'traceperf.config.json');
/* eslint-enable @typescript-eslint/no-require-imports */
if (!file && !fs.existsSync(target)) return undefined;
return fs.readFileSync(target, 'utf8');
}

export interface ReportOptions {
top?: number;
/** Return a self-contained HTML report instead of text */
Expand Down Expand Up @@ -381,7 +391,7 @@ export function main(argv: string[], io: {
return runWatchOnce(rest, io);
}
if (command === 'run') {
const args = parseRunArgs(rest);
const args = parseRunArgs(rest, readRunConfig, process.env);
io.err(typeof args === 'string' ? `traceperf: ${args}\n\n${RUN_USAGE}` : 'traceperf: run starts an app; use the traceperf command');
return 1;
}
Expand Down Expand Up @@ -559,7 +569,7 @@ if (typeof require !== 'undefined' && typeof module !== 'undefined' && require.m
const fs = require('fs');
const argv = process.argv.slice(2);
const watchArgs = argv[0] === 'watch' ? parseWatchArgs(argv.slice(1)) : undefined;
const runArgs = argv[0] === 'run' ? parseRunArgs(argv.slice(1)) : undefined;
const runArgs = argv[0] === 'run' ? parseRunArgs(argv.slice(1), readRunConfig, process.env) : undefined;
if (watchArgs && typeof watchArgs !== 'string' && !watchArgs.once) {
watchLive(watchArgs, fs);
} else if (runArgs && typeof runArgs !== 'string') {
Expand Down
167 changes: 164 additions & 3 deletions src/run.ts
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,8 @@ export interface RunArgs {
profile: boolean;
/** Ms to wait for the app to listen before giving up */
startTimeoutMs: number;
/** From the config file: log in first and send the token with every request */
login?: RunLogin;
}

export const RUN_USAGE = ` traceperf run <app.js> [app args] [options]
Expand All @@ -67,6 +69,9 @@ export const RUN_USAGE = ` traceperf run <app.js> [app args] [options]
--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
--config f.json read these options from a file (default: traceperf.config.json
if present; command-line options win). It can also log in
first: "login": {"path": "/api/login", "body": {...}, "token": "user.token"}
--no-profile don't sample the CPU (blocking code is then named
only by its tracked call)`;

Expand All @@ -78,8 +83,113 @@ function parseDuration(value: string | undefined): number | undefined {
}

/** Parse `run` arguments; returns an error message on bad input */
export function parseRunArgs(argv: string[]): RunArgs | string {
const args: RunArgs = {
/** Log in before the traffic and send the token (or cookie) it returns with every request */
export interface RunLogin {
path: string;
/** Default POST */
method?: string;
/** JSON request body; "${NAME}" in strings is replaced by the environment variable */
body?: unknown;
headers?: Record<string, string>;
/** Dotted path of the token in the JSON response, e.g. "user.token"; without it the Set-Cookie header is used */
token?: string;
/** Header to send it in (default authorization) */
header?: string;
/** Text before the token (default "Bearer ") */
prefix?: string;
}

/** traceperf.config.json: the same settings as the command-line options */
export interface RunConfig {
app?: string | string[];
paths?: string[];
concurrency?: number;
duration?: string | number;
requests?: number;
method?: string;
headers?: Record<string, string>;
warmup?: number;
probe?: number;
port?: number;
baseline?: string;
saveBaseline?: string;
html?: string;
login?: RunLogin;
}

/** Replace "${NAME}" with process environment values, in every string of a JSON value */
export function interpolateEnv<T>(value: T, env: Record<string, string | undefined>): T {
if (typeof value === 'string') return value.replace(/\$\{(\w+)\}/g, (_, name) => env[name] ?? '') as unknown as T;
if (Array.isArray(value)) return value.map(v => interpolateEnv(v, env)) as unknown as T;
if (value && typeof value === 'object') {
return Object.fromEntries(Object.entries(value).map(([k, v]) => [k, interpolateEnv(v, env)])) as T;
}
return value;
}

function configArgv(c: RunConfig): string[] {
const out: string[] = [];
const opt = (flag: string, v: unknown) => { if (v !== undefined) out.push(flag, String(v)); };
for (const p of c.paths || []) out.push('--path', p);
opt('-c', c.concurrency);
opt('-d', typeof c.duration === 'number' ? `${c.duration}ms` : c.duration);
opt('-n', c.requests);
opt('--method', c.method);
for (const [k, v] of Object.entries(c.headers || {})) out.push('-H', `${k}: ${v}`);
opt('--warmup', c.warmup);
opt('--probe', c.probe);
opt('--port', c.port);
opt('--baseline', c.baseline);
opt('--save-baseline', c.saveBaseline);
opt('--html', c.html);
return out;
}

/**
* Read run options; `readConfig(file?)` returns the text of --config FILE, or
* of traceperf.config.json when there is one (undefined: none). Command-line
* options win over the file; --path on the command line replaces its paths.
*/
export function parseRunArgs(argv: string[], readConfig?: (file?: string) => string | undefined, env: Record<string, string | undefined> = {}): RunArgs | string {
const at = argv.indexOf('--config');
const dashdash = argv.indexOf('--');
let configFile: string | undefined;
if (at >= 0 && (dashdash < 0 || at < dashdash)) {
configFile = argv[at + 1];
if (!configFile) return '--config expects a file';
argv = [...argv.slice(0, at), ...argv.slice(at + 2)];
}
let config: RunConfig | undefined;
if (readConfig) {
let text: string | undefined;
try {
text = readConfig(configFile);
} catch (e) {
return `could not read ${configFile}: ${e instanceof Error ? e.message : String(e)}`;
}
if (configFile && text === undefined) return `could not read ${configFile}`;
if (text !== undefined) {
try {
config = interpolateEnv(JSON.parse(text) as RunConfig, env);
} catch (e) {
return `${configFile || 'traceperf.config.json'} is not valid JSON: ${e instanceof Error ? e.message : String(e)}`;
}
}
}
if (!config) return parseArgv(argv);
const base = parseArgv([...configArgv(config), '--', ...(typeof config.app === 'string' ? [config.app] : config.app || [])], true);
if (typeof base === 'string') return `in the config file: ${base}`;
base.login = config.login;
const cli = parseArgv(argv, true, { ...base, paths: [], command: [] });
if (typeof cli === 'string') return cli;
if (!cli.paths.length) cli.paths = base.paths;
if (!cli.command.length) cli.command = base.command;
if (!cli.command.length) return 'run expects an app, e.g. traceperf run server.js (or "app" in the config file)';
return cli;
}

function parseArgv(argv: string[], partial = false, start?: RunArgs): RunArgs | string {
const args: RunArgs = start ? { ...start } : {
command: [], paths: [], concurrency: 10, durationMs: 5000, host: '127.0.0.1',
method: 'GET', warmup: 3, probe: 10, json: false, profile: true, max: 10, startTimeoutMs: 15000,
};
Expand Down Expand Up @@ -158,10 +268,50 @@ export function parseRunArgs(argv: string[]): RunArgs | string {
args.command.push(a);
}
}
if (!args.command.length) return 'run expects an app, e.g. traceperf run server.js';
if (!args.command.length && !partial) return 'run expects an app, e.g. traceperf run server.js';
return args;
}

/** Read a dotted path ("user.token", "data.0.jwt") from a JSON value */
function dig(value: unknown, dotted: string): unknown {
return dotted.split('.').reduce<unknown>((v, key) => (v !== null && typeof v === 'object' ? (v as Record<string, unknown>)[key] : undefined), value);
}

/** Run the login request; returns the headers to send from now on, or an error message */
export function login(http: any, args: RunArgs, port: number, spec: RunLogin): Promise<Record<string, string> | string> {
const body = spec.body === undefined ? undefined : JSON.stringify(spec.body);
return new Promise(resolve => {
const req = http.request({
host: args.host, port, path: spec.path, method: (spec.method || 'POST').toUpperCase(),
headers: { ...(body ? { 'content-type': 'application/json', 'content-length': Buffer.byteLength(body) } : {}), ...(spec.headers || {}) },
}, (res: any) => {
let text = '';
res.setEncoding('utf8');
res.on('data', (chunk: string) => { text += chunk; });
res.on('end', () => {
const where = `login ${spec.method || 'POST'} ${spec.path}`;
if (res.statusCode >= 400) return resolve(`${where} answered ${res.statusCode}: ${text.slice(0, 200)}`);
if (!spec.token) {
const cookies: string[] = [].concat(res.headers['set-cookie'] || []);
if (!cookies.length) return resolve(`${where} set no cookie; give "token": the path of the token in its JSON response`);
return resolve({ cookie: cookies.map(c => c.split(';')[0]).join('; ') });
}
let token: unknown;
try {
token = dig(JSON.parse(text), spec.token);
} catch {
return resolve(`${where} did not answer JSON: ${text.slice(0, 200)}`);
}
if (typeof token !== 'string' && typeof token !== 'number') return resolve(`${where}: no "${spec.token}" in the response: ${text.slice(0, 200)}`);
resolve({ [(spec.header || 'authorization').toLowerCase()]: `${spec.prefix ?? 'Bearer '}${token}` });
});
});
req.on('error', (e: Error) => resolve(`login failed: ${e.message}`));
if (body) req.write(body);
req.end();
});
}

export interface LoadResult {
requests: number;
errors: number;
Expand Down Expand Up @@ -576,6 +726,17 @@ export async function runApp(args: RunArgs, deps: RunDeps): Promise<number> {
return 1;
}
deps.err(`traceperf: sending ${args.requests ? `${args.requests} requests` : `${args.durationMs / 1000} s of traffic`} to ${args.paths.join(', ')} on port ${port}, ${args.concurrency} at a time`);
if (args.login) {
const got = await login(deps.http, args, port, args.login);
if (typeof got === 'string') {
deps.err(`traceperf: ${got}`);
await stopAndWait();
return 1;
}
// Later headers from -H win over the login's
args = { ...args, headers: { ...got, ...(args.headers || {}) } };
deps.err(`traceperf: logged in (${Object.keys(got).join(', ')} set)`);
}
if (args.warmup > 0) {
await sendLoad(deps.http, { ...args, concurrency: 1, requests: args.warmup * args.paths.length }, port);
skipBytes = await sizeNow();
Expand Down
Loading