diff --git a/.env.example b/.env.example index 8c61b43..4fc89bd 100644 --- a/.env.example +++ b/.env.example @@ -18,6 +18,8 @@ DB_PORT=5432 DB_USERNAME=postgres DB_PASSWORD=postgres DB_NAME=stellartip +DB_POOL_SIZE=10 +DB_POOL_SATURATION_CHECK_INTERVAL_MS=30000 # ---- JWT Authentication ---- JWT_SECRET=change-me-to-a-random-secret diff --git a/.github/workflows/load-test.yml b/.github/workflows/load-test.yml index 9e89f0e..cdff852 100644 --- a/.github/workflows/load-test.yml +++ b/.github/workflows/load-test.yml @@ -42,6 +42,8 @@ jobs: JWT_SECRET: load-test-secret NODE_ENV: test PORT: 3000 + DB_POOL_SIZE: 10 + DB_POOL_SATURATION_CHECK_INTERVAL_MS: 5000 steps: - uses: actions/checkout@v4 @@ -104,6 +106,14 @@ jobs: env: BASE_URL: http://localhost:3000 + - name: Run database pool readiness test + uses: grafana/k6-action@v0.3.1 + with: + filename: test/load/db-pool-readiness.js + flags: --out json=results/db-pool-readiness.json + env: + BASE_URL: http://localhost:3000 + - name: Upload load test results if: always() uses: actions/upload-artifact@v4 diff --git a/docs/PERFORMANCE.md b/docs/PERFORMANCE.md index 4dcea8b..869ef96 100644 --- a/docs/PERFORMANCE.md +++ b/docs/PERFORMANCE.md @@ -4,19 +4,20 @@ Load and performance testing for the StellarTip Backend API using [k6](https://k ## Thresholds -| Metric | Threshold | -|--------|-----------| -| p95 response time | < 200ms | -| Error rate | < 1% | +| Metric | Threshold | +| ----------------- | --------- | +| p95 response time | < 200ms | +| Error rate | < 1% | ## Load Envelope -| Script | Endpoint | Target RPS | Duration | Pattern | -|--------|----------|-----------|----------|---------| -| `health-smoke.js` | `GET /health` | 1000 RPS | 30s | Constant | -| `profile-reads.js` | `GET /profiles/:username` | 200 RPS | 5 min | Ramp up → sustain → ramp down | -| `auth-rate-limit.js` | `POST /auth/login` | ~15 req/VU | 2 min | Per-VU (rate-limit verification) | -| `tip-creation.js` | `POST /tips` | 50 RPS | 5 min | Ramp up → sustain → ramp down | +| Script | Endpoint | Target RPS | Duration | Pattern | +| ---------------------- | ------------------------- | ---------- | -------- | -------------------------------- | +| `health-smoke.js` | `GET /health` | 1000 RPS | 30s | Constant | +| `profile-reads.js` | `GET /profiles/:username` | 200 RPS | 5 min | Ramp up → sustain → ramp down | +| `auth-rate-limit.js` | `POST /auth/login` | ~15 req/VU | 2 min | Per-VU (rate-limit verification) | +| `tip-creation.js` | `POST /tips` | 50 RPS | 5 min | Ramp up → sustain → ramp down | +| `db-pool-readiness.js` | `GET /health/ready` | 400 RPS | 2 min | Constant DB readiness load | ## Scripts @@ -41,6 +42,32 @@ Each VU sends 15 requests (exceeding the 10 req/min limit), and the test asserts Burst test for tip creation at **50 RPS** for 5 minutes. Ramp-up: 0 → 50 RPS over 30s. Ramp-down: 50 → 0 RPS over 30s. +### `db-pool-readiness.js` + +Runs the database-backed readiness probe at **400 RPS** for 2 minutes, which is +2x the profile-read baseline. It verifies that the tuned PostgreSQL pool keeps +the database check connected with p95 latency below 250ms and fewer than 10 +failed readiness checks. + +## PostgreSQL Pool Tuning + +The API configures the TypeORM PostgreSQL pool explicitly instead of relying on +driver defaults: + +| Setting | Default | Notes | +| -------------------------------------- | ------- | --------------------------------------------------------- | +| `DB_POOL_SIZE` | `10` | Clamped to a maximum of `20` connections per API instance | +| `idleTimeoutMillis` | `30000` | Releases idle clients after 30 seconds | +| `connectionTimeoutMillis` | `5000` | Fails fast when a client cannot be acquired | +| `maxQueryExecutionTime` | `1000` | Emits slow-query warnings above 1 second | +| `DB_POOL_SATURATION_CHECK_INTERVAL_MS` | `30000` | Warn-level pool saturation check interval | + +Pool saturation is logged at warn level when requests are waiting for a +connection, or when all configured clients are busy with no idle capacity. Size +`DB_POOL_SIZE` per instance against the database's global connection budget. For +example, four API instances at the default size consume up to 40 database +connections before migrations, admin sessions, or background jobs are counted. + ## Running Locally Requires [k6](https://k6.io/docs/get-started/installation/) or Docker. @@ -57,6 +84,9 @@ k6 run --env BASE_URL=http://localhost:3000 test/load/profile-reads.js # Save JSON output for trend tracking k6 run --out json=results.json test/load/tip-creation.js + +# Verify database pool behavior under 2x readiness load +k6 run --env BASE_URL=http://localhost:3000 test/load/db-pool-readiness.js ``` ## CI diff --git a/src/config/data-source.ts b/src/config/data-source.ts index 3566a1a..0393e32 100644 --- a/src/config/data-source.ts +++ b/src/config/data-source.ts @@ -1,5 +1,9 @@ import { DataSource } from 'typeorm'; import * as dotenv from 'dotenv'; +import { + DB_SLOW_QUERY_WARNING_MS, + createPostgresPoolOptions, +} from './database-pool.config'; dotenv.config(); @@ -15,6 +19,8 @@ export default new DataSource({ migrationsTableName: 'typeorm_migrations', synchronize: false, logging: process.env.NODE_ENV !== 'production', + maxQueryExecutionTime: DB_SLOW_QUERY_WARNING_MS, + extra: createPostgresPoolOptions(), // Wrap each migration in its own transaction by default so partial // failures roll back cleanly, while still letting individual migrations // opt out via `public readonly transaction = false` on the class. diff --git a/src/config/database-pool.config.spec.ts b/src/config/database-pool.config.spec.ts new file mode 100644 index 0000000..c163d9c --- /dev/null +++ b/src/config/database-pool.config.spec.ts @@ -0,0 +1,53 @@ +import { + DB_POOL_CONNECTION_TIMEOUT_MS, + DB_POOL_IDLE_TIMEOUT_MS, + DEFAULT_DB_POOL_SATURATION_CHECK_INTERVAL_MS, + DEFAULT_DB_POOL_SIZE, + MAX_DB_POOL_SIZE, + createPostgresPoolOptions, + getDatabasePoolMonitorIntervalMs, + getDatabasePoolSize, +} from './database-pool.config'; + +describe('database pool configuration', () => { + it('uses the default pool size when DB_POOL_SIZE is not set', () => { + expect(getDatabasePoolSize({})).toBe(DEFAULT_DB_POOL_SIZE); + }); + + it('uses a positive DB_POOL_SIZE value', () => { + expect(getDatabasePoolSize({ DB_POOL_SIZE: '15' })).toBe(15); + }); + + it('caps DB_POOL_SIZE at the per-instance maximum', () => { + expect(getDatabasePoolSize({ DB_POOL_SIZE: '99' })).toBe(MAX_DB_POOL_SIZE); + }); + + it('falls back for invalid DB_POOL_SIZE values', () => { + expect(getDatabasePoolSize({ DB_POOL_SIZE: '0' })).toBe( + DEFAULT_DB_POOL_SIZE, + ); + expect(getDatabasePoolSize({ DB_POOL_SIZE: 'not-a-number' })).toBe( + DEFAULT_DB_POOL_SIZE, + ); + }); + + it('builds explicit postgres pool options for TypeORM', () => { + expect(createPostgresPoolOptions({ DB_POOL_SIZE: '12' })).toEqual({ + max: 12, + poolSize: 12, + idleTimeoutMillis: DB_POOL_IDLE_TIMEOUT_MS, + connectionTimeoutMillis: DB_POOL_CONNECTION_TIMEOUT_MS, + }); + }); + + it('uses a configurable saturation monitor interval', () => { + expect(getDatabasePoolMonitorIntervalMs({})).toBe( + DEFAULT_DB_POOL_SATURATION_CHECK_INTERVAL_MS, + ); + expect( + getDatabasePoolMonitorIntervalMs({ + DB_POOL_SATURATION_CHECK_INTERVAL_MS: '5000', + }), + ).toBe(5000); + }); +}); diff --git a/src/config/database-pool.config.ts b/src/config/database-pool.config.ts new file mode 100644 index 0000000..f2dfc6e --- /dev/null +++ b/src/config/database-pool.config.ts @@ -0,0 +1,50 @@ +export const DEFAULT_DB_POOL_SIZE = 10; +export const MAX_DB_POOL_SIZE = 20; +export const DB_POOL_IDLE_TIMEOUT_MS = 30_000; +export const DB_POOL_CONNECTION_TIMEOUT_MS = 5_000; +export const DB_SLOW_QUERY_WARNING_MS = 1_000; +export const DEFAULT_DB_POOL_SATURATION_CHECK_INTERVAL_MS = 30_000; + +type EnvSource = Record; + +function parsePositiveInteger( + value: string | undefined, + fallback: number, +): number { + if (!value) return fallback; + + const parsed = Number.parseInt(value, 10); + return Number.isFinite(parsed) && parsed > 0 ? parsed : fallback; +} + +export function getDatabasePoolSize(env: EnvSource = process.env): number { + return Math.min( + parsePositiveInteger(env.DB_POOL_SIZE, DEFAULT_DB_POOL_SIZE), + MAX_DB_POOL_SIZE, + ); +} + +export function getDatabasePoolMonitorIntervalMs( + env: EnvSource = process.env, +): number { + return parsePositiveInteger( + env.DB_POOL_SATURATION_CHECK_INTERVAL_MS, + DEFAULT_DB_POOL_SATURATION_CHECK_INTERVAL_MS, + ); +} + +export function createPostgresPoolOptions(env: EnvSource = process.env): { + max: number; + poolSize: number; + idleTimeoutMillis: number; + connectionTimeoutMillis: number; +} { + const poolSize = getDatabasePoolSize(env); + + return { + max: poolSize, + poolSize, + idleTimeoutMillis: DB_POOL_IDLE_TIMEOUT_MS, + connectionTimeoutMillis: DB_POOL_CONNECTION_TIMEOUT_MS, + }; +} diff --git a/src/config/postgres-pool-monitor.spec.ts b/src/config/postgres-pool-monitor.spec.ts new file mode 100644 index 0000000..52b4ad7 --- /dev/null +++ b/src/config/postgres-pool-monitor.spec.ts @@ -0,0 +1,135 @@ +import type { LoggerService } from '@nestjs/common'; +import type { DataSource } from 'typeorm'; +import { + getPostgresPoolStats, + isPostgresPoolSaturated, + logPostgresPoolSaturation, + startPostgresPoolSaturationMonitor, +} from './postgres-pool-monitor'; + +function dataSourceWithPool(pool: unknown): DataSource { + return { + driver: { + master: pool, + }, + } as unknown as DataSource; +} + +describe('postgres pool monitor', () => { + it('reads pg pool stats from the TypeORM postgres driver', () => { + expect( + getPostgresPoolStats( + dataSourceWithPool({ + options: { max: 10 }, + totalCount: 7, + idleCount: 3, + waitingCount: 0, + }), + ), + ).toEqual({ + max: 10, + totalCount: 7, + idleCount: 3, + waitingCount: 0, + }); + }); + + it('returns null when the postgres driver has no pool', () => { + expect(getPostgresPoolStats({ driver: {} } as unknown as DataSource)).toBe( + null, + ); + }); + + it('treats queued waiters as saturation', () => { + expect( + isPostgresPoolSaturated({ + max: 10, + totalCount: 8, + idleCount: 1, + waitingCount: 2, + }), + ).toBe(true); + }); + + it('treats a full busy pool as saturation', () => { + expect( + isPostgresPoolSaturated({ + max: 10, + totalCount: 10, + idleCount: 0, + waitingCount: 0, + }), + ).toBe(true); + }); + + it('does not warn when there is idle capacity', () => { + const warn = jest.fn(); + const logger = { warn } as unknown as LoggerService; + + const warned = logPostgresPoolSaturation( + dataSourceWithPool({ + options: { max: 10 }, + totalCount: 5, + idleCount: 2, + waitingCount: 0, + }), + logger, + ); + + expect(warned).toBe(false); + expect(warn).not.toHaveBeenCalled(); + }); + + it('logs a warn-level event with pool stats when saturated', () => { + const warn = jest.fn(); + const logger = { warn } as unknown as LoggerService; + + const warned = logPostgresPoolSaturation( + dataSourceWithPool({ + options: { max: 10 }, + totalCount: 10, + idleCount: 0, + waitingCount: 1, + }), + logger, + ); + + expect(warned).toBe(true); + expect(warn).toHaveBeenCalledWith( + 'PostgreSQL connection pool saturation detected', + 'DatabasePool', + { + max: 10, + totalCount: 10, + idleCount: 0, + waitingCount: 1, + }, + ); + }); + + it('starts a recurring saturation monitor', () => { + jest.useFakeTimers(); + + const warn = jest.fn(); + const logger = { warn } as unknown as LoggerService; + const timer = startPostgresPoolSaturationMonitor( + dataSourceWithPool({ + options: { max: 10 }, + totalCount: 10, + idleCount: 0, + waitingCount: 1, + }), + logger, + 1000, + ); + + expect(warn).toHaveBeenCalledTimes(1); + + jest.advanceTimersByTime(1000); + + expect(warn).toHaveBeenCalledTimes(2); + + clearInterval(timer); + jest.useRealTimers(); + }); +}); diff --git a/src/config/postgres-pool-monitor.ts b/src/config/postgres-pool-monitor.ts new file mode 100644 index 0000000..9224ade --- /dev/null +++ b/src/config/postgres-pool-monitor.ts @@ -0,0 +1,99 @@ +import type { LoggerService } from '@nestjs/common'; +import type { DataSource } from 'typeorm'; +import { getDatabasePoolMonitorIntervalMs } from './database-pool.config'; + +export interface PostgresPoolStats { + max: number; + totalCount: number; + idleCount: number; + waitingCount: number; +} + +interface PoolOptionsLike { + max?: unknown; + poolSize?: unknown; +} + +interface PgPoolLike { + options?: PoolOptionsLike; + totalCount?: unknown; + idleCount?: unknown; + waitingCount?: unknown; +} + +interface DataSourceDriverLike { + master?: unknown; +} + +function toNumber(value: unknown, fallback = 0): number { + return typeof value === 'number' && Number.isFinite(value) ? value : fallback; +} + +export function getPostgresPoolStats( + dataSource: DataSource, +): PostgresPoolStats | null { + const driver = (dataSource as unknown as { driver?: DataSourceDriverLike }) + .driver; + const pool = driver?.master as PgPoolLike | undefined; + + if (!pool) return null; + + const max = toNumber(pool.options?.max, toNumber(pool.options?.poolSize)); + const totalCount = toNumber(pool.totalCount); + const idleCount = toNumber(pool.idleCount); + const waitingCount = toNumber(pool.waitingCount); + + return { + max, + totalCount, + idleCount, + waitingCount, + }; +} + +export function isPostgresPoolSaturated(stats: PostgresPoolStats): boolean { + return ( + stats.waitingCount > 0 || + (stats.max > 0 && stats.totalCount >= stats.max && stats.idleCount === 0) + ); +} + +export function logPostgresPoolSaturation( + dataSource: DataSource, + logger: LoggerService, +): boolean { + const stats = getPostgresPoolStats(dataSource); + + if (!stats || !isPostgresPoolSaturated(stats)) { + return false; + } + + logger.warn( + 'PostgreSQL connection pool saturation detected', + 'DatabasePool', + { + max: stats.max, + totalCount: stats.totalCount, + idleCount: stats.idleCount, + waitingCount: stats.waitingCount, + }, + ); + + return true; +} + +export function startPostgresPoolSaturationMonitor( + dataSource: DataSource, + logger: LoggerService, + intervalMs = getDatabasePoolMonitorIntervalMs(), +): NodeJS.Timeout { + logPostgresPoolSaturation(dataSource, logger); + + const timer = setInterval(() => { + logPostgresPoolSaturation(dataSource, logger); + }, intervalMs); + + timer.unref(); + + return timer; +} diff --git a/src/config/typeorm.config.ts b/src/config/typeorm.config.ts index 4fd5f29..152da71 100644 --- a/src/config/typeorm.config.ts +++ b/src/config/typeorm.config.ts @@ -1,5 +1,9 @@ import { TypeOrmModuleOptions } from '@nestjs/typeorm'; import * as dotenv from 'dotenv'; +import { + DB_SLOW_QUERY_WARNING_MS, + createPostgresPoolOptions, +} from './database-pool.config'; dotenv.config(); @@ -19,6 +23,8 @@ const config: TypeOrmModuleOptions = { synchronize: !isProduction, logging: !isProduction, logger: 'advanced-console', + maxQueryExecutionTime: DB_SLOW_QUERY_WARNING_MS, + extra: createPostgresPoolOptions(), autoLoadEntities: true, // See `src/config/data-source.ts` for the rationale. This keeps the // production bootstrap (`migrationsRun: isProduction`) consistent with diff --git a/src/main.ts b/src/main.ts index f75cc1d..417e247 100644 --- a/src/main.ts +++ b/src/main.ts @@ -5,6 +5,7 @@ import { DataSource } from 'typeorm'; import { DocumentBuilder, SwaggerModule } from '@nestjs/swagger'; import * as compression from 'compression'; import { configureSecurity } from './config/security.config'; +import { startPostgresPoolSaturationMonitor } from './config/postgres-pool-monitor'; import { StructuredLogger } from './shared/logging/logging.config'; import { initSentry, @@ -73,8 +74,14 @@ async function bootstrap(): Promise { const port = process.env.PORT || 3000; await app.listen(port); + let poolSaturationMonitor: NodeJS.Timeout | undefined; + // Graceful shutdown function shutdown(signal: string): void { + if (poolSaturationMonitor) { + clearInterval(poolSaturationMonitor); + } + appLogger.log( `Received ${signal}, shutting down gracefully...`, 'Bootstrap', @@ -95,6 +102,10 @@ async function bootstrap(): Promise { const dataSource = app.get(DataSource); if (dataSource.isInitialized) { appLogger.log('📦 Database connection established', 'Database'); + poolSaturationMonitor = startPostgresPoolSaturationMonitor( + dataSource, + appLogger, + ); } appLogger.log( `⚡ Application running on http://localhost:${port}`, diff --git a/test/load/db-pool-readiness.js b/test/load/db-pool-readiness.js new file mode 100644 index 0000000..4004df2 --- /dev/null +++ b/test/load/db-pool-readiness.js @@ -0,0 +1,48 @@ +import http from 'k6/http'; +import { check } from 'k6'; +import { Counter, Trend } from 'k6/metrics'; + +const readinessResponseTime = new Trend('db_pool_readiness_response_time', true); +const readinessFailures = new Counter('db_pool_readiness_failures'); + +export const options = { + scenarios: { + db_pool_readiness: { + executor: 'constant-arrival-rate', + rate: 400, + timeUnit: '1s', + duration: '2m', + preAllocatedVUs: 80, + maxVUs: 160, + }, + }, + thresholds: { + http_req_failed: ['rate<0.01'], + http_req_duration: ['p(95)<250'], + db_pool_readiness_response_time: ['p(95)<250'], + db_pool_readiness_failures: ['count<10'], + }, +}; + +const BASE_URL = __ENV.BASE_URL || 'http://localhost:3000'; + +export default function () { + const res = http.get(`${BASE_URL}/health/ready`); + readinessResponseTime.add(res.timings.duration); + + const passed = check(res, { + 'status is 200': (r) => r.status === 200, + 'database is connected': (r) => { + try { + return JSON.parse(r.body).database === 'connected'; + } catch { + return false; + } + }, + 'response time < 250ms': (r) => r.timings.duration < 250, + }); + + if (!passed) { + readinessFailures.add(1); + } +}