agenthub/tests/watchdog.test.ts

import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest';
import { mkdtempSync, rmSync } from 'fs';
import { tmpdir } from 'os';
import { join } from 'path';
import { init } from '../src/cli/commands/init.js';
import { loadConfig, saveConfig } from '../src/core/config.js';
import { createTask, claimTask, getTask, reviewTask } from '../src/core/services/taskService.js';
import { listMessages } from '../src/core/services/messageService.js';
import { readTaskLog, appendTaskLog } from '../src/core/services/taskLogService.js';
import { startWatchdog, resetWatchdog } from '../src/server/watchdog.js';
import { eventBus, type AgentHubEvent } from '../src/server/events.js';
import { enterLoop, leaveLoop, resetPresence } from '../src/core/services/presenceService.js';
import { createAsk } from '../src/core/services/askService.js';

/**
 * Watchdog thresholds (TSK-0226). Fake timers drive both the scan interval and
 * the task ages (Date is mocked, so createdAt/updatedAt advance with the clock).
 * Thresholds are shrunk via the `watchdog` config section to keep the test fast.
 */
describe('watchdog', () => {
  let cwd: string;
  let stop: (() => void) | undefined;
  let events: AgentHubEvent[];
  const onChange = (e: AgentHubEvent) => events.push(e);

  // Small thresholds: interval 1s, high-prio unclaimed 2s, default 5s, stale 4s.
  const INTERVAL = 1_000;
  const HIGH = 2_000;
  const DEFAULT = 5_000;
  const STALE = 4_000;
  const REVIEW = 3_000;
  const ASK = 4_000;

  beforeEach(() => {
    cwd = mkdtempSync(join(tmpdir(), 'ah-watchdog-'));
    init(cwd, { projectName: 'watchdog-test', yes: true });
    const config = loadConfig(cwd);
    config.watchdog = {
      enabled: true,
      intervalMs: INTERVAL,
      unclaimedHighMs: HIGH,
      unclaimedDefaultMs: DEFAULT,
      staleInProgressMs: STALE,
      pendingAskMs: ASK,
      staleReviewMs: REVIEW,
    };
    saveConfig(cwd, config);
    resetWatchdog();
    resetPresence();
    events = [];
    eventBus.on('change', onChange);
    vi.useFakeTimers();
  });

  afterEach(() => {
    stop?.();
    stop = undefined;
    eventBus.off('change', onChange);
    vi.useRealTimers();
    rmSync(cwd, { recursive: true, force: true });
  });

  const remindersFor = (agent: string) =>
    listMessages(cwd).filter((m) => m.to === agent && m.text.startsWith('Reminder:'));

  it('re-notifies an unclaimed high-priority task: SSE re-emit + unread reminder + warn log', async () => {
    createTask(cwd, { title: 'Urgent fix', priority: 'high', assignedTo: 'codex' });
    stop = startWatchdog(cwd);

    // Below the threshold: nothing happens.
    await vi.advanceTimersByTimeAsync(INTERVAL);
    expect(remindersFor('codex')).toHaveLength(0);

    // Past the 2s high-priority threshold (next tick at t=2s fires the alert).
    await vi.advanceTimersByTimeAsync(INTERVAL + 100);

    // 1. Reminder message lands as UNREAD so the assignee's work loop wakes.
    const reminders = remindersFor('codex');
    expect(reminders).toHaveLength(1);
    expect(reminders[0].status).toBe('unread');
    expect(reminders[0].text).toBe('Reminder: TSK-0001 wartet auf dich');
    expect(reminders[0].taskId).toBe('TSK-0001');

    // 2. The task event is re-emitted on the bus (SSE fan-out).
    expect(events.some((e) => e.type === 'task' && e.id === 'TSK-0001' && e.assignedTo === 'codex')).toBe(true);

    // 3. Board-visible warn line on the task's live console.
    const log = readTaskLog(cwd, 'TSK-0001');
    expect(log.some((l) => l.level === 'warn' && l.text.includes('Watchdog'))).toBe(true);
  });

  it('does not spam: re-alerts only after the threshold elapses again', async () => {
    createTask(cwd, { title: 'Urgent fix', priority: 'critical', assignedTo: 'codex' });
    stop = startWatchdog(cwd);

    await vi.advanceTimersByTimeAsync(HIGH + 100); // first alert at t≈2s
    expect(remindersFor('codex')).toHaveLength(1);

    // One more interval tick — still inside the cooldown window.
    await vi.advanceTimersByTimeAsync(INTERVAL);
    expect(remindersFor('codex')).toHaveLength(1);

    // The base threshold elapsing again is NO LONGER enough: after the first
    // reminder the gap doubles (see the backoff test below). Reminding at the
    // base interval forever is exactly what buried an agent under 1500+ unread
    // messages on 09.08., so the anti-spam guarantee this test is named for now
    // has to hold across the whole lifetime of an unclaimed task, not just for
    // one cooldown window.
    await vi.advanceTimersByTimeAsync(HIGH);
    expect(remindersFor('codex')).toHaveLength(1);

    // Only the doubled gap releases the second reminder.
    await vi.advanceTimersByTimeAsync(HIGH + INTERVAL);
    expect(remindersFor('codex')).toHaveLength(2);
  });

  it('uses the longer threshold for medium/low priority tasks', async () => {
    createTask(cwd, { title: 'Routine', priority: 'medium', assignedTo: 'kimi' });
    stop = startWatchdog(cwd);

    // Past the high-priority threshold but below the default one: no alert.
    await vi.advanceTimersByTimeAsync(HIGH + INTERVAL);
    expect(remindersFor('kimi')).toHaveLength(0);

    // Past the 5s default threshold.
    await vi.advanceTimersByTimeAsync(DEFAULT);
    expect(remindersFor('kimi')).toHaveLength(1);
  });

  it('alerts the architect when an assigned task targets an agent known to be out of the work loop', async () => {
    createTask(cwd, { title: 'Unheard task', priority: 'high', assignedTo: 'codex' });
    enterLoop('codex');
    leaveLoop('codex', 'client timeout');
    stop = startWatchdog(cwd);

    await vi.advanceTimersByTimeAsync(HIGH + 100);
    const alerts = listMessages(cwd).filter(
      (m) => m.to === 'claude' && m.text.includes('not in agenthub_work'),
    );
    expect(alerts).toHaveLength(1);
    expect(alerts[0].taskId).toBe('TSK-0001');
  });

  it('routes architect-dispatched agents to the architect once and never re-notifies the agent', async () => {
    const config = loadConfig(cwd);
    config.agents = {
      ...(config.agents ?? {}),
      claude: { role: 'architect', dispatch: 'loop' },
      backyard: { role: 'implementer', dispatch: 'architect' },
    };
    saveConfig(cwd, config);
    createTask(cwd, { title: 'Backend task', priority: 'high', assignedTo: 'backyard' });
    stop = startWatchdog(cwd);
    await vi.advanceTimersByTimeAsync(HIGH + 100);
    expect(remindersFor('backyard')).toHaveLength(0);
    const notices = () => listMessages(cwd).filter((m) => m.to === 'claude' && m.text.includes('wird von dir gestartet'));
    expect(notices()).toHaveLength(1);
    await vi.advanceTimersByTimeAsync(HIGH * 2);
    expect(notices()).toHaveLength(1);
  });

  it('alerts the architect about a silent in_progress task — without reassigning', async () => {
    createTask(cwd, { title: 'WIP', priority: 'high', assignedTo: 'kimi' });
    claimTask(cwd, 'TSK-0001', 'kimi');
    stop = startWatchdog(cwd);

    // No task-log lines at all; silent past the stale threshold.
    await vi.advanceTimersByTimeAsync(STALE + INTERVAL);

    // Architect (init default: claude) got the alert; the assignee got none.
    const architectAlerts = listMessages(cwd).filter((m) => m.to === 'claude' && m.text.startsWith('Watchdog:'));
    expect(architectAlerts).toHaveLength(1);
    expect(architectAlerts[0].status).toBe('unread');
    expect(architectAlerts[0].text).toContain('TSK-0001');
    expect(architectAlerts[0].text).toContain('silent');
    expect(remindersFor('kimi')).toHaveLength(0);

    // Visibility only: the task still belongs to kimi (no auto-reassign).
    const { task } = getTask(cwd, 'TSK-0001');
    expect(task.status).toBe('in_progress');
    expect(task.assignedTo).toBe('kimi');
    expect(task.claimedBy).toBe('kimi');
  });

  it('reports a pending Ask instead of misdiagnosing the waiting agent as merely silent', async () => {
    createTask(cwd, { title: 'Blocked WIP', priority: 'high', assignedTo: 'windows-claude' });
    claimTask(cwd, 'TSK-0001', 'windows-claude');
    createAsk(cwd, {
      from: 'windows-claude',
      to: 'claude',
      taskId: 'TSK-0001',
      question: 'May I commit the finished build?',
    });
    stop = startWatchdog(cwd);

    await vi.advanceTimersByTimeAsync(ASK + INTERVAL);

    const architectAlerts = listMessages(cwd).filter(
      (m) => m.to === 'claude' && m.text.startsWith('Watchdog'),
    );
    expect(architectAlerts).toHaveLength(1);
    expect(architectAlerts[0].text).toContain('ASK-0001');
    expect(architectAlerts[0].text).toContain('wartet seit');
    expect(architectAlerts[0].text).not.toContain('no auto-reassign');
  });

  it('a fresh task-log line keeps an in_progress task from being flagged stale', async () => {
    createTask(cwd, { title: 'Chatty WIP', priority: 'high', assignedTo: 'kimi' });
    claimTask(cwd, 'TSK-0001', 'kimi');
    stop = startWatchdog(cwd);

    // Log activity well inside the stale window, repeatedly: never flagged.
    for (let i = 0; i < 4; i++) {
      await vi.advanceTimersByTimeAsync(STALE - 2 * INTERVAL); // 2s < 4s stale window
      appendTaskLog(cwd, 'TSK-0001', { text: `progress ${i}`, agent: 'kimi' });
    }
    expect(listMessages(cwd).filter((m) => m.text.startsWith('Watchdog:'))).toHaveLength(0);
  });

  it('never writes reminders into the mailbox of an agent that left the work loop', async () => {
    // The 09.08. incident: the hub kept reminding an agent it KNEW was not
    // consuming mail. 1500+ unread messages later its own work loop could no
    // longer start. The alarm disabled the recipient — worse than no alarm.
    createTask(cwd, { title: 'Urgent fix', priority: 'high', assignedTo: 'codex' });
    enterLoop('codex');
    leaveLoop('codex'); // → agentLoopStatus === 'inactive' (provably not reading)
    stop = startWatchdog(cwd);

    // Many scans, far past the threshold.
    await vi.advanceTimersByTimeAsync(HIGH * 12);

    // 1. Not a single durable reminder in the unreachable mailbox.
    expect(remindersFor('codex')).toHaveLength(0);

    // 2. The architect is told — but exactly ONCE, no matter how long it runs.
    const architectAlerts = listMessages(cwd).filter(
      (m) => m.to === 'claude' && m.text.includes('not in agenthub_work'),
    );
    expect(architectAlerts).toHaveLength(1);
    expect(architectAlerts[0].taskId).toBe('TSK-0001');

    // 3. The ephemeral SSE re-emit still happens — it costs nothing and may
    //    catch the agent mid-reconnect.
    expect(events.some((e) => e.type === 'task' && e.id === 'TSK-0001')).toBe(true);
  });

  it('backs off exponentially instead of reminding at the base interval forever', async () => {
    createTask(cwd, { title: 'Urgent fix', priority: 'high', assignedTo: 'codex' });
    enterLoop('codex'); // reachable — reminders are legitimate here
    stop = startWatchdog(cwd);

    // First reminder at the base threshold, unchanged behaviour.
    await vi.advanceTimersByTimeAsync(HIGH + INTERVAL);
    expect(remindersFor('codex')).toHaveLength(1);

    // Another base interval must NOT produce a second one — the gap doubled.
    await vi.advanceTimersByTimeAsync(HIGH);
    expect(remindersFor('codex')).toHaveLength(1);

    // Once the doubled gap has elapsed, the second reminder arrives.
    await vi.advanceTimersByTimeAsync(HIGH + INTERVAL);
    expect(remindersFor('codex')).toHaveLength(2);
  });

  it('resets the backoff once the task is claimed', async () => {
    createTask(cwd, { title: 'Urgent fix', priority: 'high', assignedTo: 'codex' });
    enterLoop('codex');
    stop = startWatchdog(cwd);
    await vi.advanceTimersByTimeAsync(HIGH + INTERVAL);
    expect(remindersFor('codex')).toHaveLength(1);

    // Claiming clears the per-task state, so a later re-open starts fresh
    // instead of inheriting a half-muted, backed-off cooldown.
    claimTask(cwd, 'TSK-0001', 'codex');
    await vi.advanceTimersByTimeAsync(HIGH + INTERVAL);
    expect(getTask(cwd, 'TSK-0001').task.status).toBe('in_progress');
    expect(remindersFor('codex')).toHaveLength(1); // claimed ⇒ no further reminders
  });

  it('alerts the architect when a review waits too long', async () => {
    createTask(cwd, { title: 'Review me', assignedTo: 'kimi' });
    claimTask(cwd, 'TSK-0001', 'kimi');
    reviewTask(cwd, 'TSK-0001');
    stop = startWatchdog(cwd);

    await vi.advanceTimersByTimeAsync(REVIEW + INTERVAL);
    const alerts = listMessages(cwd).filter(
      (m) => m.to === 'claude' && m.text.includes('waited in review'),
    );
    expect(alerts).toHaveLength(1);
    expect(alerts[0].taskId).toBe('TSK-0001');
  });
});