diff --git a/CLAUDE.md b/CLAUDE.md index 1ddc338..de7d963 100644 --- a/CLAUDE.md +++ b/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. **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. diff --git a/db/migrations/005_performance_indexes.sql b/db/migrations/005_performance_indexes.sql new file mode 100644 index 0000000..b4376c7 --- /dev/null +++ b/db/migrations/005_performance_indexes.sql @@ -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; diff --git a/scripts/perf-benchmark.js b/scripts/perf-benchmark.js new file mode 100644 index 0000000..323f24a --- /dev/null +++ b/scripts/perf-benchmark.js @@ -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.'); + } +})(); diff --git a/server/package.json b/server/package.json index e349ea3..2bee861 100644 --- a/server/package.json +++ b/server/package.json @@ -6,7 +6,8 @@ "start": "node src/index.js", "dev": "nodemon src/index.js", "test": "vitest run", - "test:watch": "vitest" + "test:watch": "vitest", + "perf": "node ../scripts/perf-benchmark.js" }, "dependencies": { "cors": "^2.8.5", diff --git a/server/src/__tests__/timing.middleware.test.js b/server/src/__tests__/timing.middleware.test.js new file mode 100644 index 0000000..f834219 --- /dev/null +++ b/server/src/__tests__/timing.middleware.test.js @@ -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'); + }); +}); diff --git a/server/src/app.js b/server/src/app.js index 400c551..072d487 100644 --- a/server/src/app.js +++ b/server/src/app.js @@ -9,13 +9,14 @@ const actualsRouter = require('./routes/actuals'); const oneTimeExpensesRouter = require('./routes/one-time-expenses'); const summaryRouter = require('./routes/summary'); const { router: financingRouter } = require('./routes/financing'); +const timingMiddleware = require('./middleware/timing'); const app = express(); app.use(cors()); app.use(express.json()); - // API routes +app.use('/api', timingMiddleware); app.use('/api', healthRouter); app.use('/api', configRouter); app.use('/api', billsRouter); diff --git a/server/src/middleware/timing.js b/server/src/middleware/timing.js new file mode 100644 index 0000000..81d8c09 --- /dev/null +++ b/server/src/middleware/timing.js @@ -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;