From 56530248dcfeb0f7f0fff659c66fa9566b583e22 Mon Sep 17 00:00:00 2001 From: dal Date: Thu, 3 Jul 2025 12:31:50 -0600 Subject: [PATCH] Enhance logger middleware by integrating Pino for improved logging capabilities. Added dynamic log level configuration based on environment variables and implemented console capture for info, warn, and error logs. Suppressed debug logs when log level is set to info or higher, ensuring cleaner output in production environments. --- apps/server/src/middleware/logger.test.ts | 124 ++++++++++++++++++++++ apps/server/src/middleware/logger.ts | 42 ++++++-- 2 files changed, 157 insertions(+), 9 deletions(-) create mode 100644 apps/server/src/middleware/logger.test.ts diff --git a/apps/server/src/middleware/logger.test.ts b/apps/server/src/middleware/logger.test.ts new file mode 100644 index 000000000..bf9db34ee --- /dev/null +++ b/apps/server/src/middleware/logger.test.ts @@ -0,0 +1,124 @@ +import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; +import type { Mock } from 'vitest'; + +describe('logger middleware', () => { + let originalEnv: NodeJS.ProcessEnv; + let originalConsole: { + info: typeof console.info; + warn: typeof console.warn; + error: typeof console.error; + debug: typeof console.debug; + }; + + beforeEach(() => { + // Save original env and console + originalEnv = { ...process.env }; + originalConsole = { + info: console.info, + warn: console.warn, + error: console.error, + debug: console.debug, + }; + + // Clear module cache to reload logger with new env + vi.resetModules(); + }); + + afterEach(() => { + // Restore original env and console + process.env = originalEnv; + console.info = originalConsole.info; + console.warn = originalConsole.warn; + console.error = originalConsole.error; + console.debug = originalConsole.debug; + }); + + it('should use info level by default when LOG_LEVEL is not set', async () => { + delete process.env.LOG_LEVEL; + + const { loggerMiddleware } = await import('./logger'); + + // Verify logger was created (basic check) + expect(loggerMiddleware).toBeDefined(); + }); + + it('should respect LOG_LEVEL environment variable', async () => { + process.env.LOG_LEVEL = 'warn'; + + const { loggerMiddleware } = await import('./logger'); + + expect(loggerMiddleware).toBeDefined(); + }); + + it('should capture console methods when LOG_LEVEL is set', async () => { + process.env.LOG_LEVEL = 'info'; + + // Create mocks to track console calls + const mockInfo = vi.fn(); + const mockWarn = vi.fn(); + const mockError = vi.fn(); + const mockDebug = vi.fn(); + + console.info = mockInfo; + console.warn = mockWarn; + console.error = mockError; + console.debug = mockDebug; + + // Import logger which should override console methods + await import('./logger'); + + // Test that console methods were overridden + const testMessage = 'Test message'; + console.info(testMessage); + console.warn(testMessage); + console.error(testMessage); + console.debug(testMessage); + + // Original mocks should not have been called (they were overridden) + expect(mockInfo).not.toHaveBeenCalled(); + expect(mockWarn).not.toHaveBeenCalled(); + expect(mockError).not.toHaveBeenCalled(); + expect(mockDebug).not.toHaveBeenCalled(); + }); + + it('should not capture console methods when LOG_LEVEL is not set', async () => { + delete process.env.LOG_LEVEL; + + // Create mocks + const mockInfo = vi.fn(); + console.info = mockInfo; + + // Import logger + await import('./logger'); + + // Test that console.info was NOT overridden + console.info('Test message'); + + // Original mock should have been called + expect(mockInfo).toHaveBeenCalledWith('Test message'); + }); + + it('should suppress debug logs when LOG_LEVEL is info', async () => { + process.env.LOG_LEVEL = 'info'; + + await import('./logger'); + + // console.debug should be a no-op function + const result = console.debug('This should be suppressed'); + expect(result).toBeUndefined(); + }); + + it('should handle multiple arguments in console methods', async () => { + process.env.LOG_LEVEL = 'info'; + + // We can't easily test the actual pino output, but we can verify + // the console methods accept multiple arguments without error + await import('./logger'); + + expect(() => { + console.info('Message', { data: 'object' }, 123); + console.warn('Warning', 'with', 'multiple', 'args'); + console.error('Error', new Error('test'), { context: 'data' }); + }).not.toThrow(); + }); +}); \ No newline at end of file diff --git a/apps/server/src/middleware/logger.ts b/apps/server/src/middleware/logger.ts index 9663328d6..47dea8c76 100644 --- a/apps/server/src/middleware/logger.ts +++ b/apps/server/src/middleware/logger.ts @@ -1,24 +1,48 @@ import { pinoLogger } from 'hono-pino'; +import pino from 'pino'; import 'pino-pretty'; const isDev = process.env.NODE_ENV !== 'production'; +const logLevel = process.env.LOG_LEVEL || 'info'; let isPinoPrettyAvailable = true; +// Create base pino instance for console capture +const baseLogger = pino({ + level: logLevel, + transport: isDev && isPinoPrettyAvailable + ? { + target: 'pino-pretty', + options: { colorize: true }, + } + : undefined, +}); + +// Simple console capture - only override if LOG_LEVEL is set +if (process.env.LOG_LEVEL) { + const originalConsole = { + info: console.info, + warn: console.warn, + error: console.error, + }; + + console.info = (...args) => baseLogger.info(args.join(' ')); + console.warn = (...args) => baseLogger.warn(args.join(' ')); + console.error = (...args) => baseLogger.error(args.join(' ')); + + // Suppress debug logs when LOG_LEVEL is info or higher + if (logLevel !== 'debug' && logLevel !== 'trace') { + console.debug = () => {}; + } +} + // Create logger with fallback for pino-pretty failures function createLogger() { - console.log('in logger middleware NODE_ENV', process.env.NODE_ENV); // Try pino-pretty in development if (isDev && isPinoPrettyAvailable) { try { return pinoLogger({ - pino: { - level: 'info', - transport: { - target: 'pino-pretty', - options: { colorize: true }, - }, - }, + pino: baseLogger, }); } catch (error) { console.error('pino-pretty not available, falling back to JSON logging', error); @@ -29,7 +53,7 @@ function createLogger() { // Fallback to simple JSON logging return pinoLogger({ pino: { - level: isDev ? 'info' : 'debug', + level: logLevel, }, }); }