From fcb27155d882119a2bca6c107283f22f98795f06 Mon Sep 17 00:00:00 2001 From: hannathkadher Date: Tue, 22 Apr 2025 10:20:48 +0400 Subject: [PATCH] typeorm logger --- libs/common/src/context/request-context.ts | 8 ++ libs/common/src/database/database.module.ts | 131 ++++++++++-------- libs/common/src/logger/logger.module.ts | 12 ++ .../src/logger/services/typeorm.logger.ts | 64 +++++++++ .../src/logger/services}/winston.logger.ts | 1 + .../middleware/request-context.middleware.ts | 14 ++ src/app.module.ts | 2 +- src/main.ts | 13 +- 8 files changed, 180 insertions(+), 65 deletions(-) create mode 100644 libs/common/src/context/request-context.ts create mode 100644 libs/common/src/logger/logger.module.ts create mode 100644 libs/common/src/logger/services/typeorm.logger.ts rename {src/common/filters/http-exception/logger => libs/common/src/logger/services}/winston.logger.ts (97%) create mode 100644 libs/common/src/middleware/request-context.middleware.ts diff --git a/libs/common/src/context/request-context.ts b/libs/common/src/context/request-context.ts new file mode 100644 index 0000000..7067bfc --- /dev/null +++ b/libs/common/src/context/request-context.ts @@ -0,0 +1,8 @@ +import { AsyncLocalStorage } from 'async_hooks'; + +export interface RequestContextStore { + requestId?: string; + userId?: string; +} + +export const requestContext = new AsyncLocalStorage(); diff --git a/libs/common/src/database/database.module.ts b/libs/common/src/database/database.module.ts index a25cf35..7ebec3b 100644 --- a/libs/common/src/database/database.module.ts +++ b/libs/common/src/database/database.module.ts @@ -43,73 +43,82 @@ import { SubspaceProductAllocationEntity } from '../modules/space/entities/subsp import { SubspaceEntity } from '../modules/space/entities/subspace/subspace.entity'; import { TagEntity } from '../modules/space/entities/tag.entity'; import { ClientEntity } from '../modules/client/entities'; +import { TypeOrmWinstonLogger } from '@app/common/logger/services/typeorm.logger'; +import { createLogger } from 'winston'; +import { winstonLoggerOptions } from '../logger/services/winston.logger'; @Module({ imports: [ TypeOrmModule.forRootAsync({ imports: [ConfigModule], inject: [ConfigService], - useFactory: (configService: ConfigService) => ({ - name: 'default', - type: 'postgres', - host: configService.get('DB_HOST'), - port: configService.get('DB_PORT'), - username: configService.get('DB_USER'), - password: configService.get('DB_PASSWORD'), - database: configService.get('DB_NAME'), - entities: [ - NewTagEntity, - ProjectEntity, - UserEntity, - UserSessionEntity, - UserOtpEntity, - ProductEntity, - DeviceUserPermissionEntity, - DeviceEntity, - PermissionTypeEntity, - CommunityEntity, - SpaceEntity, - SpaceLinkEntity, - SubspaceEntity, - TagEntity, - UserSpaceEntity, - DeviceUserPermissionEntity, - RoleTypeEntity, - UserNotificationEntity, - DeviceNotificationEntity, - RegionEntity, - TimeZoneEntity, - VisitorPasswordEntity, - DeviceStatusLogEntity, - SceneEntity, - SceneIconEntity, - SceneDeviceEntity, - SpaceModelEntity, - SubspaceModelEntity, - TagModel, - InviteUserEntity, - InviteUserSpaceEntity, - InviteSpaceEntity, - AutomationEntity, - SpaceModelProductAllocationEntity, - SubspaceModelProductAllocationEntity, - SpaceProductAllocationEntity, - SubspaceProductAllocationEntity, - ClientEntity, - ], - namingStrategy: new SnakeNamingStrategy(), - synchronize: Boolean(JSON.parse(configService.get('DB_SYNC'))), - logging: false, - extra: { - charset: 'utf8mb4', - max: 20, // set pool max size - idleTimeoutMillis: 5000, // close idle clients after 5 second - connectionTimeoutMillis: 11_000, // return an error after 11 second if connection could not be established - maxUses: 7500, // close (and replace) a connection after it has been used 7500 times (see below for discussion) - }, - continuationLocalStorage: true, - ssl: Boolean(JSON.parse(configService.get('DB_SSL'))), - }), + useFactory: (configService: ConfigService) => { + const winstonLogger = createLogger(winstonLoggerOptions); + const typeOrmLogger = new TypeOrmWinstonLogger(winstonLogger); + return { + name: 'default', + type: 'postgres', + host: configService.get('DB_HOST'), + port: configService.get('DB_PORT'), + username: configService.get('DB_USER'), + password: configService.get('DB_PASSWORD'), + database: configService.get('DB_NAME'), + entities: [ + NewTagEntity, + ProjectEntity, + UserEntity, + UserSessionEntity, + UserOtpEntity, + ProductEntity, + DeviceUserPermissionEntity, + DeviceEntity, + PermissionTypeEntity, + CommunityEntity, + SpaceEntity, + SpaceLinkEntity, + SubspaceEntity, + TagEntity, + UserSpaceEntity, + DeviceUserPermissionEntity, + RoleTypeEntity, + UserNotificationEntity, + DeviceNotificationEntity, + RegionEntity, + TimeZoneEntity, + VisitorPasswordEntity, + DeviceStatusLogEntity, + SceneEntity, + SceneIconEntity, + SceneDeviceEntity, + SpaceModelEntity, + SubspaceModelEntity, + TagModel, + InviteUserEntity, + InviteUserSpaceEntity, + InviteSpaceEntity, + AutomationEntity, + SpaceModelProductAllocationEntity, + SubspaceModelProductAllocationEntity, + SpaceProductAllocationEntity, + SubspaceProductAllocationEntity, + ClientEntity, + ], + namingStrategy: new SnakeNamingStrategy(), + synchronize: Boolean(JSON.parse(configService.get('DB_SYNC'))), + logging: true, + logger: typeOrmLogger, + extra: { + charset: 'utf8mb4', + max: 20, // set pool max size + idleTimeoutMillis: 5000, // close idle clients after 5 second + connectionTimeoutMillis: 11_000, // return an error after 11 second if connection could not be established + maxUses: 7500, // close (and replace) a connection after it has been used 7500 times (see below for discussion) + }, + continuationLocalStorage: true, + ssl: Boolean(JSON.parse(configService.get('DB_SSL'))), + }; + }, }), ], + providers: [TypeOrmWinstonLogger], }) export class DatabaseModule {} diff --git a/libs/common/src/logger/logger.module.ts b/libs/common/src/logger/logger.module.ts new file mode 100644 index 0000000..50b241a --- /dev/null +++ b/libs/common/src/logger/logger.module.ts @@ -0,0 +1,12 @@ +// src/common/logger/logger.module.ts +import { Module } from '@nestjs/common'; +import { WinstonModule } from 'nest-winston'; +import { winstonLoggerOptions } from './services/winston.logger'; +import { TypeOrmWinstonLogger } from './services/typeorm.logger'; + +@Module({ + imports: [WinstonModule.forRoot(winstonLoggerOptions)], + providers: [TypeOrmWinstonLogger], + exports: [TypeOrmWinstonLogger], +}) +export class LoggerModule {} diff --git a/libs/common/src/logger/services/typeorm.logger.ts b/libs/common/src/logger/services/typeorm.logger.ts new file mode 100644 index 0000000..098959b --- /dev/null +++ b/libs/common/src/logger/services/typeorm.logger.ts @@ -0,0 +1,64 @@ +import { Logger as WinstonLogger } from 'winston'; +import { Logger as TypeOrmLogger } from 'typeorm'; +import { requestContext } from '@app/common/context/request-context'; + +export class TypeOrmWinstonLogger implements TypeOrmLogger { + constructor( + private readonly logger: WinstonLogger, + private readonly slowQueryThreshold = 500, // ms + ) {} + + logQuery(query: string, parameters?: any[]) { + const context = requestContext.getStore(); + const requestId = context?.requestId ?? 'N/A'; + const start = Date.now(); + + const timeout = setTimeout(() => { + const duration = Date.now() - start; + + const isSlow = duration > this.slowQueryThreshold; + this.logger[isSlow ? 'warn' : 'debug'](`[DB][QUERY] ${query}`, { + requestId, + parameters, + duration: `${duration}ms`, + isSlow, + }); + }, 0); + + // Just ensures the setTimeout fires after this function returns + clearTimeout(timeout); + } + + logQueryError(error: string | Error, query: string, parameters?: any[]) { + const requestId = requestContext.getStore()?.requestId ?? 'N/A'; + this.logger.error(`[DB][ERROR] ${query}`, { + requestId, + parameters, + error, + }); + } + + logQuerySlow(time: number, query: string, parameters?: any[]) { + const requestId = requestContext.getStore()?.requestId ?? 'N/A'; + this.logger.warn(`🔥 [DB][SLOW > ${time}ms] ${query}`, { + requestId, + parameters, + time, + }); + } + + logSchemaBuild(message: string) { + this.logger.info(`[DB][SCHEMA] ${message}`); + } + + logMigration(message: string) { + this.logger.info(`[DB][MIGRATION] ${message}`); + } + + log(level: 'log' | 'info' | 'warn', message: any) { + this.logger.log({ + level, + message: `[DB] ${message}`, + }); + } +} diff --git a/src/common/filters/http-exception/logger/winston.logger.ts b/libs/common/src/logger/services/winston.logger.ts similarity index 97% rename from src/common/filters/http-exception/logger/winston.logger.ts rename to libs/common/src/logger/services/winston.logger.ts index 2c024ef..7f0e806 100644 --- a/src/common/filters/http-exception/logger/winston.logger.ts +++ b/libs/common/src/logger/services/winston.logger.ts @@ -2,6 +2,7 @@ import { utilities as nestWinstonModuleUtilities } from 'nest-winston'; import * as winston from 'winston'; export const winstonLoggerOptions: winston.LoggerOptions = { + level: 'debug', transports: [ new winston.transports.Console({ format: winston.format.combine( diff --git a/libs/common/src/middleware/request-context.middleware.ts b/libs/common/src/middleware/request-context.middleware.ts new file mode 100644 index 0000000..1560d7a --- /dev/null +++ b/libs/common/src/middleware/request-context.middleware.ts @@ -0,0 +1,14 @@ +import { Injectable, NestMiddleware } from '@nestjs/common'; +import { requestContext } from '../context/request-context'; +import { v4 as uuidv4 } from 'uuid'; + +@Injectable() +export class RequestContextMiddleware implements NestMiddleware { + use(req: any, res: any, next: () => void) { + const context = { + requestId: req.headers['x-request-id'] || uuidv4(), + }; + + requestContext.run(context, () => next()); + } +} diff --git a/src/app.module.ts b/src/app.module.ts index f07ff20..1fc6c2d 100644 --- a/src/app.module.ts +++ b/src/app.module.ts @@ -33,7 +33,7 @@ import { ClientModule } from './client/client.module'; import { DeviceCommissionModule } from './commission-device/commission-device.module'; import { PowerClampModule } from './power-clamp/power-clamp.module'; import { WinstonModule } from 'nest-winston'; -import { winstonLoggerOptions } from './common/filters/http-exception/logger/winston.logger'; +import { winstonLoggerOptions } from '../libs/common/src/logger/services/winston.logger'; @Module({ imports: [ ConfigModule.forRoot({ diff --git a/src/main.ts b/src/main.ts index 6dbfc45..d337a66 100644 --- a/src/main.ts +++ b/src/main.ts @@ -7,6 +7,9 @@ import { ValidationPipe } from '@nestjs/common'; import { json, urlencoded } from 'body-parser'; import { SeederService } from '@app/common/seed/services/seeder.service'; import { HttpExceptionFilter } from './common/filters/http-exception/http-exception.filter'; +import { Logger } from '@nestjs/common'; +import { WINSTON_MODULE_NEST_PROVIDER } from 'nest-winston'; +import { RequestContextMiddleware } from '@app/common/middleware/request-context.middleware'; async function bootstrap() { const app = await NestFactory.create(AppModule); @@ -18,6 +21,8 @@ async function bootstrap() { app.use(urlencoded({ limit: '1mb', extended: true })); app.useGlobalFilters(new HttpExceptionFilter()); + app.use(new RequestContextMiddleware().use); + app.use( rateLimit({ windowMs: 5 * 60 * 1000, @@ -43,14 +48,16 @@ async function bootstrap() { ); const seederService = app.get(SeederService); + const logger = app.get(WINSTON_MODULE_NEST_PROVIDER); + try { await seederService.seed(); - console.log('Seeding complete!'); + logger.log('Seeding complete!'); } catch (error) { - console.error('Seeding failed!', error); + logger.error('Seeding failed!', error.stack || error); } - console.log('Starting auth at port ...', process.env.PORT || 4000); + logger.log('Starting auth at port ...', process.env.PORT || 4000); await app.listen(process.env.PORT || 4000); } bootstrap();