From 167c3366c859c3ca1619132f5b199c06187e49fb Mon Sep 17 00:00:00 2001 From: Phillip Wirth Date: Thu, 12 Dec 2024 12:28:58 +0100 Subject: [PATCH] BC-8559 implement request logging in nestjs --- apps/server/src/apps/admin-api-server.app.ts | 3 ++ .../src/apps/board-collaboration.app.ts | 2 ++ apps/server/src/apps/common-cartridge.app.ts | 2 ++ apps/server/src/apps/files-storage.app.ts | 4 ++- .../src/apps/fwu-learning-contents.app.ts | 4 ++- apps/server/src/apps/h5p-editor.app.ts | 5 +++- .../src/apps/helpers/app-logger-middleware.ts | 28 ++++++++++++++++++ .../src/apps/helpers/logger-middleware.ts | 22 ++++++++++++++ .../src/apps/helpers/request-loggable.ts | 29 +++++++++++++++++++ apps/server/src/apps/management.app.ts | 5 +++- apps/server/src/apps/server.app.ts | 4 ++- apps/server/src/apps/tldraw.app.ts | 2 ++ 12 files changed, 105 insertions(+), 5 deletions(-) create mode 100644 apps/server/src/apps/helpers/app-logger-middleware.ts create mode 100644 apps/server/src/apps/helpers/logger-middleware.ts create mode 100644 apps/server/src/apps/helpers/request-loggable.ts diff --git a/apps/server/src/apps/admin-api-server.app.ts b/apps/server/src/apps/admin-api-server.app.ts index 92025e31ca..bb0f72f067 100644 --- a/apps/server/src/apps/admin-api-server.app.ts +++ b/apps/server/src/apps/admin-api-server.app.ts @@ -6,6 +6,7 @@ import { LegacyLogger, Logger } from '@src/core/logger'; import { AdminApiServerModule } from '@modules/server/admin-api.server.module'; import express from 'express'; import { install as sourceMapInstall } from 'source-map-support'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { AppStartLoggable, enableOpenApiDocs, @@ -23,6 +24,8 @@ async function bootstrap() { const nestAdminServerApp = await NestFactory.create(AdminApiServerModule, nestAdminServerExpressAdapter); const logger = await nestAdminServerApp.resolve(Logger); const legacyLogger = await nestAdminServerApp.resolve(LegacyLogger); + nestAdminServerApp.use(createAppLoggerMiddleware(await nestAdminServerApp.resolve(Logger))); + nestAdminServerApp.useLogger(legacyLogger); nestAdminServerApp.enableCors(); diff --git a/apps/server/src/apps/board-collaboration.app.ts b/apps/server/src/apps/board-collaboration.app.ts index 25a8c418c9..3cea7f4921 100644 --- a/apps/server/src/apps/board-collaboration.app.ts +++ b/apps/server/src/apps/board-collaboration.app.ts @@ -12,6 +12,7 @@ import { RedisIoAdapter } from '@infra/socketio'; import { BoardCollaborationModule } from '@modules/board/board-collaboration.app.module'; import express from 'express'; import { ExpressAdapter } from '@nestjs/platform-express'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { enableOpenApiDocs, addPrometheusMetricsMiddlewaresIfEnabled, @@ -37,6 +38,7 @@ async function bootstrap() { }; enableOpenApiDocs(nestApp, 'docs', options); const logger = await nestApp.resolve(Logger); + nestApp.use(createAppLoggerMiddleware(await nestApp.resolve(Logger))); await nestApp.init(); diff --git a/apps/server/src/apps/common-cartridge.app.ts b/apps/server/src/apps/common-cartridge.app.ts index 48a5daf6b0..5ac0a20706 100644 --- a/apps/server/src/apps/common-cartridge.app.ts +++ b/apps/server/src/apps/common-cartridge.app.ts @@ -6,6 +6,7 @@ import { LegacyLogger, Logger } from '@src/core/logger'; import { CommonCartridgeApiModule } from '@modules/common-cartridge/common-cartridge-api.module'; import express from 'express'; import { install as sourceMapInstall } from 'source-map-support'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { AppStartLoggable, enableOpenApiDocs, @@ -27,6 +28,7 @@ async function bootstrap() { const rootExpress = express(); const logger = await nestApp.resolve(Logger); + nestApp.use(createAppLoggerMiddleware(await nestApp.resolve(Logger))); addPrometheusMetricsMiddlewaresIfEnabled(logger, rootExpress); diff --git a/apps/server/src/apps/files-storage.app.ts b/apps/server/src/apps/files-storage.app.ts index 8a1f4e59a4..683a8c6c37 100644 --- a/apps/server/src/apps/files-storage.app.ts +++ b/apps/server/src/apps/files-storage.app.ts @@ -11,7 +11,8 @@ import { install as sourceMapInstall } from 'source-map-support'; import { FilesStorageApiModule } from '@modules/files-storage/files-storage-api.module'; import { API_VERSION_PATH } from '@modules/files-storage/files-storage.const'; import { SwaggerDocumentOptions } from '@nestjs/swagger'; -import { LegacyLogger } from '@src/core/logger'; +import { LegacyLogger, Logger } from '@src/core/logger'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { enableOpenApiDocs } from './helpers'; async function bootstrap() { @@ -28,6 +29,7 @@ async function bootstrap() { // customize nest app settings nestApp.enableCors({ exposedHeaders: ['Content-Disposition'] }); + nestApp.use(createAppLoggerMiddleware(await nestApp.resolve(Logger))); const options: SwaggerDocumentOptions = { operationIdFactory: (_controllerKey: string, methodKey: string) => methodKey, diff --git a/apps/server/src/apps/fwu-learning-contents.app.ts b/apps/server/src/apps/fwu-learning-contents.app.ts index e42c4d76df..08ed85a038 100644 --- a/apps/server/src/apps/fwu-learning-contents.app.ts +++ b/apps/server/src/apps/fwu-learning-contents.app.ts @@ -8,8 +8,9 @@ import express from 'express'; import { install as sourceMapInstall } from 'source-map-support'; // application imports -import { LegacyLogger } from '@src/core/logger'; +import { LegacyLogger, Logger } from '@src/core/logger'; import { FwuLearningContentsModule } from '@modules/fwu-learning-contents'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { enableOpenApiDocs } from './helpers'; async function bootstrap() { @@ -26,6 +27,7 @@ async function bootstrap() { // customize nest app settings nestApp.enableCors({ exposedHeaders: ['Content-Disposition'] }); enableOpenApiDocs(nestApp, 'docs'); + nestApp.use(createAppLoggerMiddleware(await nestApp.resolve(Logger))); await nestApp.init(); diff --git a/apps/server/src/apps/h5p-editor.app.ts b/apps/server/src/apps/h5p-editor.app.ts index 96972f118a..d113dd8416 100644 --- a/apps/server/src/apps/h5p-editor.app.ts +++ b/apps/server/src/apps/h5p-editor.app.ts @@ -8,8 +8,9 @@ import express from 'express'; import { install as sourceMapInstall } from 'source-map-support'; // application imports -import { LegacyLogger } from '@src/core/logger'; +import { LegacyLogger, Logger } from '@src/core/logger'; import { H5PEditorModule } from '@modules/h5p-editor'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { enableOpenApiDocs } from './helpers'; async function bootstrap() { @@ -24,6 +25,8 @@ async function bootstrap() { // WinstonLogger nestApp.useLogger(await nestApp.resolve(LegacyLogger)); + nestApp.use(createAppLoggerMiddleware(await nestApp.resolve(Logger))); + // customize nest app settings nestApp.enableCors({ exposedHeaders: ['Content-Disposition'] }); enableOpenApiDocs(nestApp, 'docs'); diff --git a/apps/server/src/apps/helpers/app-logger-middleware.ts b/apps/server/src/apps/helpers/app-logger-middleware.ts new file mode 100644 index 0000000000..a2fdbf08f7 --- /dev/null +++ b/apps/server/src/apps/helpers/app-logger-middleware.ts @@ -0,0 +1,28 @@ +import { Request, Response, NextFunction } from 'express'; +import { Logger } from '@src/core/logger'; +import { RequestLoggable } from '@src/apps/helpers/request-loggable'; +import { Configuration } from '@hpi-schul-cloud/commons/lib'; + +export const createAppLoggerMiddleware = ( + logger: Logger +): ((request: Request, response: Response, next: NextFunction) => void) => { + logger.setContext('AppLoggerMiddleware'); + const enabled = Configuration.get('REQUEST_LOGGING_ENABLED') as boolean; + + return (request: Request, response: Response, next: NextFunction): void => { + if (enabled) { + const startAt = process.hrtime(); + const { method, originalUrl } = request; + + response.on('finish', () => { + const { statusCode } = response; + const contentLength = response.get('content-length') || 'unknown'; + const diff = process.hrtime(startAt); + const responseTime = diff[0] * 1e3 + diff[1] * 1e-6; + logger.info(new RequestLoggable({ method, originalUrl, statusCode, responseTime, contentLength })); + }); + } + + next(); + }; +}; diff --git a/apps/server/src/apps/helpers/logger-middleware.ts b/apps/server/src/apps/helpers/logger-middleware.ts new file mode 100644 index 0000000000..def3a0714e --- /dev/null +++ b/apps/server/src/apps/helpers/logger-middleware.ts @@ -0,0 +1,22 @@ +import { Request, Response, NextFunction } from 'express'; +import { Injectable, NestMiddleware, Logger } from '@nestjs/common'; + +@Injectable() +export class LoggerMiddleware implements NestMiddleware { + private logger = new Logger('HTTP'); + + public use(request: Request, response: Response, next: NextFunction): void { + const startAt = process.hrtime(); + const { method, originalUrl } = request; + + response.on('finish', () => { + const { statusCode } = response; + const contentLength = response.get('content-length') || 'unknown'; + const diff = process.hrtime(startAt); + const responseTime = diff[0] * 1e3 + diff[1] * 1e-6; + this.logger.log(`${method} ${originalUrl} ${statusCode} ${responseTime}ms ${contentLength}`); + }); + + next(); + } +} \ No newline at end of file diff --git a/apps/server/src/apps/helpers/request-loggable.ts b/apps/server/src/apps/helpers/request-loggable.ts new file mode 100644 index 0000000000..c8bf12c7c5 --- /dev/null +++ b/apps/server/src/apps/helpers/request-loggable.ts @@ -0,0 +1,29 @@ +import { Loggable, LogMessage } from '@src/core/logger'; + +interface RequestLogInfo { + method: string; + originalUrl: string; + statusCode: number; + responseTime: number; + contentLength: string; +} + +export class RequestLoggable implements Loggable { + constructor(private readonly requestLog: RequestLogInfo) {} + + public getLogMessage(): LogMessage { + return { + message: `${this.requestLog.method} ${this.requestLog.originalUrl} ${this.requestLog.statusCode} ${this.requestLog.responseTime}ms ${this.requestLog.contentLength}`, + }; + // return { + // message: 'loggables rock', + // data: { + // method: this.requestLog.method, + // originalUrl: this.requestLog.originalUrl, + // statusCode: this.requestLog.statusCode, + // responseTime: `${this.requestLog.responseTime}ms`, + // contentLength: this.requestLog.contentLength, + // }, + // }; + } +} diff --git a/apps/server/src/apps/management.app.ts b/apps/server/src/apps/management.app.ts index 4206485007..9f78e55a93 100644 --- a/apps/server/src/apps/management.app.ts +++ b/apps/server/src/apps/management.app.ts @@ -8,8 +8,9 @@ import express from 'express'; import { install as sourceMapInstall } from 'source-map-support'; // application imports -import { LegacyLogger } from '@src/core/logger'; +import { LegacyLogger, Logger } from '@src/core/logger'; import { ManagementServerModule } from '@modules/management'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { enableOpenApiDocs } from './helpers'; async function bootstrap() { @@ -21,6 +22,8 @@ async function bootstrap() { const nestExpressAdapter = new ExpressAdapter(nestExpress); const nestApp = await NestFactory.create(ManagementServerModule, nestExpressAdapter); + nestApp.use(createAppLoggerMiddleware(await nestApp.resolve(Logger))); + // WinstonLogger nestApp.useLogger(await nestApp.resolve(LegacyLogger)); diff --git a/apps/server/src/apps/server.app.ts b/apps/server/src/apps/server.app.ts index 1046f0fdf8..4fdac329b9 100644 --- a/apps/server/src/apps/server.app.ts +++ b/apps/server/src/apps/server.app.ts @@ -23,6 +23,7 @@ import { join } from 'path'; // register source-map-support for debugging import { install as sourceMapInstall } from 'source-map-support'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { AppStartLoggable, enableOpenApiDocs, @@ -34,7 +35,7 @@ import legacyAppPromise = require('../../../../src/app'); async function bootstrap() { sourceMapInstall(); - // create the NestJS application on a seperate express instance + // create the NestJS application on a separate express instance const nestExpress = express(); const nestExpressAdapter = new ExpressAdapter(nestExpress); const nestApp = await NestFactory.create(ServerModule, nestExpressAdapter); @@ -45,6 +46,7 @@ async function bootstrap() { nestApp.useLogger(legacyLogger); const logger = await nestApp.resolve(Logger); + nestApp.use(createAppLoggerMiddleware(await nestApp.resolve(Logger))); // load the legacy feathers/express server // eslint-disable-next-line @typescript-eslint/no-unsafe-assignment diff --git a/apps/server/src/apps/tldraw.app.ts b/apps/server/src/apps/tldraw.app.ts index cab6508bbc..6776f3ca24 100644 --- a/apps/server/src/apps/tldraw.app.ts +++ b/apps/server/src/apps/tldraw.app.ts @@ -9,6 +9,7 @@ import * as WebSocket from 'ws'; import { WsAdapter } from '@nestjs/platform-ws'; import { ExpressAdapter } from '@nestjs/platform-express'; import express from 'express'; +import { createAppLoggerMiddleware } from '@src/apps/helpers/app-logger-middleware'; import { AppStartLoggable, enableOpenApiDocs, @@ -23,6 +24,7 @@ async function bootstrap() { const nestExpressAdapter = new ExpressAdapter(nestExpress); const nestApp = await NestFactory.create(TldrawApiModule, nestExpressAdapter); nestApp.useLogger(await nestApp.resolve(LegacyLogger)); + nestApp.use(createAppLoggerMiddleware(await nestApp.resolve(Logger))); nestApp.enableCors(); const nestAppWS = await NestFactory.create(TldrawWsModule);