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, }, }); }