diff --git a/src/app.module.ts b/src/app.module.ts index 70b00bf3..b8a41fcc 100644 --- a/src/app.module.ts +++ b/src/app.module.ts @@ -1,4 +1,4 @@ -import { Module, OnModuleInit } from "@nestjs/common"; +import { Module, NestModule, MiddlewareConsumer, OnModuleInit } from "@nestjs/common"; import { ConfigModule, ConfigService } from "@nestjs/config"; import { TypeOrmModule } from "@nestjs/typeorm"; import { validateEnv } from "./config/env.validation"; @@ -55,6 +55,7 @@ import { RolesGuard } from "./common/guard/roles.guard"; import { KycGuard } from "./common/guard/kyc.guard"; import { StrategyAuthGuard } from "./auth/guards/strategy-auth.guard"; import { SubmissionVerifierService } from "./oracle/submission-verifier.service"; +import { LoggingMiddleware } from "./common/middleware/logging.middleware"; @Module({ imports: [ @@ -170,9 +171,13 @@ import { SubmissionVerifierService } from "./oracle/submission-verifier.service" }, ], }) -export class AppModule implements OnModuleInit { +export class AppModule implements NestModule, OnModuleInit { constructor(private readonly verifier: SubmissionVerifierService) {} + configure(consumer: MiddlewareConsumer) { + consumer.apply(LoggingMiddleware).forRoutes("*"); + } + onModuleInit() { this.verifier.start(); } diff --git a/src/common/database/database-index.service.ts b/src/common/database/database-index.service.ts index ada38efc..2752be4a 100644 --- a/src/common/database/database-index.service.ts +++ b/src/common/database/database-index.service.ts @@ -1,6 +1,7 @@ import { Injectable } from "@nestjs/common"; import { InjectRepository } from "@nestjs/typeorm"; import { Repository, DataSource } from "typeorm"; +import { logger } from "../../config/logger"; export interface IndexAnalysis { tableName: string; @@ -114,11 +115,11 @@ export class DatabaseIndexService { await this.dataSource.query( `CREATE INDEX CONCURRENTLY IF NOT EXISTS ${recommendation.indexName} ON ${recommendation.tableName} (${recommendation.columns.join(", ")});`, ); - console.log(`Created index: ${recommendation.indexName}`); + logger.info({ indexName: recommendation.indexName }, `Created index: ${recommendation.indexName}`); } catch (error) { - console.error( - `Failed to create index ${recommendation.indexName}:`, - error, + logger.error( + { indexName: recommendation.indexName, error }, + `Failed to create index ${recommendation.indexName}`, ); } } @@ -277,7 +278,7 @@ export class DatabaseIndexService { "CREATE EXTENSION IF NOT EXISTS pg_stat_statements;", ); } catch (error) { - console.warn("Could not enable pg_stat_statements extension:", error); + logger.warn({ error }, "Could not enable pg_stat_statements extension"); } } } diff --git a/src/common/middleware/logging.middleware.spec.ts b/src/common/middleware/logging.middleware.spec.ts new file mode 100644 index 00000000..47d96011 --- /dev/null +++ b/src/common/middleware/logging.middleware.spec.ts @@ -0,0 +1,103 @@ +import { logger, createLogger } from "../../config/logger"; +import { LoggingMiddleware } from "./logging.middleware"; +import { Request, Response } from "express"; + +describe("logger", () => { + it("should be defined", () => { + expect(logger).toBeDefined(); + }); + + it("should have required logging methods", () => { + expect(typeof logger.info).toBe("function"); + expect(typeof logger.warn).toBe("function"); + expect(typeof logger.error).toBe("function"); + expect(typeof logger.debug).toBe("function"); + }); + + it("should include service base field", () => { + expect((logger as any).bindings?.()?.service ?? (logger as any)[Symbol.for('pino.serializers')]).toBeTruthy(); + }); +}); + +describe("createLogger", () => { + it("should return a child logger with the given context", () => { + const child = createLogger({ module: "test" }); + expect(child).toBeDefined(); + expect(typeof child.info).toBe("function"); + }); +}); + +describe("LoggingMiddleware", () => { + let middleware: LoggingMiddleware; + + beforeEach(() => { + middleware = new LoggingMiddleware(); + }); + + it("should be defined", () => { + expect(middleware).toBeDefined(); + }); + + it("should call next()", () => { + const req = { + headers: {}, + method: "GET", + url: "/test", + ip: "127.0.0.1", + } as unknown as Request; + + const res = { + setHeader: jest.fn(), + on: jest.fn(), + } as unknown as Response; + + const next = jest.fn(); + + middleware.use(req, res, next); + + expect(next).toHaveBeenCalledTimes(1); + }); + + it("should set x-correlation-id response header", () => { + const req = { + headers: {}, + method: "GET", + url: "/test", + ip: "127.0.0.1", + } as unknown as Request; + + const setHeader = jest.fn(); + const res = { + setHeader, + on: jest.fn(), + } as unknown as Response; + + middleware.use(req, res, jest.fn()); + + expect(setHeader).toHaveBeenCalledWith( + "x-correlation-id", + expect.any(String), + ); + }); + + it("should use provided x-correlation-id from request headers", () => { + const correlationId = "test-correlation-id-123"; + const req = { + headers: { "x-correlation-id": correlationId }, + method: "GET", + url: "/test", + ip: "127.0.0.1", + } as unknown as Request; + + const setHeader = jest.fn(); + const res = { + setHeader, + on: jest.fn(), + } as unknown as Response; + + middleware.use(req, res, jest.fn()); + + expect(setHeader).toHaveBeenCalledWith("x-correlation-id", correlationId); + expect((req as any).correlationId).toBe(correlationId); + }); +}); diff --git a/src/common/middleware/logging.middleware.ts b/src/common/middleware/logging.middleware.ts new file mode 100644 index 00000000..69687517 --- /dev/null +++ b/src/common/middleware/logging.middleware.ts @@ -0,0 +1,44 @@ +import { Injectable, NestMiddleware } from "@nestjs/common"; +import { Request, Response, NextFunction } from "express"; +import { v4 as uuidv4 } from "uuid"; +import { logger } from "../../config/logger"; + +@Injectable() +export class LoggingMiddleware implements NestMiddleware { + use(req: Request, res: Response, next: NextFunction): void { + const correlationId = (req.headers["x-correlation-id"] as string) || uuidv4(); + const startTime = Date.now(); + + // Attach correlation ID to request and response headers + (req as any).correlationId = correlationId; + res.setHeader("x-correlation-id", correlationId); + + const requestLog = logger.child({ correlationId }); + + requestLog.info( + { + method: req.method, + url: req.url, + userAgent: req.headers["user-agent"], + ip: req.ip, + }, + "Incoming request", + ); + + res.on("finish", () => { + const duration = Date.now() - startTime; + const level = res.statusCode >= 400 ? "warn" : "info"; + requestLog[level]( + { + method: req.method, + url: req.url, + statusCode: res.statusCode, + duration, + }, + "Request completed", + ); + }); + + next(); + } +} diff --git a/src/config/logger.ts b/src/config/logger.ts index 99d327ac..94027e43 100644 --- a/src/config/logger.ts +++ b/src/config/logger.ts @@ -1,8 +1,17 @@ const pino = require("pino"); -import { getCurrentTraceId } from "./tracing"; const isDevelopment = process.env.NODE_ENV === "development"; +// Lazy getter to avoid circular dependency with tracing.ts +// eslint-disable-next-line @typescript-eslint/no-explicit-any +const getTraceId = (): string | undefined => { + try { + return require("./tracing").getCurrentTraceId(); + } catch { + return undefined; + } +}; + // Create a Pino logger that automatically includes trace IDs export const logger = pino({ level: process.env.LOG_LEVEL || "info", @@ -28,7 +37,7 @@ export const logger = pino({ timestamp: pino.stdTimeFunctions.isoTime, // Mixin to add trace ID to every log entry mixin() { - const traceId = getCurrentTraceId(); + const traceId = getTraceId(); if (traceId) { return { trace_id: traceId, @@ -40,7 +49,7 @@ export const logger = pino({ // Helper function to create child loggers with context export const createLogger = (context: Record) => { - const traceId = getCurrentTraceId(); + const traceId = getTraceId(); const contextWithTrace = traceId ? { ...context, trace_id: traceId } : context; diff --git a/src/config/tracing.ts b/src/config/tracing.ts index 356b9399..a95aa3cd 100644 --- a/src/config/tracing.ts +++ b/src/config/tracing.ts @@ -17,6 +17,10 @@ import { } from "@opentelemetry/api"; import { W3CTraceContextPropagator } from "@opentelemetry/core"; +// Lazy logger reference to avoid circular dependency with logger.ts +// eslint-disable-next-line @typescript-eslint/no-explicit-any +const getLogger = (): any => require("./logger").logger; + // Rate-limited sampling configuration // Uses TraceIdRatioBasedSampler with configurable sampling rate // For production, consider implementing custom adaptive sampling based on your needs @@ -27,7 +31,7 @@ const createConfiguredSampler = () => { ); const finalRate = Math.max(Math.min(samplingRate, 1.0), minSamplingRate); - console.log(`Configured sampling rate: ${finalRate * 100}%`); + getLogger().debug({ samplingRate: finalRate }, `Configured sampling rate: ${finalRate * 100}%`); return new TraceIdRatioBasedSampler(finalRate); }; @@ -40,7 +44,7 @@ const createSpanProcessor = (): SpanProcessor => { process.env.OTEL_EXPORTER_JAEGER_ENDPOINT || "http://localhost:14268/api/traces", }); - console.log("Jaeger exporter configured"); + getLogger().info("Jaeger exporter configured"); return new BatchSpanProcessor(jaegerExporter); } @@ -51,7 +55,7 @@ const createSpanProcessor = (): SpanProcessor => { process.env.OTEL_EXPORTER_OTLP_ENDPOINT || "http://localhost:4318/v1/traces", }); - console.log("OTLP exporter configured"); + getLogger().info("OTLP exporter configured"); return new BatchSpanProcessor(otlpExporter); } @@ -90,15 +94,16 @@ export const sdk = new NodeSDK({ export const startTracing = async () => { try { sdk.start(); - console.log("OpenTelemetry tracing initialized with configurable sampling"); - console.log( - "Jaeger endpoint:", - process.env.OTEL_EXPORTER_JAEGER_ENDPOINT || - "http://localhost:14268/api/traces", + getLogger().info( + { + jaegerEndpoint: + process.env.OTEL_EXPORTER_JAEGER_ENDPOINT || + "http://localhost:14268/api/traces", + }, + "OpenTelemetry tracing initialized with configurable sampling", ); - console.log("Jaeger UI available at:", "http://localhost:16686"); } catch (err) { - console.error("Failed to start OpenTelemetry SDK:", err); + getLogger().error({ err }, "Failed to start OpenTelemetry SDK"); } }; @@ -106,9 +111,9 @@ export const startTracing = async () => { export const shutdownTracing = async () => { try { await sdk.shutdown(); - console.log("OpenTelemetry tracing shut down"); + getLogger().info("OpenTelemetry tracing shut down"); } catch (error) { - console.error("Error shutting down tracing:", error); + getLogger().error({ error }, "Error shutting down tracing"); } }; diff --git a/src/oracle/submission-verifier.service.ts b/src/oracle/submission-verifier.service.ts index 78c77354..1e115f36 100644 --- a/src/oracle/submission-verifier.service.ts +++ b/src/oracle/submission-verifier.service.ts @@ -2,6 +2,7 @@ import { Injectable, Logger } from "@nestjs/common"; import { AuditLogService } from "../audit/audit-log.service"; +import { logger } from "../config/logger"; interface OnChainSubmission { id: string; @@ -116,7 +117,7 @@ export class SubmissionVerifierService { // ------------------------------------- private async triggerAlerts(result: any) { // 👉 Replace with real integrations - console.warn("ALERT: Submission mismatch detected", result); + logger.warn({ result }, "ALERT: Submission mismatch detected"); // Example webhook // await axios.post(WEBHOOK_URL, result);