flynn/src/audit/logger.test.ts

import { existsSync, mkdtempSync, readFileSync, rmSync } from 'fs';
import { homedir, tmpdir } from 'os';
import { join, resolve } from 'path';
import { describe, expect, it } from 'vitest';
import { AuditLogger } from './logger.js';

function waitForFlush(): Promise<void> {
  return new Promise((resolvePromise) => setTimeout(resolvePromise, 25));
}

function readAuditEvents(filePath: string): Array<{ event_type: string; level: string; event: Record<string, unknown> }> {
  const content = readFileSync(filePath, 'utf-8').trim();
  if (!content) {
    return [];
  }
  return content
    .split('\n')
    .map((line) => JSON.parse(line) as { event_type: string; level: string; event: Record<string, unknown> });
}

describe('AuditLogger', () => {
  it('expands ~ in audit path before writing logs', async () => {
    const previousHome = process.env.HOME;
    const tempHome = mkdtempSync(join(tmpdir(), 'flynn-audit-home-'));
    process.env.HOME = tempHome;

    try {
      // Sanity-check this process sees the temp home.
      expect(homedir()).toBe(tempHome);

      const logger = new AuditLogger({
        enabled: true,
        path: '~/.local/share/flynn/audit.log',
        max_size_mb: 10,
        keep_days: 30,
        levels: {
          tools: 'debug',
          sessions: 'debug',
          automation: 'debug',
        },
      });

      logger.systemStart('test-component');
      await logger.close();
      await waitForFlush();

      const loggerPath = (logger as unknown as { config: { path: string } }).config.path;
      const expectedPath = resolve(tempHome, '.local/share/flynn/audit.log');
      expect(loggerPath).toBe(expectedPath);
      expect(existsSync(expectedPath)).toBe(true);
      const content = readFileSync(expectedPath, 'utf-8');
      expect(content).toContain('"event_type":"system.start"');
      expect(content).toContain('"component":"test-component"');
    } finally {
      if (previousHome === undefined) {
        delete process.env.HOME;
      } else {
        process.env.HOME = previousHome;
      }
      rmSync(tempHome, { recursive: true, force: true });
    }
  });

  it('writes run and reaction baseline events with expected levels', async () => {
    const previousHome = process.env.HOME;
    const tempHome = mkdtempSync(join(tmpdir(), 'flynn-audit-home-'));
    process.env.HOME = tempHome;

    try {
      const logger = new AuditLogger({
        enabled: true,
        path: '~/.local/share/flynn/audit.log',
        max_size_mb: 10,
        keep_days: 30,
        levels: {
          tools: 'debug',
          sessions: 'debug',
          automation: 'debug',
        },
      });

      logger.runState({
        session_id: 'telegram:123',
        channel: 'telegram',
        sender: '123',
        source: 'channel',
        state: 'start',
        request_id: 'req-1',
      });
      logger.runState({
        session_id: 'telegram:123',
        channel: 'telegram',
        sender: '123',
        source: 'channel',
        state: 'error',
        request_id: 'req-1',
        error: 'model timeout',
      });
      logger.runCancel({
        session_id: 'telegram:123',
        channel: 'telegram',
        sender: '123',
        source: 'channel',
        requested: true,
        acknowledged: true,
        request_id: 'req-1',
        latency_ms: 120,
      });
      logger.reactionMatch({
        session_id: 'telegram:123',
        channel: 'telegram',
        sender: '123',
        source: 'channel',
        rule_name: 'daily-briefing-hint',
        candidate_count: 4,
        filter_summary: 'contains:briefing',
      });
      logger.reactionSkip({
        session_id: 'telegram:123',
        channel: 'telegram',
        sender: '123',
        source: 'channel',
        reason: 'no_match',
        candidate_count: 4,
      });
      logger.subagentLifecycle({
        parent_session_id: 'telegram:123',
        subagent_id: 'planner',
        trace_id: 'trace-planner',
        action: 'spawn',
        agent: 'research',
        tier: 'complex',
        queue_mode: 'followup',
        tool_profile: 'minimal',
      });
      logger.subagentTurn({
        parent_session_id: 'telegram:123',
        subagent_id: 'planner',
        trace_id: 'trace-planner',
        action: 'complete',
        queue_mode: 'followup',
        duration_ms: 88,
        input_chars: 42,
        output_chars: 120,
      });

      await logger.close();
      await waitForFlush();

      const expectedPath = resolve(tempHome, '.local/share/flynn/audit.log');
      const events = readAuditEvents(expectedPath);
      const eventTypes = events.map((event) => event.event_type);

      expect(eventTypes).toContain('run.state');
      expect(eventTypes).toContain('run.cancel');
      expect(eventTypes).toContain('reaction.match');
      expect(eventTypes).toContain('reaction.skip');
      expect(eventTypes).toContain('subagent.lifecycle');
      expect(eventTypes).toContain('subagent.turn');

      const runError = events.find((event) => (
        event.event_type === 'run.state'
        && event.event.state === 'error'
      ));
      expect(runError?.level).toBe('error');

      const reactionSkip = events.find((event) => event.event_type === 'reaction.skip');
      expect(reactionSkip?.level).toBe('debug');
      expect(reactionSkip?.event.reason).toBe('no_match');

      const subagentLifecycle = events.find((event) => event.event_type === 'subagent.lifecycle');
      expect(subagentLifecycle?.level).toBe('info');
      expect(subagentLifecycle?.event.action).toBe('spawn');
    } finally {
      if (previousHome === undefined) {
        delete process.env.HOME;
      } else {
        process.env.HOME = previousHome;
      }
      rmSync(tempHome, { recursive: true, force: true });
    }
  });
});