1  /**
  2   * Pipeline Status Monitor — Supplement
  3   *
  4   * Covers branches not hit by the main test:
  5   * - Lines 108-119: checkServices — cron service stuck in "activating" state
  6   * - Lines 214-241: checkBrowserLoopHung — hung browser loop (restart) + healthy path
  7   * - Lines 257-258: recentErrors — statSync failure returns false
  8   * - Lines 280-282: recentErrors — outer catch when readdirSync fails
  9   * - Lines 432-451: checkSchemaIntegrity — site_status table CHECK constraint failures
 10   * - Lines 761-762: runPipelineStatusMonitor — schema warning pushed to allActions
 11   * - Lines 777-778: runPipelineStatusMonitor — snapshot writeFileSync failure (catch)
 12   * - Lines 813-826: runPipelineStatusMonitor — LLM cost variance alerts
 13   * - Lines 859-868: CLI entry point (import.meta.url guard)
 14   *
 15   * MUST be run with --experimental-test-module-mocks.
 16   */
 17  
 18  import { test, describe, mock, beforeEach } from 'node:test';
 19  import assert from 'node:assert/strict';
 20  
 21  // ═══════════════════════════════════════════════════════════════
 22  // Mock setup — all mocks BEFORE importing the module under test
 23  // ═══════════════════════════════════════════════════════════════
 24  
 25  mock.module('dotenv', {
 26    defaultExport: { config: () => {} },
 27    namedExports: { config: () => {} },
 28  });
 29  
 30  const execSyncMock = mock.fn(() => 'active\n');
 31  mock.module('child_process', {
 32    namedExports: { execSync: execSyncMock },
 33  });
 34  
 35  let capturedAppendCalls = [];
 36  let capturedWriteCalls = [];
 37  let mockFileContents = {};
 38  let mockExistsResults = {};
 39  let mockReaddirResults = {};
 40  let mockStatResults = {};
 41  let appendShouldFail = false;
 42  let writeFileSyncShouldFail = false;
 43  
 44  const appendFileSyncMock = mock.fn((path, content) => {
 45    if (appendShouldFail) {
 46      appendShouldFail = false;
 47      throw new Error('ENOENT: no such file or directory');
 48    }
 49    capturedAppendCalls.push({ path, content });
 50  });
 51  
 52  const readFileSyncMock = mock.fn((path, _encoding) => {
 53    if (mockFileContents[path] !== undefined) return mockFileContents[path];
 54    for (const [key, val] of Object.entries(mockFileContents)) {
 55      if (path.includes(key)) return val;
 56    }
 57    throw new Error(`ENOENT: no such file: ${path}`);
 58  });
 59  
 60  const writeFileSyncMock = mock.fn((path, content) => {
 61    if (writeFileSyncShouldFail) {
 62      throw new Error('EROFS: read-only file system');
 63    }
 64    capturedWriteCalls.push({ path, content });
 65  });
 66  
 67  const existsSyncMock = mock.fn(path => {
 68    for (const [key, val] of Object.entries(mockExistsResults)) {
 69      if (path.includes(key)) return val;
 70    }
 71    return false;
 72  });
 73  
 74  const readdirSyncMock = mock.fn(path => {
 75    if (readdirSyncShouldFail) {
 76      throw new Error('EACCES: permission denied');
 77    }
 78    if (readdirSyncFailAfterCalls >= 0 && readdirSyncCallCount >= readdirSyncFailAfterCalls) {
 79      readdirSyncCallCount++;
 80      throw new Error('EACCES: permission denied');
 81    }
 82    readdirSyncCallCount++;
 83    for (const [key, val] of Object.entries(mockReaddirResults)) {
 84      if (path.includes(key)) return val;
 85    }
 86    return [];
 87  });
 88  
 89  const statSyncMock = mock.fn(path => {
 90    for (const [key, val] of Object.entries(mockStatResults)) {
 91      if (path.includes(key)) return val;
 92    }
 93    return { mtimeMs: Date.now() };
 94  });
 95  
 96  const mkdirSyncMock = mock.fn(() => {});
 97  
 98  let readdirSyncShouldFail = false;
 99  let readdirSyncFailAfterCalls = -1; // -1 = disabled; N = fail on Nth call (0-indexed)
100  let readdirSyncCallCount = 0;
101  
102  mock.module('fs', {
103    namedExports: {
104      appendFileSync: appendFileSyncMock,
105      readFileSync: readFileSyncMock,
106      writeFileSync: writeFileSyncMock,
107      existsSync: existsSyncMock,
108      readdirSync: readdirSyncMock,
109      statSync: statSyncMock,
110      mkdirSync: mkdirSyncMock,
111    },
112  });
113  
114  // ── Mock better-sqlite3 with configurable browser loop data ──────────────────
115  
116  let mockBrowserLoopRow = null; // null = no row returned
117  let schemaRunShouldThrowFor = null; // set to 'sites' or 'site_status' to throw CHECK constraint
118  
119  class MockStatement {
120    constructor(sql) {
121      this.sql = sql;
122    }
123  
124    all() {
125      if (
126        this.sql.includes('FROM sites') &&
127        this.sql.includes('GROUP BY status') &&
128        !this.sql.includes('updated_at')
129      ) {
130        return [];
131      }
132      if (this.sql.includes('FROM sites') && this.sql.includes('updated_at')) {
133        return [];
134      }
135      if (this.sql.includes('FROM agent_tasks') && this.sql.includes('assigned_to')) {
136        return [];
137      }
138      if (this.sql.includes('FROM agent_tasks') && this.sql.includes('GROUP BY status')) {
139        return [];
140      }
141      return [];
142    }
143  
144    get() {
145      if (this.sql.includes('last_browser_loop_at')) {
146        return mockBrowserLoopRow;
147      }
148      if (this.sql.includes('COUNT(*)') && this.sql.includes('4 hours')) {
149        return { cnt: 0 };
150      }
151      return { cnt: 0 };
152    }
153  
154    run() {
155      // Simulate CHECK constraint failure for schema integrity tests
156      if (schemaRunShouldThrowFor) {
157        if (
158          (schemaRunShouldThrowFor === 'sites' && this.sql.includes('UPDATE sites')) ||
159          (schemaRunShouldThrowFor === 'site_status' && this.sql.includes('UPDATE site_status'))
160        ) {
161          throw new Error('CHECK constraint failed: status IN (...)');
162        }
163      }
164      return { changes: 0, lastInsertRowid: 0 };
165    }
166  }
167  
168  class MockDatabase {
169    constructor() {}
170    pragma() {}
171    prepare(sql) {
172      return new MockStatement(sql);
173    }
174    close() {}
175  }
176  
177  mock.module('better-sqlite3', {
178    defaultExport: MockDatabase,
179  });
180  
181  // ── Mock db.js to route queries through the same mock logic ─────────────────
182  // pipeline-status-monitor.js uses db.js (getOne/getAll/run), not better-sqlite3 directly.
183  
184  mock.module('../../src/utils/db.js', {
185    namedExports: {
186      getOne: async (sql, _params = []) => {
187        if (sql.includes('last_browser_loop_at')) return mockBrowserLoopRow;
188        if (sql.includes('COUNT(*)') && sql.includes('4 hours')) return { cnt: 0 };
189        return null;
190      },
191      getAll: async (sql, _params = []) => {
192        if (sql.includes('FROM sites') && sql.includes('GROUP BY status')) return [];
193        if (sql.includes('FROM sites') && sql.includes('updated_at')) return [];
194        if (sql.includes('FROM agent_tasks') && sql.includes('assigned_to')) return [];
195        if (sql.includes('FROM agent_tasks') && sql.includes('GROUP BY status')) return [];
196        if (sql.includes('llm_usage')) return [];
197        if (sql.includes('outreaches')) return [];
198        return [];
199      },
200      run: async (sql, _params = []) => {
201        if (schemaRunShouldThrowFor) {
202          if (schemaRunShouldThrowFor === 'sites' && sql.includes('UPDATE sites')) {
203            throw new Error('CHECK constraint failed: status IN (...)');
204          }
205          if (schemaRunShouldThrowFor === 'site_status' && sql.includes('UPDATE site_status')) {
206            throw new Error('CHECK constraint failed: status IN (...)');
207          }
208        }
209        return { changes: 0, rowCount: 0 };
210      },
211      query: async (_sql, _params = []) => ({ rows: [], rowCount: 0 }),
212      withTransaction: async fn => fn({ query: async () => ({ rows: [] }) }),
213      closePool: async () => {},
214      getPool: () => ({}),
215      createDatabaseConnection: () => ({}),
216      closeDatabaseConnection: async () => {},
217    },
218  });
219  
220  // ── Mock llm-usage-tracker for LLM cost variance tests ─────────────────────
221  
222  const checkBudgetVarianceMock = mock.fn(() => []);
223  
224  mock.module('../../src/utils/llm-usage-tracker.js', {
225    namedExports: {
226      checkBudgetVariance: checkBudgetVarianceMock,
227      logLLMUsage: mock.fn(() => {}),
228      getLLMBudget: mock.fn(() => null),
229    },
230  });
231  
232  // Import after all mocks
233  process.env.LOGS_DIR = '/tmp/test-logs';
234  process.env.DATABASE_PATH = '/tmp/test-psm-supp.db';
235  
236  const { runPipelineStatusMonitor } = await import('../../src/cron/pipeline-status-monitor.js');
237  
238  // ═══════════════════════════════════════════════════════════════
239  // Test suites
240  // ═══════════════════════════════════════════════════════════════
241  
242  beforeEach(() => {
243    execSyncMock.mock.resetCalls();
244    appendFileSyncMock.mock.resetCalls();
245    readFileSyncMock.mock.resetCalls();
246    writeFileSyncMock.mock.resetCalls();
247    existsSyncMock.mock.resetCalls();
248    readdirSyncMock.mock.resetCalls();
249    statSyncMock.mock.resetCalls();
250    mkdirSyncMock.mock.resetCalls();
251  
252    capturedAppendCalls = [];
253    capturedWriteCalls = [];
254    mockFileContents = {};
255    mockExistsResults = {};
256    mockReaddirResults = {};
257    mockStatResults = {};
258    appendShouldFail = false;
259    writeFileSyncShouldFail = false;
260    readdirSyncShouldFail = false;
261    readdirSyncFailAfterCalls = -1;
262    readdirSyncCallCount = 0;
263    mockBrowserLoopRow = null;
264    schemaRunShouldThrowFor = null;
265  
266    checkBudgetVarianceMock.mock.resetCalls();
267    checkBudgetVarianceMock.mock.mockImplementation(() => []);
268  
269    execSyncMock.mock.mockImplementation(cmd => {
270      if (cmd.includes('is-active')) return 'active\n';
271      if (cmd.includes('journalctl')) return '';
272      if (cmd.includes('ps --no-header')) return '0';
273      if (cmd.includes('show mmo-cron.service'))
274        return 'ActiveState=active\nStateChangeTimestamp=\n';
275      return '';
276    });
277  
278    mockReaddirResults['logs'] = [];
279    mockExistsResults['pipeline-status-snapshot.json'] = false;
280  });
281  
282  // ── Lines 108-119: cron service stuck in "activating" ────────────────────────
283  
284  describe('checkServices — cron stuck in activating (lines 108-119)', () => {
285    test('cron stuck in activating for >12min emits warning', async () => {
286      const fifteenMinAgo = new Date(Date.now() - 15 * 60 * 1000).toUTCString();
287  
288      execSyncMock.mock.mockImplementation(cmd => {
289        if (cmd.includes('show mmo-cron.service')) {
290          return `ActiveState=activating\nStateChangeTimestamp=${fifteenMinAgo}\n`;
291        }
292        if (cmd.includes('is-active')) return 'active\n';
293        if (cmd.includes('journalctl')) return '';
294        if (cmd.includes('ps --no-header')) return '0';
295        return '';
296      });
297  
298      await runPipelineStatusMonitor();
299  
300      const content = capturedAppendCalls[0]?.content || '';
301      assert.ok(
302        content.includes('Cron SERVICE stuck'),
303        `expected "Cron SERVICE stuck" in output, got: ${content.slice(0, 300)}`
304      );
305      assert.ok(content.includes('activating'), 'should mention activating state');
306    });
307  
308    test('cron activating but within 12min does NOT emit warning', async () => {
309      const fiveMinAgo = new Date(Date.now() - 5 * 60 * 1000).toUTCString();
310  
311      execSyncMock.mock.mockImplementation(cmd => {
312        if (cmd.includes('show mmo-cron.service')) {
313          return `ActiveState=activating\nStateChangeTimestamp=${fiveMinAgo}\n`;
314        }
315        if (cmd.includes('is-active')) return 'active\n';
316        if (cmd.includes('journalctl')) return '';
317        if (cmd.includes('ps --no-header')) return '0';
318        return '';
319      });
320  
321      await runPipelineStatusMonitor();
322  
323      const content = capturedAppendCalls[0]?.content || '';
324      assert.ok(
325        !content.includes('Cron SERVICE stuck'),
326        'should not warn when activating for only 5min'
327      );
328    });
329  
330    test('systemctl show failure is swallowed silently', async () => {
331      execSyncMock.mock.mockImplementation(cmd => {
332        if (cmd.includes('show mmo-cron.service')) {
333          throw new Error('D-Bus connection failure');
334        }
335        if (cmd.includes('is-active')) return 'active\n';
336        if (cmd.includes('journalctl')) return '';
337        if (cmd.includes('ps --no-header')) return '0';
338        return '';
339      });
340  
341      // Should not throw — the catch block swallows this
342      const result = await runPipelineStatusMonitor();
343      assert.ok(result, 'should still return a result');
344    });
345  });
346  
347  // ── Lines 214-241: checkBrowserLoopHung ──────────────────────────────────────
348  
349  describe('checkBrowserLoopHung (lines 214-241)', () => {
350    test('browser loop healthy: both cycles recent → reports active', async () => {
351      // Both browser and API cycle happened recently
352      const tenMinAgo = new Date(Date.now() - 10 * 60 * 1000)
353        .toISOString()
354        .replace('T', ' ')
355        .slice(0, 19);
356      mockBrowserLoopRow = {
357        last_browser_loop_at: tenMinAgo,
358        last_api_loop_at: tenMinAgo,
359      };
360  
361      await runPipelineStatusMonitor();
362  
363      const content = capturedAppendCalls[0]?.content || '';
364      assert.ok(
365        content.includes('browser_loop active'),
366        `expected "browser_loop active" in output, got: ${content.slice(0, 500)}`
367      );
368    });
369  
370    test('browser loop hung: stale browser + recent API → triggers restart', async () => {
371      const thirtyFiveMinAgo = new Date(Date.now() - 95 * 60 * 1000)
372        .toISOString()
373        .replace('T', ' ')
374        .slice(0, 19);
375      const fiveMinAgo = new Date(Date.now() - 5 * 60 * 1000)
376        .toISOString()
377        .replace('T', ' ')
378        .slice(0, 19);
379  
380      mockBrowserLoopRow = {
381        last_browser_loop_at: thirtyFiveMinAgo,
382        last_api_loop_at: fiveMinAgo,
383      };
384  
385      execSyncMock.mock.mockImplementation(cmd => {
386        if (cmd.includes('restart') && cmd.includes('333method-pipeline')) return 'ok\n';
387        if (cmd.includes('is-active')) return 'active\n';
388        if (cmd.includes('journalctl')) return '';
389        if (cmd.includes('ps --no-header')) return '0';
390        if (cmd.includes('show mmo-cron.service')) return 'ActiveState=active\n';
391        return '';
392      });
393  
394      const result = await runPipelineStatusMonitor();
395  
396      const content = capturedAppendCalls[0]?.content || '';
397      assert.ok(
398        content.includes('browser_loop stale'),
399        `expected "browser_loop stale" in output, got: ${content.slice(0, 500)}`
400      );
401      assert.ok(
402        result.actions.some(a => a.startsWith('restarted_hung_browser_loop')),
403        'should record browser loop restart action'
404      );
405    });
406  
407    test('browser loop hung: restart failure is logged', async () => {
408      const thirtyFiveMinAgo = new Date(Date.now() - 95 * 60 * 1000)
409        .toISOString()
410        .replace('T', ' ')
411        .slice(0, 19);
412      const fiveMinAgo = new Date(Date.now() - 5 * 60 * 1000)
413        .toISOString()
414        .replace('T', ' ')
415        .slice(0, 19);
416  
417      mockBrowserLoopRow = {
418        last_browser_loop_at: thirtyFiveMinAgo,
419        last_api_loop_at: fiveMinAgo,
420      };
421  
422      execSyncMock.mock.mockImplementation(cmd => {
423        if (cmd.includes('restart') && cmd.includes('333method-pipeline')) {
424          throw new Error('unit not found');
425        }
426        if (cmd.includes('is-active')) return 'active\n';
427        if (cmd.includes('journalctl')) return '';
428        if (cmd.includes('ps --no-header')) return '0';
429        if (cmd.includes('show mmo-cron.service')) return 'ActiveState=active\n';
430        return '';
431      });
432  
433      await runPipelineStatusMonitor();
434  
435      const content = capturedAppendCalls[0]?.content || '';
436      assert.ok(content.includes('Restart failed'), 'should report restart failure');
437      assert.ok(content.includes('unit not found'), 'should include error detail');
438    });
439  
440    test('browser loop: no timestamps in DB → reports no timestamps yet', async () => {
441      mockBrowserLoopRow = { last_browser_loop_at: null, last_api_loop_at: null };
442  
443      await runPipelineStatusMonitor();
444  
445      const content = capturedAppendCalls[0]?.content || '';
446      assert.ok(
447        content.includes('no timestamps yet'),
448        `expected "no timestamps yet" in output, got: ${content.slice(0, 300)}`
449      );
450    });
451  
452    test('browser loop: row is null → reports no timestamps yet', async () => {
453      mockBrowserLoopRow = null; // DB returns null (no row)
454  
455      await runPipelineStatusMonitor();
456  
457      const content = capturedAppendCalls[0]?.content || '';
458      assert.ok(
459        content.includes('no timestamps yet'),
460        `expected "no timestamps yet" in output, got: ${content.slice(0, 300)}`
461      );
462    });
463  });
464  
465  // ── Lines 257-258: recentErrors — statSync failure ────────────────────────────
466  
467  describe('recentErrors — statSync failure (lines 257-258)', () => {
468    test('statSync failure on log file causes it to be excluded', async () => {
469      // A log file exists but statSync throws for it
470      const realLog = 'pipeline-2026-03-07.log';
471      const badLog = 'unreadable-2026-03-07.log';
472  
473      mockReaddirResults['logs'] = [realLog, badLog];
474  
475      // statSync throws for the bad log, returns recent mtime for the real log
476      statSyncMock.mock.mockImplementation(path => {
477        if (path.includes('unreadable')) throw new Error('EACCES: permission denied');
478        return { mtimeMs: Date.now() - 2 * 60 * 1000 }; // 2 min ago
479      });
480  
481      mockFileContents[realLog] = '[2026-03-07] [ERROR] Real error in pipeline\n';
482  
483      await runPipelineStatusMonitor();
484  
485      const content = capturedAppendCalls[0]?.content || '';
486      // The bad log was filtered out (statSync threw → return false)
487      // The real log was included
488      assert.ok(
489        content.includes('Real error in pipeline'),
490        'should include errors from readable log'
491      );
492      // Should NOT throw despite one log being unreadable
493    });
494  });
495  
496  // ── Lines 280-282: recentErrors — outer catch ─────────────────────────────────
497  
498  describe('recentErrors — outer catch when readdirSync fails (lines 280-282)', () => {
499    test('readdirSync failure in recentErrors is caught and reported', async () => {
500      // checkPipelineHung calls readdirSync first (call 0, succeeds → returns [])
501      // recentErrors calls readdirSync second (call 1, throws)
502      readdirSyncFailAfterCalls = 1;
503      readdirSyncCallCount = 0;
504  
505      await runPipelineStatusMonitor();
506  
507      const content = capturedAppendCalls[0]?.content || '';
508      assert.ok(
509        content.includes('error reading logs'),
510        `expected "error reading logs" in output, got: ${content.slice(0, 400)}`
511      );
512      assert.ok(content.includes('permission denied'), 'should include error message');
513    });
514  });
515  
516  // ── Lines 432-451: checkSchemaIntegrity — site_status table ──────────────────
517  
518  describe('checkSchemaIntegrity — site_status table (lines 432-451)', () => {
519    test('site_status CHECK constraint failure triggers schema warning', async () => {
520      // sites table passes, but site_status table throws CHECK constraint error
521      schemaRunShouldThrowFor = 'site_status';
522  
523      await runPipelineStatusMonitor();
524  
525      const content = capturedAppendCalls[0]?.content || '';
526      assert.ok(
527        content.includes('SCHEMA MIGRATION MISSING'),
528        `expected "SCHEMA MIGRATION MISSING" in output, got: ${content.slice(0, 500)}`
529      );
530      assert.ok(content.includes('site_status.status'), 'should mention site_status table');
531    });
532  
533    test('sites CHECK constraint failure triggers schema warning for sites table', async () => {
534      schemaRunShouldThrowFor = 'sites';
535  
536      await runPipelineStatusMonitor();
537  
538      const content = capturedAppendCalls[0]?.content || '';
539      assert.ok(
540        content.includes('SCHEMA MIGRATION MISSING'),
541        `expected "SCHEMA MIGRATION MISSING" in output, got: ${content.slice(0, 500)}`
542      );
543      assert.ok(content.includes('sites.status'), 'should mention sites table');
544    });
545  
546    test('schema warning is pushed to allActions (lines 761-762)', async () => {
547      schemaRunShouldThrowFor = 'site_status';
548  
549      const result = await runPipelineStatusMonitor();
550  
551      assert.ok(
552        result.actions.some(a => a.includes('SCHEMA MIGRATION MISSING')),
553        'schema warning should be in allActions'
554      );
555      assert.ok(result.summary.includes('actions'), 'summary should mention actions');
556    });
557  });
558  
559  // ── Lines 777-778: snapshot writeFileSync failure ─────────────────────────────
560  
561  describe('snapshot writeFileSync failure (lines 777-778)', () => {
562    test('snapshot write failure is swallowed (non-fatal)', async () => {
563      writeFileSyncShouldFail = true;
564  
565      // Should not throw despite snapshot write failing
566      const result = await runPipelineStatusMonitor();
567      assert.ok(result, 'should still return a result when snapshot write fails');
568      // The status file append should still succeed (appendFileSync is separate)
569      assert.ok(capturedAppendCalls.length >= 1, 'should still write status file');
570    });
571  });
572  
573  // ── Lines 813-826: LLM cost variance alerts ───────────────────────────────────
574  
575  describe('LLM cost variance alerts (lines 813-826)', () => {
576    test('cost_variance type produces per-stage cost alert line', async () => {
577      checkBudgetVarianceMock.mock.mockImplementation(() => [
578        {
579          type: 'cost_variance',
580          stage: 'scoring',
581          avgCost: 0.0312,
582          expectedCost: 0.025,
583          maxCost: 0.04,
584          callCount: 47,
585        },
586      ]);
587  
588      await runPipelineStatusMonitor();
589  
590      const content = capturedAppendCalls[0]?.content || '';
591      assert.ok(content.includes('LLM COST ALERTS'), 'should show LLM cost alerts header');
592      assert.ok(content.includes('scoring'), 'should include stage name');
593      assert.ok(content.includes('0.0312'), 'should include avg cost');
594      assert.ok(content.includes('47 calls'), 'should include call count');
595    });
596  
597    test('model_mismatch type produces model mismatch alert line', async () => {
598      checkBudgetVarianceMock.mock.mockImplementation(() => [
599        {
600          type: 'model_mismatch',
601          stage: 'proposals',
602          actualModel: 'gpt-4o',
603          expectedModel: 'gpt-4o-mini',
604          callCount: 12,
605        },
606      ]);
607  
608      await runPipelineStatusMonitor();
609  
610      const content = capturedAppendCalls[0]?.content || '';
611      assert.ok(content.includes('LLM COST ALERTS'), 'should show LLM cost alerts header');
612      assert.ok(
613        content.includes('model_mismatch') || content.includes('gpt-4o'),
614        'should include model info'
615      );
616      assert.ok(content.includes('proposals'), 'should include stage name');
617    });
618  
619    test('no variances: LLM cost section is omitted', async () => {
620      checkBudgetVarianceMock.mock.mockImplementation(() => []);
621  
622      await runPipelineStatusMonitor();
623  
624      const content = capturedAppendCalls[0]?.content || '';
625      assert.ok(!content.includes('LLM COST ALERTS'), 'should omit section when no variances');
626    });
627  });