From c333c68dcd3cf26cd24092b16d76c6b6eb93eb35 Mon Sep 17 00:00:00 2001 From: aliyudotdev <296488884+aliyudotdev@users.noreply.github.com> Date: Mon, 29 Jun 2026 01:35:15 -0700 Subject: [PATCH] feat: add slow query logging and EXPLAIN ANALYZE (#884) --- src/config/database.config.ts | 4 ++ src/database/logging/slow-query.logger.ts | 86 +++++++++++++++++++++++ 2 files changed, 90 insertions(+) create mode 100644 src/database/logging/slow-query.logger.ts diff --git a/src/config/database.config.ts b/src/config/database.config.ts index 4c0e4781..018f1d4c 100644 --- a/src/config/database.config.ts +++ b/src/config/database.config.ts @@ -1,5 +1,6 @@ import { TypeOrmModuleOptions } from '@nestjs/typeorm'; import { resolvePoolConfig } from '../database/pool'; +import { SlowQueryLogger } from '../database/logging/slow-query.logger'; interface DatabaseConnectionSettings { host: string; @@ -71,9 +72,12 @@ export function getDatabaseConfig(): TypeOrmModuleOptions { const primary = readPrimarySettings(); const replicas = getReadReplicaConnections(primary); const pool = resolvePoolConfig(); + const isTestEnv = process.env.NODE_ENV === 'test'; const commonOptions = { autoLoadEntities: true, synchronize: process.env.NODE_ENV !== 'production', + maxQueryExecutionTime: parseInt(process.env.DB_SLOW_QUERY_THRESHOLD_MS ?? '500', 10), + logger: isTestEnv ? undefined : new SlowQueryLogger(), extra: { max: pool.max, min: pool.min, diff --git a/src/database/logging/slow-query.logger.ts b/src/database/logging/slow-query.logger.ts new file mode 100644 index 00000000..20f06ce5 --- /dev/null +++ b/src/database/logging/slow-query.logger.ts @@ -0,0 +1,86 @@ +import { Injectable, Logger } from '@nestjs/common'; +import { Logger as TypeOrmLogger, QueryRunner } from 'typeorm'; + +const EXPLAIN_THRESHOLD_MS = parseInt(process.env.DB_EXPLAIN_THRESHOLD_MS ?? '2000', 10); + +/** + * TypeORM logger that emits structured slow-query logs and, for the + * slowest queries, an async EXPLAIN ANALYZE. Wired up only outside the + * test environment via getDatabaseConfig(). + */ +@Injectable() +export class SlowQueryLogger implements TypeOrmLogger { + private readonly logger = new Logger(SlowQueryLogger.name); + + logQuery(): void { + // Per-query logging is intentionally a no-op; only slow queries are logged. + } + + logQueryError(error: string | Error, query: string, parameters?: unknown[]): void { + this.logger.error( + JSON.stringify({ + message: 'Query error', + error: error instanceof Error ? error.message : error, + query, + parameters, + }), + ); + } + + logQuerySlow(time: number, query: string, parameters?: unknown[], queryRunner?: QueryRunner): void { + this.logger.warn( + JSON.stringify({ + message: 'Slow query detected', + durationMs: time, + query, + parameters, + }), + ); + + if (time >= EXPLAIN_THRESHOLD_MS && this.isSelect(query)) { + this.logExplainAnalyze(query, parameters, queryRunner).catch((err: Error) => + this.logger.error(`Failed to run EXPLAIN ANALYZE: ${err.message}`), + ); + } + } + + logSchemaBuild(message: string): void { + this.logger.log(message); + } + + logMigration(message: string): void { + this.logger.log(message); + } + + log(level: 'log' | 'info' | 'warn', message: unknown): void { + if (level === 'warn') { + this.logger.warn(message as string); + } else { + this.logger.log(message as string); + } + } + + private isSelect(query: string): boolean { + return /^\s*select/i.test(query); + } + + private async logExplainAnalyze( + query: string, + parameters: unknown[] | undefined, + queryRunner?: QueryRunner, + ): Promise { + if (!queryRunner) { + return; + } + + const explain = await queryRunner.connection.query(`EXPLAIN ANALYZE ${query}`, parameters as any[]); + + this.logger.warn( + JSON.stringify({ + message: 'EXPLAIN ANALYZE for slow query', + query, + explain, + }), + ); + } +}