diff options
Diffstat (limited to 'packages/server/src/core/logger.test.ts')
| -rw-r--r-- | packages/server/src/core/logger.test.ts | 432 |
1 files changed, 0 insertions, 432 deletions
diff --git a/packages/server/src/core/logger.test.ts b/packages/server/src/core/logger.test.ts deleted file mode 100644 index 2663a6be..00000000 --- a/packages/server/src/core/logger.test.ts +++ /dev/null @@ -1,432 +0,0 @@ -/** - * @license - * Copyright 2025 Google LLC - * SPDX-License-Identifier: Apache-2.0 - */ - -import { - describe, - it, - expect, - vi, - beforeEach, - afterEach, - afterAll, -} from 'vitest'; -import { Logger, MessageSenderType, LogEntry } from './logger.js'; -import { promises as fs } from 'node:fs'; -import path from 'node:path'; - -const GEMINI_DIR = '.gemini'; -const LOG_FILE_NAME = 'logs.json'; -const TEST_LOG_FILE_PATH = path.join(process.cwd(), GEMINI_DIR, LOG_FILE_NAME); - -async function cleanupLogFile() { - try { - await fs.unlink(TEST_LOG_FILE_PATH); - } catch (error) { - if ((error as NodeJS.ErrnoException).code !== 'ENOENT') { - // Other errors during unlink are ignored for cleanup purposes - } - } - try { - const geminiDirPath = path.join(process.cwd(), GEMINI_DIR); - const dirContents = await fs.readdir(geminiDirPath); - for (const file of dirContents) { - if (file.startsWith(LOG_FILE_NAME + '.') && file.endsWith('.bak')) { - try { - await fs.unlink(path.join(geminiDirPath, file)); - } catch (_e) { - /* ignore */ - } - } - } - } catch (error) { - if ((error as NodeJS.ErrnoException).code !== 'ENOENT') { - /* ignore if .gemini dir itself is missing */ - } - } -} - -async function readLogFile(): Promise<LogEntry[]> { - try { - const content = await fs.readFile(TEST_LOG_FILE_PATH, 'utf-8'); - return JSON.parse(content) as LogEntry[]; - } catch (error) { - if ((error as NodeJS.ErrnoException).code === 'ENOENT') { - return []; - } - throw error; - } -} - -describe('Logger', () => { - let logger: Logger; - - beforeEach(async () => { - vi.useFakeTimers(); - vi.setSystemTime(new Date('2025-01-01T12:00:00.000Z')); - await cleanupLogFile(); - logger = new Logger(); - // Initialize is usually called here, but some tests initialize their own instances. - // For tests that use the global `logger`, it will be initialized here. - await logger.initialize(); - }); - - afterEach(async () => { - logger.close(); - await cleanupLogFile(); - vi.useRealTimers(); - vi.resetAllMocks(); // Ensure mocks are reset for every test - }); - - afterAll(async () => { - await cleanupLogFile(); - }); - - describe('initialize', () => { - it('should create .gemini directory and an empty log file if none exist', async () => { - await cleanupLogFile(); - const geminiDirPath = path.join(process.cwd(), GEMINI_DIR); - try { - await fs.rm(geminiDirPath, { recursive: true, force: true }); - } catch (_e) { - /* ignore */ - } - - const newLogger = new Logger(); - await newLogger.initialize(); - - const dirExists = await fs - .access(geminiDirPath) - .then(() => true) - .catch(() => false); - expect(dirExists).toBe(true); - const fileExists = await fs - .access(TEST_LOG_FILE_PATH) - .then(() => true) - .catch(() => false); - expect(fileExists).toBe(true); - const logContent = await readLogFile(); - expect(logContent).toEqual([]); - newLogger.close(); - }); - - it('should load existing logs and set correct messageId for the current session', async () => { - const fixedTime = new Date('2025-01-01T10:00:00.000Z'); - vi.setSystemTime(fixedTime); - const currentSessionId = Math.floor(fixedTime.getTime() / 1000); - const existingLogs: LogEntry[] = [ - { - sessionId: currentSessionId, - messageId: 0, - timestamp: new Date('2025-01-01T10:00:05.000Z').toISOString(), - type: MessageSenderType.USER, - message: 'Msg1', - }, - { - sessionId: currentSessionId - 100, - messageId: 5, - timestamp: new Date('2025-01-01T09:00:00.000Z').toISOString(), - type: MessageSenderType.USER, - message: 'OldMsg', - }, - { - sessionId: currentSessionId, - messageId: 1, - timestamp: new Date('2025-01-01T10:00:10.000Z').toISOString(), - type: MessageSenderType.USER, - message: 'Msg2', - }, - ]; - await fs.mkdir(path.join(process.cwd(), GEMINI_DIR), { recursive: true }); - await fs.writeFile(TEST_LOG_FILE_PATH, JSON.stringify(existingLogs)); - const newLogger = new Logger(); - await newLogger.initialize(); - expect(newLogger['messageId']).toBe(2); - expect(newLogger['logs']).toEqual(existingLogs); - newLogger.close(); - }); - - it('should set messageId to 0 for a new session if log file exists but has no logs for current session', async () => { - const fixedTime = new Date('2025-01-01T14:00:00.000Z'); - vi.setSystemTime(fixedTime); - const existingLogs: LogEntry[] = [ - { - sessionId: Math.floor(fixedTime.getTime() / 1000) - 500, - messageId: 5, - timestamp: new Date().toISOString(), - type: MessageSenderType.USER, - message: 'OldMsg', - }, - ]; - await fs.mkdir(path.join(process.cwd(), GEMINI_DIR), { recursive: true }); - await fs.writeFile(TEST_LOG_FILE_PATH, JSON.stringify(existingLogs)); - const newLogger = new Logger(); - await newLogger.initialize(); - expect(newLogger['messageId']).toBe(0); - newLogger.close(); - }); - - it('should be idempotent', async () => { - // logger is initialized in beforeEach - await logger.logMessage(MessageSenderType.USER, 'test message'); - const initialMessageId = logger['messageId']; - const initialLogCount = logger['logs'].length; - await logger.initialize(); // Second call should not change state - expect(logger['messageId']).toBe(initialMessageId); - expect(logger['logs'].length).toBe(initialLogCount); - const logsFromFile = await readLogFile(); - expect(logsFromFile.length).toBe(1); - }); - - it('should handle invalid JSON in log file by backing it up and starting fresh', async () => { - await fs.mkdir(path.join(process.cwd(), GEMINI_DIR), { recursive: true }); - await fs.writeFile(TEST_LOG_FILE_PATH, 'invalid json'); - const consoleDebugSpy = vi - .spyOn(console, 'debug') - .mockImplementation(() => {}); - const newLogger = new Logger(); - await newLogger.initialize(); - expect(consoleDebugSpy).toHaveBeenCalledWith( - expect.stringContaining('Invalid JSON in log file'), - expect.any(SyntaxError), - ); - const logContent = await readLogFile(); - expect(logContent).toEqual([]); - const dirContents = await fs.readdir( - path.join(process.cwd(), GEMINI_DIR), - ); - expect( - dirContents.some( - (f) => - f.startsWith(LOG_FILE_NAME + '.invalid_json') && f.endsWith('.bak'), - ), - ).toBe(true); - consoleDebugSpy.mockRestore(); - newLogger.close(); - }); - - it('should handle non-array JSON in log file by backing it up and starting fresh', async () => { - await fs.mkdir(path.join(process.cwd(), GEMINI_DIR), { recursive: true }); - await fs.writeFile( - TEST_LOG_FILE_PATH, - JSON.stringify({ not: 'an array' }), - ); - const consoleDebugSpy = vi - .spyOn(console, 'debug') - .mockImplementation(() => {}); - const newLogger = new Logger(); - await newLogger.initialize(); - expect(consoleDebugSpy).toHaveBeenCalledWith( - `Log file at ${TEST_LOG_FILE_PATH} is not a valid JSON array. Starting with empty logs.`, - ); - const logContent = await readLogFile(); - expect(logContent).toEqual([]); - const dirContents = await fs.readdir( - path.join(process.cwd(), GEMINI_DIR), - ); - expect( - dirContents.some( - (f) => - f.startsWith(LOG_FILE_NAME + '.malformed_array') && - f.endsWith('.bak'), - ), - ).toBe(true); - consoleDebugSpy.mockRestore(); - newLogger.close(); - }); - }); - - describe('logMessage', () => { - it('should append a message to the log file and update in-memory logs', async () => { - await logger.logMessage(MessageSenderType.USER, 'Hello, world!'); - const logsFromFile = await readLogFile(); - expect(logsFromFile.length).toBe(1); - expect(logsFromFile[0]).toMatchObject({ - sessionId: logger['sessionId'], - messageId: 0, - type: MessageSenderType.USER, - message: 'Hello, world!', - timestamp: new Date('2025-01-01T12:00:00.000Z').toISOString(), - }); - expect(logger['logs'].length).toBe(1); - expect(logger['logs'][0]).toEqual(logsFromFile[0]); - expect(logger['messageId']).toBe(1); - }); - - it('should correctly increment messageId for subsequent messages in the same session', async () => { - await logger.logMessage(MessageSenderType.USER, 'First'); - vi.advanceTimersByTime(1000); - await logger.logMessage(MessageSenderType.USER, 'Second'); - const logs = await readLogFile(); - expect(logs.length).toBe(2); - expect(logs[0].messageId).toBe(0); - expect(logs[1].messageId).toBe(1); - expect(logs[1].timestamp).not.toBe(logs[0].timestamp); - expect(logger['messageId']).toBe(2); - }); - - it('should handle logger not initialized', async () => { - const uninitializedLogger = new Logger(); - const consoleDebugSpy = vi - .spyOn(console, 'debug') - .mockImplementation(() => {}); - await uninitializedLogger.logMessage(MessageSenderType.USER, 'test'); - expect(consoleDebugSpy).toHaveBeenCalledWith( - 'Logger not initialized or session ID missing. Cannot log message.', - ); - expect((await readLogFile()).length).toBe(0); - consoleDebugSpy.mockRestore(); - uninitializedLogger.close(); - }); - - it('should simulate concurrent writes from different logger instances to the same file', async () => { - const logger1 = new Logger(); // logger1 - vi.setSystemTime(new Date('2025-01-01T13:00:00.000Z')); - await logger1.initialize(); - const s1 = logger1['sessionId']; - - const logger2 = new Logger(); // logger2, will share same session if time is same - vi.setSystemTime(new Date('2025-01-01T13:00:00.000Z')); - await logger2.initialize(); - expect(logger2['sessionId']).toEqual(s1); - - // Log from logger1 - await logger1.logMessage(MessageSenderType.USER, 'L1M1'); // L1 internal msgId becomes 1, writes {s1, 0} - vi.advanceTimersByTime(10); - - // Log from logger2. It reads file (sees {s1,0}), its internal msgId for s1 is 1. - await logger2.logMessage(MessageSenderType.USER, 'L2M1'); // L2 internal msgId becomes 2, writes {s1, 1} - vi.advanceTimersByTime(10); - - // Log from logger1. It reads file (sees {s1,0}, {s1,1}), its internal msgId for s1 is 2. - await logger1.logMessage(MessageSenderType.USER, 'L1M2'); // L1 internal msgId becomes 3, writes {s1, 2} - vi.advanceTimersByTime(10); - - // Log from logger2. It reads file (sees {s1,0}, {s1,1}, {s1,2}), its internal msgId for s1 is 3. - await logger2.logMessage(MessageSenderType.USER, 'L2M2'); // L2 internal msgId becomes 4, writes {s1, 3} - - const logsFromFile = await readLogFile(); - expect(logsFromFile.length).toBe(4); - const messageIdsInFile = logsFromFile - .map((log) => log.messageId) - .sort((a, b) => a - b); - expect(messageIdsInFile).toEqual([0, 1, 2, 3]); - - const messagesInFile = logsFromFile - .sort((a, b) => a.messageId - b.messageId) - .map((l) => l.message); - expect(messagesInFile).toEqual(['L1M1', 'L2M1', 'L1M2', 'L2M2']); - - // Check internal state (next messageId each logger would use for that session) - expect(logger1['messageId']).toBe(3); // L1 wrote 0, then 2. Next is 3. - expect(logger2['messageId']).toBe(4); // L2 wrote 1, then 3. Next is 4. - - logger1.close(); - logger2.close(); - }); - - it('should not throw, not increment messageId, and log error if writing to file fails', async () => { - const writeFileSpy = vi - .spyOn(fs, 'writeFile') - .mockRejectedValueOnce(new Error('Disk full')); - const consoleDebugSpy = vi - .spyOn(console, 'debug') - .mockImplementation(() => {}); - const initialMessageId = logger['messageId']; - const initialLogCount = logger['logs'].length; - - await logger.logMessage(MessageSenderType.USER, 'test fail write'); - - expect(consoleDebugSpy).toHaveBeenCalledWith( - 'Error writing to log file:', - expect.any(Error), - ); - expect(logger['messageId']).toBe(initialMessageId); // Not incremented - expect(logger['logs'].length).toBe(initialLogCount); // Log not added to in-memory cache - - writeFileSpy.mockRestore(); - consoleDebugSpy.mockRestore(); - }); - }); - - describe('getPreviousUserMessages', () => { - it('should retrieve user messages, sorted newest first by session, then timestamp, then messageId', async () => { - const loggerSort = new Logger(); - vi.setSystemTime(new Date('2025-01-01T10:00:00.000Z')); - await loggerSort.initialize(); - const s1 = loggerSort['sessionId']!; - await loggerSort.logMessage(MessageSenderType.USER, 'S1M0_ts100000'); // msgId 0 - vi.advanceTimersByTime(10); - await loggerSort.logMessage(MessageSenderType.USER, 'S1M1_ts100010'); // msgId 1 - loggerSort.close(); // Close to ensure next initialize starts a new session if time changed - - vi.setSystemTime(new Date('2025-01-01T11:00:00.000Z')); - await loggerSort.initialize(); // Re-initialize for a new session - const s2 = loggerSort['sessionId']!; - expect(s2).not.toEqual(s1); - await loggerSort.logMessage(MessageSenderType.USER, 'S2M0_ts110000'); // msgId 0 for s2 - vi.advanceTimersByTime(10); - await loggerSort.logMessage( - 'model' as MessageSenderType, - 'S2_Model_ts110010', - ); - vi.advanceTimersByTime(10); - await loggerSort.logMessage(MessageSenderType.USER, 'S2M1_ts110020'); // msgId 1 for s2 - loggerSort.close(); - - // To test the sorting thoroughly, especially the session part, we'll read the file - // as if it was written by multiple sessions and then initialize a new logger to load them. - const combinedLogs = await readLogFile(); - const finalLogger = new Logger(); - // Manually set its internal logs to simulate loading from a file with mixed sessions - finalLogger['logs'] = combinedLogs; - finalLogger['initialized'] = true; // Mark as initialized to allow getPreviousUserMessages to run - - const messages = await finalLogger.getPreviousUserMessages(); - expect(messages).toEqual([ - 'S2M1_ts110020', - 'S2M0_ts110000', - 'S1M1_ts100010', - 'S1M0_ts100000', - ]); - finalLogger.close(); - }); - - it('should return empty array if no user messages exist', async () => { - await logger.logMessage('system' as MessageSenderType, 'System boot'); - const messages = await logger.getPreviousUserMessages(); - expect(messages).toEqual([]); - }); - - it('should return empty array if logger not initialized', async () => { - const uninitializedLogger = new Logger(); - const messages = await uninitializedLogger.getPreviousUserMessages(); - expect(messages).toEqual([]); - uninitializedLogger.close(); - }); - }); - - describe('close', () => { - it('should reset logger state', async () => { - await logger.logMessage(MessageSenderType.USER, 'A message'); - logger.close(); - const consoleDebugSpy = vi - .spyOn(console, 'debug') - .mockImplementation(() => {}); - await logger.logMessage(MessageSenderType.USER, 'Another message'); - expect(consoleDebugSpy).toHaveBeenCalledWith( - 'Logger not initialized or session ID missing. Cannot log message.', - ); - const messages = await logger.getPreviousUserMessages(); - expect(messages).toEqual([]); - expect(logger['initialized']).toBe(false); - expect(logger['logFilePath']).toBeUndefined(); - expect(logger['logs']).toEqual([]); - expect(logger['sessionId']).toBeUndefined(); - expect(logger['messageId']).toBe(0); - consoleDebugSpy.mockRestore(); - }); - }); -}); |
