summaryrefslogtreecommitdiff
path: root/packages/server/src/core/logger.test.ts
diff options
context:
space:
mode:
Diffstat (limited to 'packages/server/src/core/logger.test.ts')
-rw-r--r--packages/server/src/core/logger.test.ts432
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();
- });
- });
-});