Browse Source

feat: add per-session log rotation with auto-cleanup (#309)

* feat: per-session log files with cleanup and os.homedir()

* feat: export initLogger, getLogDir, resetLogger from utils barrel

* feat: initialize per-session logger at plugin startup

* test: rewrite logger tests with OPENCODE_LOG_DIR isolation

* style: apply biome formatting

* fix: add log() calls in cleanup tests to create session file

* fix: isolate JSON.stringify to prevent log entry loss on unserializable data

* fix: prevent undefined-to-string coercion in test env restore
jwcrystal 3 months ago
parent
commit
680ce51cba
4 changed files with 210 additions and 81 deletions
  1. 3 1
      src/index.ts
  2. 1 1
      src/utils/index.ts
  3. 145 68
      src/utils/logger.test.ts
  4. 61 11
      src/utils/logger.ts

+ 3 - 1
src/index.ts

@@ -31,9 +31,11 @@ import {
   lsp_rename,
   setUserLspConfig,
 } from './tools';
-import { log } from './utils/logger';
+import { initLogger, log } from './utils/logger';
 
 const OhMyOpenCodeLite: Plugin = async (ctx) => {
+  const sessionId = new Date().toISOString().replace(/[-:]/g, '').slice(0, 15);
+  initLogger(sessionId);
   const config = loadPluginConfig(ctx.directory);
   const agentDefs = createAgents(config);
   const agents = getAgentConfigs(config);

+ 1 - 1
src/utils/index.ts

@@ -1,7 +1,7 @@
 export * from './agent-variant';
 export * from './env';
 export * from './internal-initiator';
-export { log } from './logger';
+export { getLogDir, initLogger, log, resetLogger } from './logger';
 export * from './polling';
 export * from './session';
 export { extractZip } from './zip-extractor';

+ 145 - 68
src/utils/logger.test.ts

@@ -2,125 +2,202 @@ import { afterEach, beforeEach, describe, expect, test } from 'bun:test';
 import * as fs from 'node:fs';
 import * as os from 'node:os';
 import * as path from 'node:path';
-import { log } from './logger';
+import { getLogDir, initLogger, log, resetLogger } from './logger';
 
 describe('logger', () => {
-  const testLogFile = path.join(
-    process.env.HOME || os.tmpdir(),
-    '.local/share/opencode/oh-my-opencode-slim.log',
-  );
+  let tmpDir: string;
+  let origLogDir: string | undefined;
 
   beforeEach(() => {
-    // Clean up log file before each test
-    if (fs.existsSync(testLogFile)) {
-      fs.unlinkSync(testLogFile);
-    }
+    tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'logger-test-'));
+    origLogDir = process.env.OPENCODE_LOG_DIR;
+    process.env.OPENCODE_LOG_DIR = tmpDir;
+    resetLogger();
   });
 
   afterEach(() => {
-    // Clean up log file after each test
-    if (fs.existsSync(testLogFile)) {
-      fs.unlinkSync(testLogFile);
+    if (origLogDir === undefined) {
+      delete process.env.OPENCODE_LOG_DIR;
+    } else {
+      process.env.OPENCODE_LOG_DIR = origLogDir;
     }
+    fs.rmSync(tmpDir, { recursive: true, force: true });
+  });
+
+  test('log() silently no-ops before initLogger()', () => {
+    log('should not crash');
+    expect(fs.readdirSync(tmpDir).length).toBe(0);
   });
 
-  test('writes log message to file', () => {
+  test('initLogger creates per-session log file', () => {
+    initLogger('20260416T143052');
     log('test message');
 
-    expect(fs.existsSync(testLogFile)).toBe(true);
-    const content = fs.readFileSync(testLogFile, 'utf-8');
-    expect(content).toContain('test message');
+    const files = fs.readdirSync(tmpDir);
+    expect(files).toEqual(['oh-my-opencode-slim.20260416T143052.log']);
   });
 
-  test('includes timestamp in log entry', () => {
+  test('writes log message with timestamp', () => {
+    initLogger('session1');
     log('timestamped message');
 
-    const content = fs.readFileSync(testLogFile, 'utf-8');
-    // Check for ISO timestamp format [YYYY-MM-DDTHH:MM:SS.sssZ]
+    const logPath = path.join(tmpDir, 'oh-my-opencode-slim.session1.log');
+    const content = fs.readFileSync(logPath, 'utf-8');
     expect(content).toMatch(/\[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z\]/);
+    expect(content).toContain('timestamped message');
   });
 
   test('logs message with data object', () => {
+    initLogger('session1');
     log('message with data', { key: 'value', number: 42 });
 
-    const content = fs.readFileSync(testLogFile, 'utf-8');
-    expect(content).toContain('message with data');
+    const logPath = path.join(tmpDir, 'oh-my-opencode-slim.session1.log');
+    const content = fs.readFileSync(logPath, 'utf-8');
     expect(content).toContain('"key":"value"');
     expect(content).toContain('"number":42');
   });
 
-  test('logs message without data', () => {
+  test('logs message without extra JSON when no data', () => {
+    initLogger('session1');
     log('message without data');
 
-    const content = fs.readFileSync(testLogFile, 'utf-8');
-    expect(content).toContain('message without data');
-    // Should not have extra JSON at the end
+    const logPath = path.join(tmpDir, 'oh-my-opencode-slim.session1.log');
+    const content = fs.readFileSync(logPath, 'utf-8');
     expect(content.trim()).toMatch(/message without data\s*$/);
   });
 
   test('appends multiple log entries', () => {
-    log('first message');
-    log('second message');
-    log('third message');
+    initLogger('session1');
+    log('first');
+    log('second');
+    log('third');
 
-    const content = fs.readFileSync(testLogFile, 'utf-8');
-    const lines = content.trim().split('\n');
+    const logPath = path.join(tmpDir, 'oh-my-opencode-slim.session1.log');
+    const lines = fs.readFileSync(logPath, 'utf-8').trim().split('\n');
     expect(lines.length).toBe(3);
-    expect(lines[0]).toContain('first message');
-    expect(lines[1]).toContain('second message');
-    expect(lines[2]).toContain('third message');
+    expect(lines[0]).toContain('first');
+    expect(lines[1]).toContain('second');
+    expect(lines[2]).toContain('third');
   });
 
-  test('handles complex data structures', () => {
-    const complexData = {
-      nested: { deep: { value: 'test' } },
-      array: [1, 2, 3],
-      boolean: true,
-      null: null,
-    };
+  test('initLogger called twice uses second session file', () => {
+    initLogger('session1');
+    log('from session1');
+    initLogger('session2');
+    log('from session2');
+
+    const files = fs.readdirSync(tmpDir).sort();
+    expect(files).toEqual([
+      'oh-my-opencode-slim.session1.log',
+      'oh-my-opencode-slim.session2.log',
+    ]);
+
+    const content1 = fs.readFileSync(path.join(tmpDir, files[0]), 'utf-8');
+    const content2 = fs.readFileSync(path.join(tmpDir, files[1]), 'utf-8');
+    expect(content1).toContain('from session1');
+    expect(content1).not.toContain('from session2');
+    expect(content2).toContain('from session2');
+  });
 
-    log('complex data', complexData);
+  test('cleanup deletes files older than 7 days', () => {
+    const oldFileName = 'oh-my-opencode-slim.20260301T000000.log';
+    const oldPath = path.join(tmpDir, oldFileName);
+    fs.writeFileSync(oldPath, 'old log\n');
 
-    const content = fs.readFileSync(testLogFile, 'utf-8');
-    expect(content).toContain('complex data');
-    expect(content).toContain('"nested":');
-    expect(content).toContain('"array":[1,2,3]');
-    expect(content).toContain('"boolean":true');
+    const eightDaysAgo = Date.now() - 8 * 24 * 60 * 60 * 1000;
+    fs.utimesSync(oldPath, new Date(eightDaysAgo), new Date(eightDaysAgo));
+
+    initLogger('current');
+    log('init');
+
+    const files = fs.readdirSync(tmpDir);
+    expect(files).not.toContain(oldFileName);
+    expect(files.find((f) => f.includes('current'))).toBeDefined();
   });
 
-  test('handles special characters in message', () => {
-    log('message with special chars: @#$%^&*()');
+  test('cleanup preserves recent files', () => {
+    const recentFileName = 'oh-my-opencode-slim.20260415T000000.log';
+    const recentPath = path.join(tmpDir, recentFileName);
+    fs.writeFileSync(recentPath, 'recent log\n');
+
+    initLogger('current');
 
-    const content = fs.readFileSync(testLogFile, 'utf-8');
-    expect(content).toContain('message with special chars: @#$%^&*()');
+    const files = fs.readdirSync(tmpDir);
+    expect(files).toContain(recentFileName);
   });
 
-  test('handles empty string message', () => {
-    log('');
+  test('cleanup with mixed-age files deletes only old ones', () => {
+    const oldFileName = 'oh-my-opencode-slim.old.log';
+    const oldPath = path.join(tmpDir, oldFileName);
+    fs.writeFileSync(oldPath, 'old log\n');
+    const eightDaysAgo = Date.now() - 8 * 24 * 60 * 60 * 1000;
+    fs.utimesSync(oldPath, new Date(eightDaysAgo), new Date(eightDaysAgo));
+
+    const recentFileName = 'oh-my-opencode-slim.recent.log';
+    const recentPath = path.join(tmpDir, recentFileName);
+    fs.writeFileSync(recentPath, 'recent log\n');
+
+    initLogger('current');
+    log('init');
 
-    const content = fs.readFileSync(testLogFile, 'utf-8');
-    expect(content).toMatch(
-      /\[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z\]\s+\n/,
-    );
+    const files = fs.readdirSync(tmpDir);
+    expect(files).not.toContain(oldFileName);
+    expect(files).toContain(recentFileName);
+    expect(files.find((f) => f.includes('current'))).toBeDefined();
   });
 
-  test('does not throw when logging fails', () => {
-    // Make the log directory read-only to force a write error
-    // This test is platform-dependent and might not work on all systems
-    // So we'll just verify that log() doesn't throw
-    expect(() => {
-      log('test message', { data: 'value' });
-    }).not.toThrow();
+  test('cleanup with no existing files does not crash', () => {
+    expect(() => initLogger('fresh')).not.toThrow();
+    log('init');
+    const files = fs.readdirSync(tmpDir);
+    expect(files.find((f) => f.includes('fresh'))).toBeDefined();
   });
 
   test('handles circular references in data', () => {
+    initLogger('session1');
     const circular: any = { name: 'test' };
     circular.self = circular;
 
-    // JSON.stringify will throw on circular references
-    // The logger should handle this gracefully (catch block)
-    expect(() => {
-      log('circular data', circular);
-    }).not.toThrow();
+    expect(() => log('circular data', circular)).not.toThrow();
+
+    const logPath = path.join(tmpDir, 'oh-my-opencode-slim.session1.log');
+    const content = fs.readFileSync(logPath, 'utf-8');
+    expect(content).toContain('circular data');
+    expect(content).toContain('[unserializable]');
+  });
+
+  test('getLogDir returns OPENCODE_LOG_DIR when set', () => {
+    expect(getLogDir()).toBe(tmpDir);
+  });
+
+  test('getLogDir falls back to os.homedir when env not set', () => {
+    delete process.env.OPENCODE_LOG_DIR;
+    try {
+      expect(getLogDir()).toBe(
+        path.join(os.homedir(), '.local/share/opencode'),
+      );
+    } finally {
+      if (origLogDir === undefined) {
+        delete process.env.OPENCODE_LOG_DIR;
+      } else {
+        process.env.OPENCODE_LOG_DIR = origLogDir;
+      }
+    }
+  });
+
+  test('handles complex data structures', () => {
+    initLogger('session1');
+    log('complex data', {
+      nested: { deep: { value: 'test' } },
+      array: [1, 2, 3],
+      boolean: true,
+      null: null,
+    });
+
+    const logPath = path.join(tmpDir, 'oh-my-opencode-slim.session1.log');
+    const content = fs.readFileSync(logPath, 'utf-8');
+    expect(content).toContain('"nested":');
+    expect(content).toContain('"array":[1,2,3]');
+    expect(content).toContain('"boolean":true');
   });
 });

+ 61 - 11
src/utils/logger.ts

@@ -2,22 +2,72 @@ import * as fs from 'node:fs';
 import * as os from 'node:os';
 import * as path from 'node:path';
 
-const logFile = path.join(
-  process.env.HOME || os.tmpdir(),
-  '.local/share/opencode/oh-my-opencode-slim.log',
-);
-
-// Ensure directory exists
-try {
-  fs.mkdirSync(path.dirname(logFile), { recursive: true });
-} catch {
-  // Ignore
+const LOG_PREFIX = 'oh-my-opencode-slim.';
+const LOG_SUFFIX = '.log';
+const RETENTION_MS = 7 * 24 * 60 * 60 * 1000; // 7 days
+
+let logFile: string | null = null;
+
+function getLogDir(): string {
+  return (
+    process.env.OPENCODE_LOG_DIR ??
+    path.join(os.homedir(), '.local/share/opencode')
+  );
+}
+
+function cleanupOldLogs(logDir: string): void {
+  try {
+    const entries = fs.readdirSync(logDir);
+    const now = Date.now();
+    for (const entry of entries) {
+      if (entry.startsWith(LOG_PREFIX) && entry.endsWith(LOG_SUFFIX)) {
+        const filePath = path.join(logDir, entry);
+        try {
+          const stat = fs.statSync(filePath);
+          if (now - stat.mtimeMs > RETENTION_MS) {
+            fs.unlinkSync(filePath);
+          }
+        } catch {
+          // Skip individual file errors
+        }
+      }
+    }
+  } catch {
+    // Directory may not exist yet — that's fine
+  }
 }
 
+export function initLogger(sessionId: string): void {
+  const dir = getLogDir();
+  try {
+    fs.mkdirSync(dir, { recursive: true });
+  } catch {
+    // Directory creation failed — logging will silently fail
+  }
+  logFile = path.join(dir, `${LOG_PREFIX}${sessionId}${LOG_SUFFIX}`);
+  cleanupOldLogs(dir);
+}
+
+/** @internal Reset logger state for testing */
+export function resetLogger(): void {
+  logFile = null;
+}
+
+export { getLogDir };
+
 export function log(message: string, data?: unknown): void {
+  if (!logFile) return; // Uninitialized — silently no-op
   try {
     const timestamp = new Date().toISOString();
-    const logEntry = `[${timestamp}] ${message} ${data ? JSON.stringify(data) : ''}\n`;
+    let dataStr = '';
+    if (data !== undefined) {
+      try {
+        dataStr = JSON.stringify(data);
+      } catch {
+        dataStr = '[unserializable]';
+      }
+    }
+    const logEntry = `[${timestamp}] ${message} ${dataStr}\n`;
     fs.appendFileSync(logFile, logEntry);
   } catch {
     // Silently ignore logging errors