Compare commits
3 Commits
metrics-co
...
perf-regre
| Author | SHA1 | Date | |
|---|---|---|---|
| 239c8596a7 | |||
| 76a9559514 | |||
| 0a1e3666ef |
13
CLAUDE.md
13
CLAUDE.md
@@ -94,3 +94,16 @@ The default route `/` renders the paycheck-centric main view (`client/src/pages/
|
|||||||
**Financing:** `GET/POST /api/financing`, `PUT/DELETE /api/financing/:id`, `PATCH /api/financing-payments/:id/paid`. Plans track a total amount, payoff due date, and `start_date`. Payment per period is auto-calculated as `(remaining balance) / (remaining periods)`. Split plans (`assigned_paycheck = null`) divide each period's payment across both paychecks. Plans auto-close when fully paid. Financing payments are included in the paycheck remaining balance. `start_date` prevents a plan from appearing on paycheck months before it was created — both virtual previews and `generate` respect this guard.
|
**Financing:** `GET/POST /api/financing`, `PUT/DELETE /api/financing/:id`, `PATCH /api/financing-payments/:id/paid`. Plans track a total amount, payoff due date, and `start_date`. Payment per period is auto-calculated as `(remaining balance) / (remaining periods)`. Split plans (`assigned_paycheck = null`) divide each period's payment across both paychecks. Plans auto-close when fully paid. Financing payments are included in the paycheck remaining balance. `start_date` prevents a plan from appearing on paycheck months before it was created — both virtual previews and `generate` respect this guard.
|
||||||
|
|
||||||
**Migrations:** SQL files in `db/migrations/` are applied in filename order on server startup. Add new migrations as `00N_description.sql` — they run once and are tracked in the `migrations` table.
|
**Migrations:** SQL files in `db/migrations/` are applied in filename order on server startup. Add new migrations as `00N_description.sql` — they run once and are tracked in the `migrations` table.
|
||||||
|
|
||||||
|
## Performance Tooling
|
||||||
|
|
||||||
|
**Timing middleware** (`server/src/middleware/timing.js`): Registered early in `app.js`. Logs every request's method, path, status code, and duration. Emits a `[SLOW]` warning for responses exceeding 200 ms.
|
||||||
|
|
||||||
|
**Benchmark script** (`scripts/perf-benchmark.js`): Hits `GET /api/paychecks`, `GET /api/financing`, and `GET /api/summary/annual` five times each and reports min/mean/max latency. Exits non-zero if any mean exceeds the threshold (default 500 ms, override via `SLOW_THRESHOLD_MS` env var). Target server URL defaults to `http://localhost:3001` (override via `BENCHMARK_URL`).
|
||||||
|
|
||||||
|
```bash
|
||||||
|
cd server && npm run perf # run against localhost:3001
|
||||||
|
BENCHMARK_URL=http://localhost:3000 npm run perf
|
||||||
|
```
|
||||||
|
|
||||||
|
**Performance indexes** (`db/migrations/005_performance_indexes.sql`): Adds indexes on `paychecks(period_year, period_month)`, `paycheck_bills(paycheck_id)`, `actuals(paycheck_id)`, `one_time_expenses(paycheck_id)`, `financing_payments(plan_id)`, and `financing_plans(active)` — applied automatically on server startup.
|
||||||
|
|||||||
7
db/migrations/005_performance_indexes.sql
Normal file
7
db/migrations/005_performance_indexes.sql
Normal file
@@ -0,0 +1,7 @@
|
|||||||
|
-- Performance indexes for high-traffic query patterns
|
||||||
|
CREATE INDEX IF NOT EXISTS idx_paychecks_period ON paychecks(period_year, period_month);
|
||||||
|
CREATE INDEX IF NOT EXISTS idx_paycheck_bills_paycheck_id ON paycheck_bills(paycheck_id);
|
||||||
|
CREATE INDEX IF NOT EXISTS idx_actuals_paycheck_id ON actuals(paycheck_id);
|
||||||
|
CREATE INDEX IF NOT EXISTS idx_one_time_expenses_paycheck_id ON one_time_expenses(paycheck_id);
|
||||||
|
CREATE INDEX IF NOT EXISTS idx_financing_payments_plan_id ON financing_payments(plan_id);
|
||||||
|
CREATE INDEX IF NOT EXISTS idx_financing_plans_active ON financing_plans(active) WHERE active = true;
|
||||||
@@ -1,251 +0,0 @@
|
|||||||
#!/usr/bin/env node
|
|
||||||
/**
|
|
||||||
* metrics-coverage.js — Static analysis script for metrics/logging instrumentation coverage.
|
|
||||||
*
|
|
||||||
* Scans all Express route files in server/src/routes/*.js and app.js to measure
|
|
||||||
* how many route handlers contain logging calls (console.error/console.warn/console.log).
|
|
||||||
*
|
|
||||||
* Usage:
|
|
||||||
* node scripts/metrics-coverage.js # JSON output (default)
|
|
||||||
* node scripts/metrics-coverage.js --format=text # Human-readable table
|
|
||||||
*
|
|
||||||
* Sample output (captured 2026-03-20):
|
|
||||||
* {
|
|
||||||
* "files": [
|
|
||||||
* { "file": "actuals.js", "total": 5, "logged": 5, "unlogged": 0, "coverage": 100 },
|
|
||||||
* { "file": "bills.js", "total": 6, "logged": 6, "unlogged": 0, "coverage": 100 },
|
|
||||||
* { "file": "config.js", "total": 2, "logged": 2, "unlogged": 0, "coverage": 100 },
|
|
||||||
* { "file": "financing.js", "total": 6, "logged": 6, "unlogged": 0, "coverage": 100 },
|
|
||||||
* { "file": "health.js", "total": 1, "logged": 0, "unlogged": 1, "coverage": 0 },
|
|
||||||
* { "file": "one-time-expenses.js", "total": 3, "logged": 3, "unlogged": 0, "coverage": 100 },
|
|
||||||
* { "file": "paychecks.js", "total": 6, "logged": 6, "unlogged": 0, "coverage": 100 },
|
|
||||||
* { "file": "summary.js", "total": 2, "logged": 2, "unlogged": 0, "coverage": 100 }
|
|
||||||
* ],
|
|
||||||
* "app": {
|
|
||||||
* "has_request_timing_middleware": false,
|
|
||||||
* "has_error_handling_middleware": false,
|
|
||||||
* "middleware_count": 11
|
|
||||||
* },
|
|
||||||
* "aggregate": {
|
|
||||||
* "total_handlers": 31,
|
|
||||||
* "logged_handlers": 30,
|
|
||||||
* "unlogged_handlers": 1,
|
|
||||||
* "coverage_pct": 96.77
|
|
||||||
* }
|
|
||||||
* }
|
|
||||||
*/
|
|
||||||
|
|
||||||
'use strict';
|
|
||||||
|
|
||||||
const fs = require('fs');
|
|
||||||
const path = require('path');
|
|
||||||
|
|
||||||
const ROUTES_DIR = path.resolve(__dirname, '../server/src/routes');
|
|
||||||
const APP_FILE = path.resolve(__dirname, '../server/src/app.js');
|
|
||||||
|
|
||||||
// Regex patterns for route handler definitions.
|
|
||||||
// Matches: router.get/post/put/patch/delete( and app.get/post/put/patch/delete(
|
|
||||||
const ROUTE_DEF_RE = /\b(?:router|app)\.(get|post|put|patch|delete)\s*\(/g;
|
|
||||||
|
|
||||||
// Logging call patterns
|
|
||||||
const LOG_RE = /\bconsole\.(error|warn|log)\s*\(/;
|
|
||||||
|
|
||||||
/**
|
|
||||||
* Extract individual route handler bodies from source.
|
|
||||||
* Strategy: find each route definition, then walk forward counting
|
|
||||||
* braces to find the closing of the outermost async/function callback.
|
|
||||||
*/
|
|
||||||
function extractHandlerBodies(src) {
|
|
||||||
const handlers = [];
|
|
||||||
let match;
|
|
||||||
ROUTE_DEF_RE.lastIndex = 0;
|
|
||||||
|
|
||||||
while ((match = ROUTE_DEF_RE.exec(src)) !== null) {
|
|
||||||
const startIdx = match.index;
|
|
||||||
// Find the opening paren of the route call
|
|
||||||
const parenOpen = src.indexOf('(', startIdx);
|
|
||||||
if (parenOpen === -1) continue;
|
|
||||||
|
|
||||||
// Walk from the paren open, tracking paren depth to find the matching close.
|
|
||||||
// The handler callback body will be inside the outer parens.
|
|
||||||
let depth = 0;
|
|
||||||
let bodyStart = -1;
|
|
||||||
let bodyEnd = -1;
|
|
||||||
let inString = false;
|
|
||||||
let stringChar = '';
|
|
||||||
let i = parenOpen;
|
|
||||||
|
|
||||||
while (i < src.length) {
|
|
||||||
const ch = src[i];
|
|
||||||
|
|
||||||
// Basic string tracking (skip contents of string literals)
|
|
||||||
if (!inString && (ch === '"' || ch === "'" || ch === '`')) {
|
|
||||||
inString = true;
|
|
||||||
stringChar = ch;
|
|
||||||
i++;
|
|
||||||
continue;
|
|
||||||
}
|
|
||||||
if (inString) {
|
|
||||||
if (ch === '\\') { i += 2; continue; } // skip escape
|
|
||||||
if (ch === stringChar) inString = false;
|
|
||||||
i++;
|
|
||||||
continue;
|
|
||||||
}
|
|
||||||
|
|
||||||
if (ch === '(') {
|
|
||||||
depth++;
|
|
||||||
if (depth === 1) {
|
|
||||||
// This is the opening of the route call args
|
|
||||||
}
|
|
||||||
} else if (ch === ')') {
|
|
||||||
depth--;
|
|
||||||
if (depth === 0) {
|
|
||||||
bodyEnd = i;
|
|
||||||
break;
|
|
||||||
}
|
|
||||||
} else if (ch === '{' && depth >= 1 && bodyStart === -1) {
|
|
||||||
// First brace inside the outer parens — start of the handler body
|
|
||||||
bodyStart = i;
|
|
||||||
}
|
|
||||||
|
|
||||||
i++;
|
|
||||||
}
|
|
||||||
|
|
||||||
if (bodyStart !== -1 && bodyEnd !== -1) {
|
|
||||||
handlers.push(src.slice(bodyStart, bodyEnd));
|
|
||||||
}
|
|
||||||
}
|
|
||||||
|
|
||||||
return handlers;
|
|
||||||
}
|
|
||||||
|
|
||||||
/**
|
|
||||||
* Analyse a single route file.
|
|
||||||
*/
|
|
||||||
function analyseRouteFile(filePath) {
|
|
||||||
const src = fs.readFileSync(filePath, 'utf8');
|
|
||||||
const handlers = extractHandlerBodies(src);
|
|
||||||
|
|
||||||
const logged = handlers.filter(body => LOG_RE.test(body));
|
|
||||||
|
|
||||||
return {
|
|
||||||
file: path.basename(filePath),
|
|
||||||
total: handlers.length,
|
|
||||||
logged: logged.length,
|
|
||||||
unlogged: handlers.length - logged.length,
|
|
||||||
coverage: handlers.length === 0
|
|
||||||
? null
|
|
||||||
: Math.round((logged.length / handlers.length) * 10000) / 100,
|
|
||||||
};
|
|
||||||
}
|
|
||||||
|
|
||||||
/**
|
|
||||||
* Analyse app.js for middleware-level instrumentation.
|
|
||||||
*/
|
|
||||||
function analyseApp(filePath) {
|
|
||||||
const src = fs.readFileSync(filePath, 'utf8');
|
|
||||||
|
|
||||||
// Request timing: morgan, custom middleware checking req.method, Date.now() at top-level use()
|
|
||||||
const hasRequestTiming =
|
|
||||||
/\brequire\s*\(\s*['"]morgan['"]\s*\)/.test(src) ||
|
|
||||||
/app\.use\s*\(.*Date\.now\(\)/.test(src) ||
|
|
||||||
/app\.use\s*\(.*req,\s*res,\s*next/.test(src) && /Date\.now|performance\.now/.test(src);
|
|
||||||
|
|
||||||
// Error handling middleware: app.use((err, req, res, next) => ...)
|
|
||||||
const hasErrorHandling = /app\.use\s*\(\s*(?:\S+\s*,\s*)?\(\s*err\s*,/.test(src);
|
|
||||||
|
|
||||||
// Count top-level app.use() calls (middleware registrations)
|
|
||||||
const middlewareMatches = src.match(/app\.use\s*\(/g) || [];
|
|
||||||
|
|
||||||
return {
|
|
||||||
has_request_timing_middleware: hasRequestTiming,
|
|
||||||
has_error_handling_middleware: hasErrorHandling,
|
|
||||||
middleware_count: middlewareMatches.length,
|
|
||||||
};
|
|
||||||
}
|
|
||||||
|
|
||||||
function run() {
|
|
||||||
const format = process.argv.includes('--format=text') ? 'text' : 'json';
|
|
||||||
|
|
||||||
// Analyse all route files
|
|
||||||
const routeFiles = fs.readdirSync(ROUTES_DIR)
|
|
||||||
.filter(f => f.endsWith('.js'))
|
|
||||||
.sort();
|
|
||||||
|
|
||||||
const fileResults = routeFiles.map(f =>
|
|
||||||
analyseRouteFile(path.join(ROUTES_DIR, f))
|
|
||||||
);
|
|
||||||
|
|
||||||
// Aggregate
|
|
||||||
const totalHandlers = fileResults.reduce((s, r) => s + r.total, 0);
|
|
||||||
const loggedHandlers = fileResults.reduce((s, r) => s + r.logged, 0);
|
|
||||||
|
|
||||||
const aggregate = {
|
|
||||||
total_handlers: totalHandlers,
|
|
||||||
logged_handlers: loggedHandlers,
|
|
||||||
unlogged_handlers: totalHandlers - loggedHandlers,
|
|
||||||
coverage_pct: totalHandlers === 0
|
|
||||||
? null
|
|
||||||
: Math.round((loggedHandlers / totalHandlers) * 10000) / 100,
|
|
||||||
};
|
|
||||||
|
|
||||||
const appInfo = analyseApp(APP_FILE);
|
|
||||||
|
|
||||||
const result = {
|
|
||||||
files: fileResults,
|
|
||||||
app: appInfo,
|
|
||||||
aggregate,
|
|
||||||
};
|
|
||||||
|
|
||||||
if (format === 'json') {
|
|
||||||
console.log(JSON.stringify(result, null, 2));
|
|
||||||
return;
|
|
||||||
}
|
|
||||||
|
|
||||||
// Text table
|
|
||||||
const COL_FILE = 28;
|
|
||||||
const COL_TOTAL = 7;
|
|
||||||
const COL_LOGGED = 8;
|
|
||||||
const COL_COVER = 10;
|
|
||||||
|
|
||||||
const pad = (s, n) => String(s).padEnd(n);
|
|
||||||
const lpad = (s, n) => String(s).padStart(n);
|
|
||||||
|
|
||||||
const hr = '-'.repeat(COL_FILE + COL_TOTAL + COL_LOGGED + COL_COVER + 6);
|
|
||||||
|
|
||||||
console.log('\nMetrics Instrumentation Coverage\n');
|
|
||||||
console.log(
|
|
||||||
pad('Route File', COL_FILE) +
|
|
||||||
lpad('Handlers', COL_TOTAL) +
|
|
||||||
lpad('Logged', COL_LOGGED) +
|
|
||||||
lpad('Coverage', COL_COVER)
|
|
||||||
);
|
|
||||||
console.log(hr);
|
|
||||||
|
|
||||||
for (const r of fileResults) {
|
|
||||||
const cov = r.coverage === null ? 'N/A' : `${r.coverage}%`;
|
|
||||||
console.log(
|
|
||||||
pad(r.file, COL_FILE) +
|
|
||||||
lpad(r.total, COL_TOTAL) +
|
|
||||||
lpad(r.logged, COL_LOGGED) +
|
|
||||||
lpad(cov, COL_COVER)
|
|
||||||
);
|
|
||||||
}
|
|
||||||
|
|
||||||
console.log(hr);
|
|
||||||
const aggCov = aggregate.coverage_pct === null ? 'N/A' : `${aggregate.coverage_pct}%`;
|
|
||||||
console.log(
|
|
||||||
pad('TOTAL', COL_FILE) +
|
|
||||||
lpad(aggregate.total_handlers, COL_TOTAL) +
|
|
||||||
lpad(aggregate.logged_handlers, COL_LOGGED) +
|
|
||||||
lpad(aggCov, COL_COVER)
|
|
||||||
);
|
|
||||||
|
|
||||||
console.log('\napp.js middleware:');
|
|
||||||
console.log(` Request timing middleware : ${appInfo.has_request_timing_middleware}`);
|
|
||||||
console.log(` Error handling middleware : ${appInfo.has_error_handling_middleware}`);
|
|
||||||
console.log(` app.use() call count : ${appInfo.middleware_count}`);
|
|
||||||
console.log('');
|
|
||||||
}
|
|
||||||
|
|
||||||
run();
|
|
||||||
62
scripts/perf-benchmark.js
Normal file
62
scripts/perf-benchmark.js
Normal file
@@ -0,0 +1,62 @@
|
|||||||
|
#!/usr/bin/env node
|
||||||
|
'use strict';
|
||||||
|
|
||||||
|
const BASE_URL = process.env.BENCHMARK_URL || 'http://localhost:3001';
|
||||||
|
const ITERATIONS = 5;
|
||||||
|
const MEAN_THRESHOLD_MS = parseInt(process.env.SLOW_THRESHOLD_MS || '500', 10);
|
||||||
|
|
||||||
|
const ENDPOINTS = [
|
||||||
|
{ label: 'GET /api/paychecks', path: `/api/paychecks?year=${new Date().getFullYear()}&month=${new Date().getMonth() + 1}` },
|
||||||
|
{ label: 'GET /api/financing', path: '/api/financing' },
|
||||||
|
{ label: 'GET /api/summary/annual', path: `/api/summary/annual?year=${new Date().getFullYear()}` },
|
||||||
|
];
|
||||||
|
|
||||||
|
async function measureEndpoint(endpoint) {
|
||||||
|
const times = [];
|
||||||
|
for (let i = 0; i < ITERATIONS; i++) {
|
||||||
|
const start = Date.now();
|
||||||
|
const res = await fetch(`${BASE_URL}${endpoint.path}`);
|
||||||
|
const duration = Date.now() - start;
|
||||||
|
if (!res.ok) {
|
||||||
|
console.warn(` [warn] ${endpoint.label} returned HTTP ${res.status}`);
|
||||||
|
}
|
||||||
|
times.push(duration);
|
||||||
|
}
|
||||||
|
const min = Math.min(...times);
|
||||||
|
const max = Math.max(...times);
|
||||||
|
const mean = Math.round(times.reduce((a, b) => a + b, 0) / times.length);
|
||||||
|
return { min, mean, max };
|
||||||
|
}
|
||||||
|
|
||||||
|
(async () => {
|
||||||
|
console.log(`Benchmarking ${BASE_URL} (${ITERATIONS} iterations each, threshold ${MEAN_THRESHOLD_MS}ms)\n`);
|
||||||
|
|
||||||
|
let failed = false;
|
||||||
|
|
||||||
|
for (const endpoint of ENDPOINTS) {
|
||||||
|
let stats;
|
||||||
|
try {
|
||||||
|
stats = await measureEndpoint(endpoint);
|
||||||
|
} catch (err) {
|
||||||
|
console.error(` [error] ${endpoint.label}: ${err.message}`);
|
||||||
|
failed = true;
|
||||||
|
continue;
|
||||||
|
}
|
||||||
|
|
||||||
|
const flag = stats.mean >= MEAN_THRESHOLD_MS ? ' *** SLOW ***' : '';
|
||||||
|
console.log(`${endpoint.label}`);
|
||||||
|
console.log(` min=${stats.min}ms mean=${stats.mean}ms max=${stats.max}ms${flag}`);
|
||||||
|
|
||||||
|
if (stats.mean >= MEAN_THRESHOLD_MS) {
|
||||||
|
failed = true;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
console.log('');
|
||||||
|
if (failed) {
|
||||||
|
console.error('FAIL: one or more endpoints exceeded the threshold or errored.');
|
||||||
|
process.exit(1);
|
||||||
|
} else {
|
||||||
|
console.log('PASS: all endpoints within threshold.');
|
||||||
|
}
|
||||||
|
})();
|
||||||
@@ -6,7 +6,8 @@
|
|||||||
"start": "node src/index.js",
|
"start": "node src/index.js",
|
||||||
"dev": "nodemon src/index.js",
|
"dev": "nodemon src/index.js",
|
||||||
"test": "vitest run",
|
"test": "vitest run",
|
||||||
"test:watch": "vitest"
|
"test:watch": "vitest",
|
||||||
|
"perf": "node ../scripts/perf-benchmark.js"
|
||||||
},
|
},
|
||||||
"dependencies": {
|
"dependencies": {
|
||||||
"cors": "^2.8.5",
|
"cors": "^2.8.5",
|
||||||
|
|||||||
98
server/src/__tests__/timing.middleware.test.js
Normal file
98
server/src/__tests__/timing.middleware.test.js
Normal file
@@ -0,0 +1,98 @@
|
|||||||
|
import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest';
|
||||||
|
|
||||||
|
const timingMiddleware = require('../middleware/timing');
|
||||||
|
|
||||||
|
function makeResMock() {
|
||||||
|
const listeners = {};
|
||||||
|
return {
|
||||||
|
statusCode: 200,
|
||||||
|
on(event, cb) {
|
||||||
|
listeners[event] = cb;
|
||||||
|
},
|
||||||
|
emit(event) {
|
||||||
|
if (listeners[event]) listeners[event]();
|
||||||
|
},
|
||||||
|
};
|
||||||
|
}
|
||||||
|
|
||||||
|
describe('timingMiddleware', () => {
|
||||||
|
let consoleSpy;
|
||||||
|
let warnSpy;
|
||||||
|
|
||||||
|
beforeEach(() => {
|
||||||
|
consoleSpy = vi.spyOn(console, 'log').mockImplementation(() => {});
|
||||||
|
warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {});
|
||||||
|
});
|
||||||
|
|
||||||
|
afterEach(() => {
|
||||||
|
consoleSpy.mockRestore();
|
||||||
|
warnSpy.mockRestore();
|
||||||
|
vi.useRealTimers();
|
||||||
|
});
|
||||||
|
|
||||||
|
it('calls next()', () => {
|
||||||
|
const req = { method: 'GET', path: '/api/health' };
|
||||||
|
const res = makeResMock();
|
||||||
|
const next = vi.fn();
|
||||||
|
|
||||||
|
timingMiddleware(req, res, next);
|
||||||
|
expect(next).toHaveBeenCalledOnce();
|
||||||
|
});
|
||||||
|
|
||||||
|
it('logs timing on response finish', () => {
|
||||||
|
const req = { method: 'GET', path: '/api/health' };
|
||||||
|
const res = makeResMock();
|
||||||
|
|
||||||
|
timingMiddleware(req, res, vi.fn());
|
||||||
|
res.emit('finish');
|
||||||
|
|
||||||
|
expect(consoleSpy).toHaveBeenCalledOnce();
|
||||||
|
const msg = consoleSpy.mock.calls[0][0];
|
||||||
|
expect(msg).toMatch(/\[timing\] GET \/api\/health 200 \d+ms/);
|
||||||
|
});
|
||||||
|
|
||||||
|
it('emits SLOW warning when duration exceeds 200ms threshold', () => {
|
||||||
|
vi.useFakeTimers();
|
||||||
|
|
||||||
|
const req = { method: 'POST', path: '/api/paychecks' };
|
||||||
|
const res = makeResMock();
|
||||||
|
|
||||||
|
timingMiddleware(req, res, vi.fn());
|
||||||
|
|
||||||
|
// Advance time past the threshold
|
||||||
|
vi.advanceTimersByTime(250);
|
||||||
|
res.emit('finish');
|
||||||
|
|
||||||
|
expect(warnSpy).toHaveBeenCalledOnce();
|
||||||
|
const msg = warnSpy.mock.calls[0][0];
|
||||||
|
expect(msg).toMatch(/\[SLOW\] POST \/api\/paychecks/);
|
||||||
|
expect(consoleSpy).not.toHaveBeenCalled();
|
||||||
|
});
|
||||||
|
|
||||||
|
it('does not emit SLOW warning for fast requests', () => {
|
||||||
|
vi.useFakeTimers();
|
||||||
|
|
||||||
|
const req = { method: 'GET', path: '/api/financing' };
|
||||||
|
const res = makeResMock();
|
||||||
|
|
||||||
|
timingMiddleware(req, res, vi.fn());
|
||||||
|
|
||||||
|
vi.advanceTimersByTime(50);
|
||||||
|
res.emit('finish');
|
||||||
|
|
||||||
|
expect(consoleSpy).toHaveBeenCalledOnce();
|
||||||
|
expect(warnSpy).not.toHaveBeenCalled();
|
||||||
|
});
|
||||||
|
|
||||||
|
it('includes status code in the log message', () => {
|
||||||
|
const req = { method: 'GET', path: '/api/bills' };
|
||||||
|
const res = makeResMock();
|
||||||
|
res.statusCode = 404;
|
||||||
|
|
||||||
|
timingMiddleware(req, res, vi.fn());
|
||||||
|
res.emit('finish');
|
||||||
|
|
||||||
|
const msg = consoleSpy.mock.calls[0][0];
|
||||||
|
expect(msg).toContain('404');
|
||||||
|
});
|
||||||
|
});
|
||||||
@@ -9,13 +9,14 @@ const actualsRouter = require('./routes/actuals');
|
|||||||
const oneTimeExpensesRouter = require('./routes/one-time-expenses');
|
const oneTimeExpensesRouter = require('./routes/one-time-expenses');
|
||||||
const summaryRouter = require('./routes/summary');
|
const summaryRouter = require('./routes/summary');
|
||||||
const { router: financingRouter } = require('./routes/financing');
|
const { router: financingRouter } = require('./routes/financing');
|
||||||
|
const timingMiddleware = require('./middleware/timing');
|
||||||
|
|
||||||
const app = express();
|
const app = express();
|
||||||
|
|
||||||
app.use(cors());
|
app.use(cors());
|
||||||
app.use(express.json());
|
app.use(express.json());
|
||||||
|
|
||||||
// API routes
|
// API routes
|
||||||
|
app.use('/api', timingMiddleware);
|
||||||
app.use('/api', healthRouter);
|
app.use('/api', healthRouter);
|
||||||
app.use('/api', configRouter);
|
app.use('/api', configRouter);
|
||||||
app.use('/api', billsRouter);
|
app.use('/api', billsRouter);
|
||||||
|
|||||||
21
server/src/middleware/timing.js
Normal file
21
server/src/middleware/timing.js
Normal file
@@ -0,0 +1,21 @@
|
|||||||
|
'use strict';
|
||||||
|
|
||||||
|
const SLOW_THRESHOLD_MS = 200;
|
||||||
|
|
||||||
|
function timingMiddleware(req, res, next) {
|
||||||
|
const start = Date.now();
|
||||||
|
|
||||||
|
res.on('finish', () => {
|
||||||
|
const duration = Date.now() - start;
|
||||||
|
const msg = `${req.method} ${req.path} ${res.statusCode} ${duration}ms`;
|
||||||
|
if (duration >= SLOW_THRESHOLD_MS) {
|
||||||
|
console.warn(`[SLOW] ${msg}`);
|
||||||
|
} else {
|
||||||
|
console.log(`[timing] ${msg}`);
|
||||||
|
}
|
||||||
|
});
|
||||||
|
|
||||||
|
next();
|
||||||
|
}
|
||||||
|
|
||||||
|
module.exports = timingMiddleware;
|
||||||
Reference in New Issue
Block a user