v0.42.18.0 fix: sync orphan-pileup watchdog (#1633) + links-lag µs stamp (#1768) (#1807)

* fix(extract): links_extraction_lag never clears on Postgres (#1768) Stamp the full-microsecond updated_at (via to_char ... AT TIME ZONE UTC) instead of the millisecond-truncated JS Date, so links_extracted_at equals the DB updated_at exactly and the staleness predicate clears. Stamp SQL unchanged: version-arm backdating still works, D4 preserved, CDX-1 strengthened. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * feat(core): out-of-band hard-deadline watchdog primitive (#1633) Bun eval-Worker that SIGTERM->grace->SIGKILLs its own process from a separate OS thread, so a sync whose main event loop is starved (ReDoS spin) still dies. Signals SELF (no PID-reuse footgun). Empirically validated on Bun 1.3.13. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * fix(sync): arm hard-deadline watchdog + graceful SIGINT cancel (#1633) cli.ts installs the watchdog before connectEngine (bounds connect hangs); resolveSyncHardDeadline + composeAbortSignals in sync.ts; SIGINT graceful cancel on single-source + --all; withRefreshingLock timer unref'd. Non-TTY default 3600s makes cron orphan-pileup structurally impossible. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * docs(claude): annotate process-watchdog + #1768/#1633 fixes Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * chore: bump version and changelog (v0.42.13.0) Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * chore: rebump v0.42.13.0 -> v0.42.18.0 (queue collision) Sibling workspaces claimed v0.42.13-v0.42.17; advance this branch's slot. VERSION + package.json + CHANGELOG header + CLAUDE.md annotations + llms bundles. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * docs(key-files): current-state phrasing for #1633/#1768 entries (fix check:doc-history) The doc-history guard bans the bolded **v0.X release-clause marker in reference docs (history belongs in CHANGELOG + git). Rewrote the extract.ts/sync.ts additions as current-state prose and de-versioned the process-watchdog entry. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-07-27 22:15:33 +00:00 · 2026-06-03 08:00:57 -07:00
parent fd2fde9d26
commit bde11bb18f
18 changed files with 655 additions and 9 deletions
@@ -178,6 +178,37 @@ describe('gbrain extract --stale', () => {
    expect(await engine.countStalePagesForExtraction({ versionTs: LINK_EXTRACTOR_VERSION_TS })).toBe(0);
  });

+  test('CRITICAL (#1768): microsecond updated_at clears after --stale (no permanent lag)', async () => {
+    // Repro of #1768: extractStaleFromDB used to stamp page.updated_at.toISOString()
+    // (a JS Date, millisecond-truncated). The DB updated_at keeps microseconds, so
+    // `updated_at > links_extracted_at` stayed true forever and links_extraction_lag
+    // was stuck at 100% on Postgres. We inject a microsecond updated_at explicitly so
+    // the precision gap is deterministic regardless of the engine's now() granularity.
+    await engine.putPage('people/alice', personPage('Alice'));
+    await engine.putPage('companies/acme', companyPage('Acme', '[Alice](people/alice) advises [Acme](companies/acme).'));
+    // Microsecond-precision updated_at, recent (after LINK_EXTRACTOR_VERSION_TS) so the
+    // version arm doesn't fire — the edited arm is what must clear.
+    await engine.executeRaw(`UPDATE pages SET updated_at = '2026-06-02 08:18:58.999166+00'`);
+    expect(await engine.countStalePagesForExtraction({ versionTs: LINK_EXTRACTOR_VERSION_TS })).toBe(2);
+
+    await runExtract(engine, ['--stale']);
+    // Fixed: links_extracted_at stamped at the EXACT microsecond updated_at, so the
+    // edited arm clears. Pre-fix this stayed at 2 (the bug).
+    expect(await engine.countStalePagesForExtraction({ versionTs: LINK_EXTRACTOR_VERSION_TS })).toBe(0);
+
+    // And it stays cleared on a re-run (the "no matter how many times I re-run" symptom).
+    await runExtract(engine, ['--stale']);
+    expect(await engine.countStalePagesForExtraction({ versionTs: LINK_EXTRACTOR_VERSION_TS })).toBe(0);
+
+    // The stamp itself carries microsecond precision (not millisecond-truncated).
+    const stamp = await stampOf('companies/acme');
+    expect(stamp).not.toBeNull();
+    const usRows = await engine.executeRaw<{ eq: boolean }>(
+      `SELECT links_extracted_at >= updated_at AS eq FROM pages WHERE slug = 'companies/acme'`,
+    );
+    expect(usRows[0]?.eq).toBe(true);
+  });
+
  test('CDX-4 (D2): a link-flush throw aborts the sweep and leaves pages UNSTAMPED', async () => {
    await engine.putPage('people/alice', personPage('Alice'));
    await engine.putPage('companies/acme', companyPage('Acme', '[Alice](people/alice) founded [Acme](companies/acme).'));
@@ -0,0 +1,33 @@
+/**
+ * Fixture for test/process-watchdog.serial.test.ts. Spawned via `bun`.
+ *
+ * Usage: bun watchdog-harness.ts <mode> <deadlineMs> <graceMs>
+ *   starve-with    — install the watchdog, then starve the event loop forever.
+ *                    The watchdog must SIGKILL this process by deadline+grace.
+ *   starve-without — no watchdog, just starve. Proves the busy loop truly hangs
+ *                    (the test kills it). Isolates the watchdog as cause of death.
+ *   clean-dispose  — install with a long deadline, dispose immediately, exit 0.
+ *                    The watchdog must NOT kill a cleanly-disposed process.
+ *
+ * Safety net: the busy loop self-exits after 8s so a failed test kill can't hang CI.
+ */
+import { installProcessWatchdog } from '../../src/core/process-watchdog.ts';
+
+const mode = process.argv[2] ?? 'starve-with';
+const deadlineMs = Number(process.argv[3] ?? 300);
+const graceMs = Number(process.argv[4] ?? 150);
+
+if (mode === 'starve-with' || mode === 'clean-dispose') {
+  const handle = installProcessWatchdog({ deadlineMs, graceMs, label: 'test-wd' });
+  if (mode === 'clean-dispose') {
+    handle.dispose();
+    process.stdout.write('DISPOSED\n');
+    process.exit(0);
+  }
+}
+
+// Starve the main event loop with a synchronous busy loop (simulates ReDoS).
+const start = Date.now();
+while (Date.now() - start < 8000) { /* spin — no await, no yield */ }
+process.stdout.write('SURVIVED\n'); // must NOT print under starve-with
+process.exit(0);
@@ -0,0 +1,67 @@
+/**
+ * Bun-pinned integration for the out-of-band watchdog (#1633, plan A4).
+ *
+ * Bun's worker_threads Worker is flagged "experimental", and the whole #1633
+ * fix rests on a worker timer firing + SIGKILLing the process while the MAIN
+ * thread is starved by a synchronous loop. These tests spawn a real harness
+ * process that starves its own loop and assert the watchdog kills it anyway.
+ *
+ * Serial because they use real subprocesses + wall-clock timing.
+ */
+import { describe, test, expect } from 'bun:test';
+import { join } from 'node:path';
+
+const HARNESS = join(import.meta.dir, 'fixtures', 'watchdog-harness.ts');
+
+async function runHarness(
+  mode: string,
+  deadlineMs: number,
+  graceMs: number,
+  hardCapMs: number,
+): Promise<{ exitCode: number | null; signalled: boolean; elapsedMs: number; stdout: string; killedByTest: boolean }> {
+  const proc = Bun.spawn(['bun', HARNESS, mode, String(deadlineMs), String(graceMs)], {
+    stdout: 'pipe',
+    stderr: 'pipe',
+  });
+  const start = Date.now();
+  let killedByTest = false;
+  const cap = setTimeout(() => { killedByTest = true; proc.kill('SIGKILL'); }, hardCapMs);
+  await proc.exited;
+  clearTimeout(cap);
+  const elapsedMs = Date.now() - start;
+  const stdout = await new Response(proc.stdout).text();
+  // Bun surfaces signal death via exitCode === null + signalCode, or a negative
+  // exitCode on some platforms. Treat "not a clean 0" as signalled for our purpose.
+  const signalled = proc.exitCode !== 0;
+  return { exitCode: proc.exitCode, signalled, elapsedMs, stdout, killedByTest };
+}
+
+describe('process-watchdog integration (Bun-pinned)', () => {
+  test('starved process IS killed by the watchdog around deadline+grace', async () => {
+    // deadline 300 + grace 200 = ~500ms expected death. Hard cap 4s: if the
+    // watchdog failed, the test's own SIGKILL fires and the assertion catches it.
+    const r = await runHarness('starve-with', 300, 200, 4000);
+    expect(r.stdout).not.toContain('SURVIVED'); // the bug symptom
+    expect(r.killedByTest).toBe(false);          // watchdog, not the test, killed it
+    expect(r.signalled).toBe(true);
+    // Died well before the harness's 8s self-exit safety net, near deadline+grace.
+    expect(r.elapsedMs).toBeLessThan(3000);
+  }, 15000);
+
+  test('control: a starved process WITHOUT the watchdog does not self-exit', async () => {
+    // Proves the busy loop genuinely starves (so the death above is the watchdog).
+    // No watchdog installed; the test's hard cap (1.2s) is what kills it.
+    const r = await runHarness('starve-without', 300, 200, 1200);
+    expect(r.killedByTest).toBe(true);   // only the test's SIGKILL stopped it
+    expect(r.stdout).not.toContain('SURVIVED');
+  }, 15000);
+
+  test('clean dispose: a disposed watchdog never kills the process', async () => {
+    // Long deadline, disposed immediately, process exits 0 fast and prints DISPOSED.
+    const r = await runHarness('clean-dispose', 60000, 60000, 5000);
+    expect(r.exitCode).toBe(0);
+    expect(r.killedByTest).toBe(false);
+    expect(r.stdout).toContain('DISPOSED');
+    expect(r.elapsedMs).toBeLessThan(4000);
+  }, 15000);
+});
@@ -0,0 +1,61 @@
+/**
+ * Pure-function coverage for the watchdog state machine (#1633). No threads, no
+ * real timers — the spawn-based integration lives in
+ * test/process-watchdog.serial.test.ts (Bun-pinned, real processes).
+ */
+import { describe, test, expect } from 'bun:test';
+import { watchdogDecision, installProcessWatchdog } from '../src/core/process-watchdog.ts';
+
+describe('watchdogDecision', () => {
+  const deadline = 1000;
+  const grace = 300;
+
+  test('waits before the deadline', () => {
+    expect(watchdogDecision(0, deadline, grace)).toBe('wait');
+    expect(watchdogDecision(999, deadline, grace)).toBe('wait');
+  });
+
+  test('SIGTERM at the deadline boundary (inclusive)', () => {
+    expect(watchdogDecision(1000, deadline, grace)).toBe('sigterm');
+    expect(watchdogDecision(1299, deadline, grace)).toBe('sigterm');
+  });
+
+  test('SIGKILL at deadline+grace boundary (inclusive)', () => {
+    expect(watchdogDecision(1300, deadline, grace)).toBe('sigkill');
+    expect(watchdogDecision(5000, deadline, grace)).toBe('sigkill');
+  });
+
+  test('zero grace goes straight to SIGKILL at the deadline', () => {
+    expect(watchdogDecision(999, deadline, 0)).toBe('wait');
+    expect(watchdogDecision(1000, deadline, 0)).toBe('sigkill');
+  });
+});
+
+describe('installProcessWatchdog (handle contract)', () => {
+  test('non-positive deadline returns an inert no-op handle', () => {
+    const warns: string[] = [];
+    const h0 = installProcessWatchdog({ deadlineMs: 0, onWarn: (m) => warns.push(m) });
+    expect(h0.active).toBe(false);
+    h0.dispose(); // idempotent, no throw
+    const hNeg = installProcessWatchdog({ deadlineMs: -5, onWarn: (m) => warns.push(m) });
+    expect(hNeg.active).toBe(false);
+  });
+
+  test('active handle disposes idempotently without killing the test process', () => {
+    // Long deadline so it never fires during the test; dispose tears it down.
+    const h = installProcessWatchdog({ deadlineMs: 60_000, graceMs: 60_000, label: 'unit-wd' });
+    expect(h.active).toBe(true);
+    h.dispose();
+    expect(h.active).toBe(false);
+    h.dispose(); // second dispose is a no-op
+    expect(h.active).toBe(false);
+  });
+
+  test('label is sanitized to a safe charset', () => {
+    // A nasty label must not throw at construction (it is stripped before the
+    // inline worker string). We dispose immediately so nothing fires.
+    const h = installProcessWatchdog({ deadlineMs: 60_000, label: "evil'; \n process.exit(1) //" });
+    expect(h.active).toBe(true);
+    h.dispose();
+  });
+});
@@ -0,0 +1,90 @@
+/**
+ * #1633 wiring: resolveSyncHardDeadline precedence + composeAbortSignals.
+ * Pure (no engine, no env mutation — env is injected per-call).
+ */
+import { describe, test, expect } from 'bun:test';
+import {
+  resolveSyncHardDeadline,
+  composeAbortSignals,
+  HARD_DEADLINE_GRACE_SEC,
+} from '../src/commands/sync.ts';
+
+const GRACE_MS = HARD_DEADLINE_GRACE_SEC * 1000;
+
+describe('resolveSyncHardDeadline', () => {
+  test('--no-hard-deadline disables everything (even with --timeout)', () => {
+    const r = resolveSyncHardDeadline(['--source', 'x', '--timeout', '60', '--no-hard-deadline'], { isTty: false });
+    expect(r).toBeNull();
+  });
+
+  test('--hard-deadline wins and sets the deadline (with grace)', () => {
+    const r = resolveSyncHardDeadline(['--hard-deadline', '120'], { isTty: true });
+    expect(r).toEqual({ deadlineMs: 120_000, graceMs: GRACE_MS, reason: 'flag:--hard-deadline' });
+  });
+
+  test('--hard-deadline accepts s/m/h suffix', () => {
+    expect(resolveSyncHardDeadline(['--hard-deadline', '2m'], { isTty: true })?.deadlineMs).toBe(120_000);
+  });
+
+  test('--hard-deadline with a bad value throws (same posture as --timeout)', () => {
+    expect(() => resolveSyncHardDeadline(['--hard-deadline', 'nope'], { isTty: true })).toThrow();
+    expect(() => resolveSyncHardDeadline(['--hard-deadline', '0'], { isTty: true })).toThrow();
+  });
+
+  test('--timeout (single-source) auto-arms the hard backstop', () => {
+    const r = resolveSyncHardDeadline(['--source', 'briefings', '--timeout', '480'], { isTty: false });
+    expect(r).toEqual({ deadlineMs: 480_000, graceMs: GRACE_MS, reason: 'flag:--timeout' });
+  });
+
+  test('--timeout + --all does NOT auto-arm (per-source budgets); falls through', () => {
+    // Non-TTY → falls to the default; TTY → null.
+    const nonTty = resolveSyncHardDeadline(['--all', '--timeout', '60'], { isTty: false });
+    expect(nonTty?.reason).toBe('default:non-tty');
+    const tty = resolveSyncHardDeadline(['--all', '--timeout', '60'], { isTty: true });
+    expect(tty).toBeNull();
+  });
+
+  test('env GBRAIN_SYNC_MAX_RUNTIME_SECONDS sets the deadline', () => {
+    const r = resolveSyncHardDeadline([], { isTty: true, env: { GBRAIN_SYNC_MAX_RUNTIME_SECONDS: '900' } });
+    expect(r).toEqual({ deadlineMs: 900_000, graceMs: GRACE_MS, reason: 'env:GBRAIN_SYNC_MAX_RUNTIME_SECONDS' });
+  });
+
+  test('env 0 disables (overrides the non-TTY default)', () => {
+    const r = resolveSyncHardDeadline([], { isTty: false, env: { GBRAIN_SYNC_MAX_RUNTIME_SECONDS: '0' } });
+    expect(r).toBeNull();
+  });
+
+  test('non-TTY default is 3600s', () => {
+    const r = resolveSyncHardDeadline([], { isTty: false });
+    expect(r).toEqual({ deadlineMs: 3_600_000, graceMs: GRACE_MS, reason: 'default:non-tty' });
+  });
+
+  test('TTY interactive with no flag/env arms nothing', () => {
+    expect(resolveSyncHardDeadline([], { isTty: true })).toBeNull();
+  });
+
+  test('defaultNonTtySec override is honored', () => {
+    const r = resolveSyncHardDeadline([], { isTty: false, defaultNonTtySec: 60 });
+    expect(r?.deadlineMs).toBe(60_000);
+  });
+});
+
+describe('composeAbortSignals', () => {
+  test('all-undefined returns undefined', () => {
+    expect(composeAbortSignals(undefined, undefined)).toBeUndefined();
+  });
+
+  test('single signal is returned directly (no wrapper)', () => {
+    const c = new AbortController();
+    expect(composeAbortSignals(c.signal, undefined)).toBe(c.signal);
+  });
+
+  test('composite aborts when ANY input aborts', () => {
+    const a = new AbortController();
+    const b = new AbortController();
+    const sig = composeAbortSignals(a.signal, b.signal)!;
+    expect(sig.aborted).toBe(false);
+    b.abort(new Error('boom'));
+    expect(sig.aborted).toBe(true);
+  });
+});