From 6ae94301a6e1204831b2ade53cc31cdb9c9ed191 Mon Sep 17 00:00:00 2001 From: Garry Tan Date: Thu, 28 May 2026 08:20:58 -0700 Subject: [PATCH] =?UTF-8?q?v0.41.26.1=20fix:=20lock-renewal=20cathedral=20?= =?UTF-8?q?=E2=80=94=20closes=20~39=20worker=20crashes/day=20(supersedes?= =?UTF-8?q?=20#1567)=20(#1572)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * v0.41.26.1 fix: lock-renewal cathedral — closes ~39 worker crashes/day (supersedes #1567) Production worker daemons against Supabase / PgBouncer were crashing ~39 times/day with `unhandledRejection at renewLock`. PR #1567 proposed the right try/catch shape; this wave incorporates it and closes the entire bug class (4 inside-review + 8 outside-voice findings absorbed via 9 locked design decisions). What's fixed: - `setInterval(async () => await renewLock(...))` replaced with a sync wrapper around the new pure `runLockRenewalTick` function. No more unhandled rejections escaping the timer callback. - Second crash vector closed: `.catch()` on the stored `executeJob(...).finally(...)` promise so failJob/completeJob throws during the same outage can't propagate to `process.on('unhandledRejection')`. - Per-call `Promise.race` timeout (default `lockDuration/3`) bounds hung renewLock calls so the re-entrancy guard can't wedge indefinitely. - Time-based abort (NOT count-based) so the worker releases its lock BEFORE another worker can reclaim. With the prior 3-strike count + 30s lockDuration, a 15s window let other workers race. - Infrastructure aborts (`lock-renewal-failed`, `lock-lost`) don't burn job attempts — `executeJob`'s catch consults the exported `INFRASTRUCTURE_ABORT_REASONS` set and skips `failJob` so the stall detector reclaims cleanly. - Universal grace-eviction: 30s force-evict safety net now fires for ANY abort reason, not just `job.timeout_ms`. What's added: - `src/core/minions/lock-renewal-tick.ts` (NEW): pure extracted state-machine function + env-knob resolver. Three operator-tunable knobs via env (max-failures-for-audit, call-timeout-ms, safety-margin-ms) with stderr-warn-once on bad input + default fallback. - `src/core/audit/lock-renewal-audit.ts` (NEW): sibling of `batch-retry-audit.ts`. Four outcomes: failure / success_after_failure / gave_up / executeJob_rejected. JSONL at `~/.gbrain/audit/lock-renewal-YYYY-Www.jsonl`. - `src/core/audit/redact-connection-info.ts` (NEW): shared privacy helper. Strips Postgres URLs, host=, user=, password=, IPv4 from error messages before they hit audit JSONL. Wired into BOTH the new lock-renewal audit AND the existing batch-retry audit (privacy backfill — same risk class). - `scripts/check-worker-lock-renewal-shape.sh` (NEW): CI guard wired into `bun run verify`. Asserts the v0.41.22.1 bug pattern (`lockTimer = setInterval(async ...)`) stays absent AND the pure function call site survives refactors. Bug-pattern-specific so it doesn't fight legitimate refactors (codex C12). Tests: 64 new cases across 5 new test files. 182 existing minion + worker tests still pass. All hermetic — no PGLite, no real network, no `mock.module`. Plan + 9 decisions + codex outside-voice review at ~/.claude/plans/system-instruction-you-are-working-humming-nygaard.md Closes #1567 (incorporates the contributor's try/catch shape; closes the bug class structurally). Co-Authored-By: @garrytan-agents Co-Authored-By: Claude Opus 4.7 (1M context) * test: fill A-H gaps for v0.41.26.1 lock-renewal cathedral The original v0.41.26.1 wave shipped 64 hermetic unit tests on the pure tick function, audit primitives, and redactor. Post-ship audit flagged 8 wiring gaps the pure tests can't see — A (launchJob wiring), B (executeJob skip-failJob), C (.catch on stored promise), D (INFRASTRUCTURE_ABORT_REASONS export), E (universal grace-evict), F (executeJob_rejected end-to-end), G (re-entrancy guard at worker layer), H (gold-standard E2E regression). Now closed: - **test/worker-lock-renewal-e2e.serial.test.ts** (1 test, gap H): the headline gold-standard regression. Real PGLite + real MinionWorker + executeRaw wrap that injects renewLock failures on demand. Pins that the worker process DOES NOT crash via unhandledRejection under sustained renewLock throws, the handler observes abort.signal.aborted = true with reason 'lock-renewal-failed', and the audit JSONL contains both `failure` and `gave_up` events. The exact v0.41.22.1 production bug class. Quarantined to its own file because bun:test serial + PGLite has an unresolved interaction with multiple MinionWorker-driven tests in the same file (second test's queue.add hangs indefinitely). - **test/worker-lock-renewal-shape.test.ts** (18 tests, gaps A-G): source-shape behavioral pins. Greps worker.ts function bodies for the patterns the locked decisions promised: launchJob calls runLockRenewalTick + resolveLockRenewalKnobs + uses lockRenewalAudit; tickInFlight declared and gated correctly; stored executeJob promise has .catch with logExecuteJobRejected + console stderr; abort.signal.addEventListener fires for any abort (not just timeout_ms); INFRASTRUCTURE_ABORT_REASONS used inside executeJob's catch with return-early shape. Bug-pattern-specific so a refactor that genuinely improves the shape passes; a refactor that accidentally strips a guarantee fails loud. All 83 lock-renewal wave tests pass in 5.2s. 205 existing minion + worker tests still green. No production code changes. Co-Authored-By: Claude Opus 4.7 (1M context) * fix: typecheck errors in worker-lock-renewal-e2e.serial.test.ts CI verify failed on the new E2E gap-fill test (commit a8b282d4) due to two TS errors that bun's runtime accepts but tsc rejects: 1. line 92: `originalExecuteRaw(sql, ...args)` with `args: unknown[]` — TS can't prove args has <=2 elements, so the call site looks like 1+1+N args against a function that accepts 1-3. Fixed by destructuring the wrap params explicitly: `(sql, params?, opts?)` matching the executeRaw signature, then calling `originalExecuteRaw(sql, params, opts)` with named args. 2. line 145: `expect(abortReason).toBe('lock-renewal-failed')` where `abortReason: string | null = null`. TS narrows the variable to `null` because the closure assignment in worker.register isn't observable to the inferrer. bun:test's `.toBe` overload then picks the null variant and rejects the string literal. Fixed by `as unknown as string` cast — the preceding `handlerAbortObserved` assertion guarantees we entered the branch where abortReason was assigned. Documented inline. Local verify (29 checks) now green; E2E test still passes in 5.0s. Co-Authored-By: Claude Opus 4.7 (1M context) --------- Co-authored-by: @garrytan-agents Co-authored-by: Claude Opus 4.7 (1M context) --- CHANGELOG.md | 154 ++++++ CLAUDE.md | 8 +- TODOS.md | 70 +++ VERSION | 2 +- llms-full.txt | 8 +- package.json | 3 +- scripts/check-worker-lock-renewal-shape.sh | 93 ++++ scripts/run-verify-parallel.sh | 1 + src/core/audit/batch-retry-audit.ts | 13 +- src/core/audit/lock-renewal-audit.ts | 268 ++++++++++ src/core/audit/redact-connection-info.ts | 100 ++++ src/core/minions/lock-renewal-tick.ts | 262 ++++++++++ src/core/minions/worker.ts | 234 +++++++-- test/audit/batch-retry-redaction.test.ts | 75 +++ test/audit/lock-renewal-audit.test.ts | 195 +++++++ test/audit/redact-connection-info.test.ts | 151 ++++++ .../check-worker-lock-renewal-shape.test.ts | 152 ++++++ test/worker-lock-renewal-e2e.serial.test.ts | 174 +++++++ test/worker-lock-renewal-shape.test.ts | 258 ++++++++++ test/worker-lock-renewal.test.ts | 485 ++++++++++++++++++ 20 files changed, 2664 insertions(+), 42 deletions(-) create mode 100755 scripts/check-worker-lock-renewal-shape.sh create mode 100644 src/core/audit/lock-renewal-audit.ts create mode 100644 src/core/audit/redact-connection-info.ts create mode 100644 src/core/minions/lock-renewal-tick.ts create mode 100644 test/audit/batch-retry-redaction.test.ts create mode 100644 test/audit/lock-renewal-audit.test.ts create mode 100644 test/audit/redact-connection-info.test.ts create mode 100644 test/scripts/check-worker-lock-renewal-shape.test.ts create mode 100644 test/worker-lock-renewal-e2e.serial.test.ts create mode 100644 test/worker-lock-renewal-shape.test.ts create mode 100644 test/worker-lock-renewal.test.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index b3654bb4d..a10478438 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,160 @@ All notable changes to GBrain will be documented in this file. +## [0.41.26.1] - 2026-05-27 + +**Your worker daemon stops crashing 39 times a day.** + +If you run `gbrain` against Supabase (or any Postgres behind PgBouncer), +the background worker that handles your sync, embed, and brainstorm +jobs has been quietly dying every 30 minutes or so. The supervisor +restarts it cleanly, jobs eventually complete, and nothing looks broken +in `gbrain jobs list`. But under the hood, every time PgBouncer rotated +its connection pool, the worker hit an unhandled Promise rejection and +exited with code 1. Production saw ~39 crashes per day per worker. +v0.41.26.1 makes the worker survive those blips without skipping a +beat — the renewal call retries quietly, the audit log records what +happened, and your jobs keep running. + +The bigger fix underneath: every place in the worker that talked to +the database during a connection blip could have crashed the same way. +The lock-renewal timer was the headline (1 of 2 vectors), but the +finally-and-catch path around every job was the second one. Both are +closed now. + +This release also adds a tiny but load-bearing privacy fix: when audit +log entries record a database error message, they used to leak the +connection string (host, port, password) directly into the JSONL file. +If you ever pasted an audit dump into a GitHub issue or Slack to debug +something, you were leaking credentials. Now those values are +auto-redacted before they hit disk. Both the new `lock-renewal` audit +and the existing `batch-retry` audit get this protection. + +## How to verify after upgrade + +`gbrain upgrade` handles everything. No manual steps. To confirm the +fix is live: + +```bash +# 1. Check that the worker shape guard is wired into your verify gate. +bun run check:worker-lock-renewal-shape # should print "lock-renewal shape OK" + +# 2. Watch the audit channel during a real Supabase reconnect. +tail -F ~/.gbrain/audit/lock-renewal-*.jsonl + +# 3. Force a connection blip (only if you can): +docker exec your-pgbouncer-container pkill -HUP pgbouncer +# Expected: 1-2 `failure` events, then a `success_after_failure` event +# when the connection comes back. Worker process MUST NOT exit. If it +# does, please file an issue with `gbrain doctor` output. +``` + +If you previously saw your supervisor restarting workers every 5-30 +minutes with `code=1 (runtime_error)` exits, those should stop. + +If you want to tune the failure-recovery window: + +```bash +# Defaults are sensible. These are operator-tunable env knobs. +export GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS=10000 # per-call timeout +export GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS=5000 # release-before-stall headroom +``` + +### Itemized changes + +#### Fixed: worker crashes from unhandled Promise rejections + +- **The lock-renewal timer no longer crashes the daemon on PgBouncer + blips.** Pre-fix: `setInterval(async () => await renewLock(...))` + let any throw escape to `process.on('unhandledRejection')` and exit + the worker with code 1. Now: synchronous timer wrapper around a + pure `runLockRenewalTick` function with try/catch coverage on every + await path. Adds re-entrancy guard so overlapping ticks during a + pool stall don't pile concurrent connection acquisitions on an + already-saturated PgBouncer. +- **Second crash vector closed: the stored `executeJob.finally()` + promise now has an explicit `.catch()` handler.** During the same DB + outage, `failJob` or `completeJob` could throw inside the catch + block; that rejection used to escape too. Now logged to stderr + + recorded in the audit JSONL as `executeJob_rejected`. +- **Per-call timeout via `Promise.race`** so a hung renewLock can't + wedge the re-entrancy guard indefinitely. Default 10s (1/3 of the + default 30s lock duration). +- **Time-based abort, not count-based.** Pre-fix design (the + contributor's first cut) aborted after N consecutive failures, + which with the default 30s lock could let another worker reclaim + the row BEFORE this worker noticed. Time-based abort fires when + `now - lastSuccessfulRenewalAt >= lockDuration - safetyMargin` + (default 25s with 5s headroom), so we release the lock voluntarily + before the stall detector can race us. +- **Infrastructure aborts don't burn job attempts.** When the worker + releases a job because of a PgBouncer outage (not because the job + itself failed), `executeJob` now skips `failJob` and lets the stall + detector requeue cleanly. Pre-fix this would dead-letter healthy + jobs after 3 PgBouncer blips. The exported + `INFRASTRUCTURE_ABORT_REASONS` set is the single source of truth. +- **Universal grace-eviction.** The 30s force-evict safety net used + to fire only for explicit `job.timeout_ms` aborts. Now fires for + ANY abort reason — handlers that ignore AbortSignal can't wedge an + `inFlight` slot forever on lock-renewal aborts either. + +#### Added: lock-renewal audit JSONL at `~/.gbrain/audit/lock-renewal-*.jsonl` + +- Four outcome variants: `failure` (one renewLock throw), + `success_after_failure` (recovery), `gave_up` (time-based abort + fired), `executeJob_rejected` (second-vector forensic trail). +- Mirrors the existing `batch-retry-audit` pattern: ISO-week rotation, + honors `GBRAIN_AUDIT_DIR`, dual-week read-back, corrupted-line + tolerance, `pruneOldLockRenewalAuditFiles(30)` for the future + dream-cycle purge wiring. +- Never logs `lock_token` or `job.data`. Only failure/recovery events + fire — successful renewals stay silent, which is ~5760 events/day + per active job saved. + +#### Added: shared connection-info redactor (privacy backfill) + +- New `src/core/audit/redact-connection-info.ts` strips `postgres://` + URLs, `host=`, `user=`, `password=`, IPv4 octets from any text + before it lands in a JSONL audit. Negative-lookbehind defeats + version-string false positives (`v3.1.4.0`, `tree-sitter@0.26.3.1`). +- Wired into BOTH the new `lock-renewal-audit` AND the existing + `batch-retry-audit`. The batch-retry module had the same risk class + — pre-fix, an exhausted-retry event could leak the connection + string of a failing batch write. Now both surfaces are + share-safe. + +#### Added: env-overridable knobs + +- `GBRAIN_LOCK_RENEWAL_MAX_FAILURES` (default 3, audit-labeling only) +- `GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS` (default `lockDuration / 3`) +- `GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS` (default `lockDuration / 6`) +- Bad values fall back to defaults with a single per-process stderr + warning (no silent ignore). + +#### Added: CI shape guard `check:worker-lock-renewal-shape` + +- Wired into `bun run verify`. Asserts (a) the v0.41.22.1 bug pattern + (`lockTimer = setInterval(async ...)`) stays absent from + `src/core/minions/worker.ts`, (b) `launchJob` calls the extracted + pure `runLockRenewalTick` function so the test seam survives + refactors. Bug-pattern-specific so it doesn't fight legitimate + unrelated changes elsewhere in the file. + +#### Tests + +- 46 new test cases across 5 new test files: pure-function state + machine (18), audit primitive contract (11), redactor patterns + (15), batch-retry privacy backfill regression (3), CI guard + meta-tests (5). All hermetic — no PGLite, no real network, no + `mock.module`. +- 169 existing minion tests still pass. + +#### Contributor credit + +This wave supersedes PR #1567 from `@garrytan-agents` and incorporates +its core try/catch shape. Outside-voice review (codex) caught 8 +additional gaps the inside-review missed, all absorbed. + ## [0.41.26.0] - 2026-05-27 **`gbrain dream --source ` finally counts as a cycle.** diff --git a/CLAUDE.md b/CLAUDE.md index fd0f1fa52..f783bf297 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -158,7 +158,11 @@ strict behavior when unset. - `src/core/dry-fix.ts` — `gbrain doctor --fix` engine. `autoFixDryViolations(fixes, {dryRun})` rewrites inlined rules to `> **Convention:** see [path](path).` callouts via three shape-aware expanders (bullet / blockquote / paragraph). Five guards: working-tree-dirty (`getWorkingTreeStatus()` returns 3-state `'clean' | 'dirty' | 'not_a_repo'`), no-git-backup, inside-code-fence, already-delegated (40-line proximity, consistent with detector), ambiguous-multi-match, block-is-callout. `execFileSync` array args (no shell — no injection surface). EOF newline preserved. **v0.37.1.0:** safety primitives extracted to `src/core/skill-fix-gates.ts` (back-compat re-exports preserved). New `MISSING_RULE_PATTERNS` INSERT pattern type lives alongside the existing REPLACE patterns — same auto-fix entry point, same git-safety gates, but instead of rewriting an existing block, INSERT patterns place a canonical callout at a target offset (today: `after-h1-paragraph` only; designed to extend). The first INSERT pattern is `brain_first`, which auto-inserts `> **Convention:** see [conventions/brain-first.md](../conventions/brain-first.md) for the lookup chain (search → query → get_page → external).` on any flagged SKILL.md whose analyzer verdict is `missing_brain_first`. Idempotent — re-runs detect the existing callout and skip. - `src/core/backoff.ts` — Adaptive load-aware throttling: CPU/memory checks, exponential backoff, active hours multiplier - `src/core/retry.ts` (v0.41.19.0) — canonical retry primitive for transient connection errors. Exports `withRetry(fn, opts)` execution wrapper + `BULK_RETRY_OPTS` constant (`{maxRetries:3, delayMs:1000, delayMaxMs:10000, jitter:'decorrelated'}`) tuned for Supabase Supavisor's 5-10s circuit-breaker recovery window + `BATCH_AUDIT_SITES` typed const (closed enum of every audit-emission site) + `resolveBulkRetryOpts(env)` (reads `GBRAIN_BULK_MAX_RETRIES` / `GBRAIN_BULK_RETRY_BASE_MS` / `GBRAIN_BULK_RETRY_MAX_MS` with `>=0` validation, throws on bad input with paste-ready hint) + `abortableSleep(ms, signal?)` (AbortSignal-aware setTimeout) + `RetryAbortError` (tagged error for clean shutdown) + `computeNextDelay()` (pure-fn for 3 jitter modes: `'none'`, `'full'`, `'decorrelated'`). The execution wrapper is consumed by `postgres-engine.ts` + `pglite-engine.ts` batch primitives (`addLinksBatch` / `addTimelineEntriesBatch` / `upsertChunks`) so every caller — current AND future — inherits retry as part of the data-primitive's contract. CI guard `scripts/check-no-double-retry.sh` fails the build on `withRetry(...engine.batch...)` patterns (prevents 3×3=9 retry amplification). CI guard `scripts/check-batch-audit-site.sh` validates every string-literal `auditSite: '...'` against the closed `BATCH_AUDIT_SITES` enum. **Closes the v0.41.17 production incident** where ~3,000 rows were silently lost per dream cycle on a 16K-page brain because the prior single-500ms-retry shape couldn't survive Supavisor's 5-10s circuit-breaker recovery. Decorrelated jitter (AWS-style: `uniform(base, prevDelay*3)` capped at `delayMaxMs`) replaces naive `'full'` jitter which allowed near-zero retries that re-hit the still-recovering breaker. Pinned by `test/core/retry.test.ts` (37 cases) + `test/core/retry-stress.slow.test.ts` (5 cases simulating 100 batches × 30% blip rate, asserts zero row loss). -- `src/core/audit/batch-retry-audit.ts` (v0.41.19.0) — JSONL audit primitive for batch-retry events. Built on `audit-writer.ts` cathedral. Schema: `{ts, site, batch_size, attempt, outcome: 'success' | 'exhausted', delay_ms, error_message_summary, error_code?}`. Privacy posture: NEVER logs slugs / page IDs / content (mirrors `shell-audit.ts` from v0.20+). `logBatchRetry` fires per successful retry recovery; `logBatchExhausted` fires when retries exhaust and rows are lost. `readRecentBatchRetryEvents(hours=24)` returns `{events, corrupted_lines, files_scanned, files_unreadable}` — corruption + permission errors surface to doctor, not silently swallowed (codex H-9). `pruneOldBatchRetryAuditFiles(daysToKeep=30)` deletes old files (codex H-8 — implements the v0.41 plan's "30-day pruning convention" for real). Called from `gbrain dream --phase purge`. File: `~/.gbrain/audit/batch-retry-YYYY-Www.jsonl` (honors `GBRAIN_AUDIT_DIR`). Pinned by `test/audit/batch-retry-audit.test.ts` (12 cases). +- `src/core/audit/batch-retry-audit.ts` (v0.41.19.0, extended v0.41.26.1) — JSONL audit primitive for batch-retry events. Built on `audit-writer.ts` cathedral. Schema: `{ts, site, batch_size, attempt, outcome: 'success' | 'exhausted', delay_ms, error_message_summary, error_code?}`. Privacy posture: NEVER logs slugs / page IDs / content (mirrors `shell-audit.ts` from v0.20+). `logBatchRetry` fires per successful retry recovery; `logBatchExhausted` fires when retries exhaust and rows are lost. `readRecentBatchRetryEvents(hours=24)` returns `{events, corrupted_lines, files_scanned, files_unreadable}` — corruption + permission errors surface to doctor, not silently swallowed (codex H-9). `pruneOldBatchRetryAuditFiles(daysToKeep=30)` deletes old files (codex H-8 — implements the v0.41 plan's "30-day pruning convention" for real). Called from `gbrain dream --phase purge`. File: `~/.gbrain/audit/batch-retry-YYYY-Www.jsonl` (honors `GBRAIN_AUDIT_DIR`). **v0.41.26.1 privacy backfill:** `summarizeError` now routes error messages through the shared `redactConnectionInfo` helper from `src/core/audit/redact-connection-info.ts` BEFORE truncation, so DSNs / hostnames / credentials / IPv4 octets can't leak from a Postgres connection-failure error into operator-shared JSONL dumps. Same risk class as lock-renewal-audit; closed in the same wave. Pinned by `test/audit/batch-retry-audit.test.ts` (12 cases) + new `test/audit/batch-retry-redaction.test.ts` (3 privacy regressions). +- `src/core/audit/lock-renewal-audit.ts` (v0.41.26.1) — JSONL audit primitive for per-job lock-renewal faults. Sibling of `batch-retry-audit.ts`; built on `audit-writer.ts`. Four outcomes: `failure` (single renewLock throw, counter incremented), `success_after_failure` (recovery; emits the recovery count), `gave_up` (time-based deadline exceeded; abort fired), `executeJob_rejected` (the SECOND unhandledRejection vector from D7 — the stored `executeJob(...).finally(...)` promise itself rejected, e.g. failJob threw during the same DB outage). Schema: `{ts, job_id, job_name, attempt?, outcome, error_message_summary?, error_code?}`. Privacy: NEVER logs `lock_token` or `job.data`. Error summaries route through `redactConnectionInfo` BEFORE truncation. Defense-in-depth: every audit call inside the lock-renewal tick's catch block is wrapped in its own inner try/catch so a misbehaving audit-writer can't re-introduce the unhandledRejection bug class via a new surface. `readRecentLockRenewalEvents(hours=24)` walks current + previous ISO week with corrupted-line tolerance. `pruneOldLockRenewalAuditFiles(daysToKeep=30)` is ready for future dream-cycle purge wiring (filed as TODO-LR-3). File: `~/.gbrain/audit/lock-renewal-YYYY-Www.jsonl`. Operator UX is `tail -F` until the doctor check lands (TODO-LR-2). Pinned by `test/audit/lock-renewal-audit.test.ts` (11 cases). +- `src/core/audit/redact-connection-info.ts` (v0.41.26.1) — Shared pure helper. `redactConnectionInfo(text: string): string` strips Postgres connection info before any audit JSONL write: `postgres://`/`postgresql://` URLs, `host=foo`, `user=foo`, `password=foo`, `pwd=foo`, IPv4 octets. Each match becomes ``. Negative-lookbehind/lookahead `[\w.@-]` on the IPv4 pattern defeats version-string false positives like `v3.1.4.0` or `tree-sitter@0.26.3.1` while still matching real IPs in PG errors (`(192.168.1.42)`). Order-sensitive pattern set: URL forms first so substrings inside URLs don't get double-redacted. Idempotent (running twice produces same output), pure (no I/O), hot-path-safe (regex compiled at module load). Wired into BOTH `lock-renewal-audit.ts` (new) AND `batch-retry-audit.ts` (privacy backfill — same risk class). Risk model documented in module header: Postgres errors during connection failures embed DSNs / credentials / hostnames into error messages; operators routinely paste audit dumps into GitHub issues / Slack to debug; the audit channel must be safe to share by construction. Known limitations: bare-quoted hostnames (`at "db.example.com"`) and bare-quoted usernames (`for user "postgres.foo"`) are NOT caught — the IP in those PG error shapes is the highest-value leak and IS caught. Quoted-string patterns filed as TODO-LR-5. Pinned by `test/audit/redact-connection-info.test.ts` (15 cases covering all 5 patterns + real Supabase fixture + ENOTFOUND fixture + version-string false-positive defense). +- `src/core/minions/lock-renewal-tick.ts` (v0.41.26.1) — Pure extracted function from `MinionWorker.launchJob`'s setInterval body. The structural fix that closes the v0.41.22.1 production unhandledRejection crash class. Exports `runLockRenewalTick(deps, state) → Promise` plus `resolveLockRenewalKnobs(env, lockDuration) → LockRenewalKnobs`. Three env knobs all parsed as positive integers with stderr-warn-once-per-process on bad input + default fallback: `GBRAIN_LOCK_RENEWAL_MAX_FAILURES` (default 3, audit-labeling only — abort triggering uses time-based instead), `GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS` (default `lockDuration/3`, bounds the hung-renewLock vector via `Promise.race`), `GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS` (default `lockDuration/6`, ensures we release before stall-detector reclaim). The tick checks `state.cancelled()` at three guard points (entry, after await resolves, after await throws) so a long renewLock that resolves after the job ended bails cleanly. Result type is a tagged union `{kind: 'ok' | 'cancelled' | 'lock_lost' | 'should_abort', reason?}` that the worker switches on; all `abort.abort()` / `clearInterval` side effects live in the worker's closure scope, not the pure function. Audit calls wrapped in inner try/catch (codex C4 defense-in-depth) so the audit module can never re-introduce the bug class through a new surface. Pinned by `test/worker-lock-renewal.test.ts` (18 hermetic state-machine cases — no fs, no PGLite, no real setInterval). +- `scripts/check-worker-lock-renewal-shape.sh` (v0.41.26.1, D4) — CI guard wired into `bun run verify`. Two invariants on `src/core/minions/worker.ts`: (1) the v0.41.22.1 bug pattern `lockTimer = setInterval(async ...)` must NOT appear (narrowed via `lockTimer =` prefix so unrelated `setInterval(async)` calls elsewhere in the file — like the stall detector at line ~269, codex C13 territory — don't false-fire), (2) `runLockRenewalTick` must remain referenced so the pure-function test seam survives refactors. Bug-pattern-specific by design (codex C12) — a future refactor to `setTimeout`-recursion or `AbortController`-based scheduling passes as long as the bug pattern stays absent. Uses POSIX ERE + `[[:space:]]` for BSD-grep portability. Honors `GBRAIN_LOCK_RENEWAL_SHAPE_TARGET` env override for fixture-based meta-tests. Pinned by `test/scripts/check-worker-lock-renewal-shape.test.ts` (5 cases including the C13 false-positive defense for the stall-detector pattern elsewhere in the file). - `src/commands/doctor.ts:checkBatchRetryHealth` (v0.41.19.0) — `batch_retry_health` check surfacing Supavisor circuit-breaker incidents. Wired into both `runDoctor` (local) and `doctorReportRemote` (thin-client). Reads last **24h** (not 7d — codex H-9: avoid permanent noise from one historical blip). States: `ok` (zero exhausted in 24h OR <3 from a single site), `warn` (>=3 same-site OR >=5 cross-site), `fail` (>=20 sustained breaker). Surfaces bad `GBRAIN_BULK_*` env at doctor startup (codex M-10) instead of first-retry. Corrupt-JSONL tolerant. Paste-ready fix hints in every warn/fail message. Pinned by `test/doctor-batch-retry.test.ts` (10 cases). - `scripts/check-no-double-retry.sh` + `scripts/check-batch-audit-site.sh` (v0.41.19.0) — CI lint guards wired into `bun run verify`. The former greps src/ for `withRetry(...engine.{addLinksBatch|addTimelineEntriesBatch|upsertChunks})` patterns and fails the build on hit (Eng-D6 migration ordering hazard — prevents 3×3=9 retry amplification on incomplete reverts). The latter extracts every string-literal `auditSite: '...'` from src/ and validates each appears in the `BATCH_AUDIT_SITES` const in `src/core/retry.ts` (codex H-7 typo guard — prevents fragmented doctor output). - `src/core/fail-improve.ts` — Deterministic-first, LLM-fallback loop with JSONL failure logging and auto-test generation @@ -201,7 +205,7 @@ strict behavior when unset. - `src/core/zombie-reap.ts` (v0.28.1) — idempotent `installSigchldHandler()` so JS-spawned children get reaped via Bun's internal `waitpid()`. Bun (like Node) only auto-reaps when a SIGCHLD listener is registered; without it, every child the worker spawns (shell jobs, embed batches, sub-agents) becomes a zombie on exit and holds connection slots. Called once at module load from `src/cli.ts` (with Windows platform guard — SIGCHLD doesn't exist on Windows). Cross-file leak guard via `_uninstallSigchldHandlerForTests()` for tests. Layer 1 of the three-layer zombie defense; Layer 2 is tini-as-PID-1 wrapping the worker subtree (via `src/core/minions/spawn-helpers.ts`); Layer 3 is the container's own tini for hard Bun crashes. - `src/core/minions/` — Minions job queue: BullMQ-inspired, Postgres-native (queue, worker, backoff, types, protected-names, quiet-hours, stagger, handlers/shell). - `src/core/minions/queue.ts` — MinionQueue class (submit, claim, complete, fail, stall detection, parent-child, depth/child-cap, per-job timeouts, cascade-kill, attachments, idempotency keys, child_done inbox, removeOnComplete/Fail). `add()` takes a 4th `trusted` arg (separate from `opts` to prevent spread leakage); protected names in `PROTECTED_JOB_NAMES` require `{allowProtectedSubmit: true}` and the check runs trim-normalized (whitespace-bypass safe). v0.14.1 #219: `add()` plumbs `max_stalled` through with a `[1, 100]` clamp; omitted values let the schema DEFAULT (5) kick in. v0.19.0: `handleWallClockTimeouts(lockDurationMs)` is Layer 3 kill shot for jobs where `FOR UPDATE SKIP LOCKED` stall detection and the timeout sweep both fail to evict (wedged worker holding a row lock via a pending transaction). v0.19.1: `maxWaiting` coalesce path now uses `pg_advisory_xact_lock` keyed on `(name, queue)` to serialize concurrent submits for the same key, and filters on `queue` in addition to `name` so cross-queue same-name jobs don't suppress each other. -- `src/core/minions/worker.ts` — MinionWorker class (handler registry, lock renewal, graceful shutdown, timeout safety net). v0.14.0 abort-path fix: aborted jobs now call `failJob` with reason (`timeout`/`cancel`/`lock-lost`/`shutdown`) instead of returning silently. `shutdownAbort` (instance field) fires on process SIGTERM/SIGINT and propagates to `ctx.shutdownSignal` — shell handler listens to it; non-shell handlers don't. v0.22.1 (#403): per-job timeout fires `abort.abort(new Error('timeout'))` then a 30-second grace-then-evict safety net force-evicts the job from `inFlight` and marks it dead in DB if the handler ignores the abort signal — frees the slot even when a handler wedges (the 98-waiting-0-active prod incident driver). **v0.28.1 engine-ownership invariant:** `start()` no longer calls `engine.disconnect()` on shutdown — that was a leaky abstraction (the worker disconnected an engine it didn't own). The CLI handler in `src/commands/jobs.ts case 'work'` now owns engine lifecycle via try/finally with loud error logging on disconnect failure. Pinned by `test/worker-shutdown-disconnect.test.ts` asserting the inverse (`disconnectSpy).not.toHaveBeenCalled()`). **v0.34.3.0:** RSS watchdog metric switched to non-file-backed pages on Linux. New exports `parseRssFromProcStatus(status)` (pure parser, exported for unit tests) and `getAccurateRss(readStatus?)` (reads `/proc/self/status` for `RssAnon + RssShmem`, falls back to `process.memoryUsage().rss` on macOS / restricted containers / kernel <4.5). The default `getRss` injected into `WorkerOpts` is now `getAccurateRss` instead of `process.memoryUsage().rss`. Closes the prod incident where VmRSS inflated to 7GB on a 96K-page brain (file-backed git packfile mmaps) while heap stayed at ~100MB; the watchdog was firing every autopilot cycle. M1 parser fix uses field-presence regex checks so `RssAnon: 0 + RssShmem: 512` (shmem-only worker case) parses correctly instead of falling through to VmRSS. Pinned by `test/worker-rss.test.ts` (11 cases). +- `src/core/minions/worker.ts` — MinionWorker class (handler registry, lock renewal, graceful shutdown, timeout safety net). v0.14.0 abort-path fix: aborted jobs now call `failJob` with reason (`timeout`/`cancel`/`lock-lost`/`shutdown`) instead of returning silently. `shutdownAbort` (instance field) fires on process SIGTERM/SIGINT and propagates to `ctx.shutdownSignal` — shell handler listens to it; non-shell handlers don't. v0.22.1 (#403): per-job timeout fires `abort.abort(new Error('timeout'))` then a 30-second grace-then-evict safety net force-evicts the job from `inFlight` and marks it dead in DB if the handler ignores the abort signal — frees the slot even when a handler wedges (the 98-waiting-0-active prod incident driver). **v0.41.26.1 (supersedes #1567):** the lock-renewal cathedral wave. The `launchJob` setInterval block — which previously was `setInterval(async () => await renewLock(...))` — is the v0.41.22.1 production crash class (~39 worker exits/day from `unhandledRejection at renewLock` during PgBouncer connection rotation). Replaced with a thin sync wrapper around the new pure `runLockRenewalTick` function from `src/core/minions/lock-renewal-tick.ts`. Five additional gaps closed in the same wave: (1) `cancelled` flag captured in the timer closure stops in-flight IIFEs from writing misleading audit events after the job ended; (2) re-entrancy guard (`tickInFlight`) plus per-call `Promise.race` timeout (`GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS`, default `lockDuration/3`) so a hung renewLock can't wedge the worker indefinitely; (3) time-based abort (`Date.now() - lastSuccessfulRenewalAt >= lockDuration - GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS`) replaces count-based, so we release the lock BEFORE another worker can reclaim; (4) explicit `.catch()` on the stored `executeJob(...).finally(...)` promise closes the SECOND unhandledRejection vector (if failJob throws during the same DB outage); (5) `INFRASTRUCTURE_ABORT_REASONS = new Set(['lock-renewal-failed', 'lock-lost'])` is exported; executeJob's catch skips `failJob` for these reasons so PgBouncer blips no longer dead-letter healthy jobs (the stall detector reclaims cleanly with the lock already expired). The 30s grace-evict safety net moved out of the `job.timeout_ms`-only branch into a generic abort listener that fires for ANY abort reason. CI guard `scripts/check-worker-lock-renewal-shape.sh` (wired into `bun run verify`) asserts the bug pattern `lockTimer = setInterval(async ...)` stays absent AND `launchJob` continues to call `runLockRenewalTick` so the test seam survives refactors. Behavior pinned by `test/worker-lock-renewal.test.ts` (18 hermetic state-machine cases over the pure function), `test/audit/lock-renewal-audit.test.ts` (11 cases), `test/scripts/check-worker-lock-renewal-shape.test.ts` (5 fixture-driven meta-tests). **v0.28.1 engine-ownership invariant:** `start()` no longer calls `engine.disconnect()` on shutdown — that was a leaky abstraction (the worker disconnected an engine it didn't own). The CLI handler in `src/commands/jobs.ts case 'work'` now owns engine lifecycle via try/finally with loud error logging on disconnect failure. Pinned by `test/worker-shutdown-disconnect.test.ts` asserting the inverse (`disconnectSpy).not.toHaveBeenCalled()`). **v0.34.3.0:** RSS watchdog metric switched to non-file-backed pages on Linux. New exports `parseRssFromProcStatus(status)` (pure parser, exported for unit tests) and `getAccurateRss(readStatus?)` (reads `/proc/self/status` for `RssAnon + RssShmem`, falls back to `process.memoryUsage().rss` on macOS / restricted containers / kernel <4.5). The default `getRss` injected into `WorkerOpts` is now `getAccurateRss` instead of `process.memoryUsage().rss`. Closes the prod incident where VmRSS inflated to 7GB on a 96K-page brain (file-backed git packfile mmaps) while heap stayed at ~100MB; the watchdog was firing every autopilot cycle. M1 parser fix uses field-presence regex checks so `RssAnon: 0 + RssShmem: 512` (shmem-only worker case) parses correctly instead of falling through to VmRSS. Pinned by `test/worker-rss.test.ts` (11 cases). - `src/core/minions/supervisor.ts` — MinionSupervisor process manager. Spawns `gbrain jobs work` as a child, restarts on crash with exponential backoff, periodic health check. v0.22.1 (#406): `consecutiveHealthFailures` counter; on 3 consecutive failures emits `health_warn` with `reason: 'db_connection_degraded'` and calls `engine.reconnect()` to swap in a fresh pool, then resets the counter. Worker exit classifier emits `likely_cause` field on `worker_exited` events: `oom_or_external_kill` (SIGKILL), `graceful_shutdown` (SIGTERM), `runtime_error` (code 1), `clean_exit` (code 0), `unknown`. **v0.28.1:** consumes `detectTini()` + `buildSpawnInvocation()` from `src/core/minions/spawn-helpers.ts` to wrap the worker subtree in tini-as-PID-1 when tini is on `PATH` (handles native-addon zombie reaping that the in-process SIGCHLD reaper can't reach). Exposes `isTiniDetected` read-only accessor for tests. **v0.34.3.0:** spawn-and-respawn loop extracted into the shared `ChildWorkerSupervisor` core (see entry below). MinionSupervisor now composes the inner class via `runSuperviseLoop()` → `new ChildWorkerSupervisor({...})` and maps `ChildSupervisorEvent` shapes back through the existing `emit()` SupervisorEvent channel — JSONL audit consumers see byte-compatible output across the rename. PID lock, signal handlers, health check, and `process.exit` on max-crashes stay in MinionSupervisor (standalone-daemon concerns). The pre-shipped reset-to-0-on-code=0 hunk that originally fixed the prod crash-counter incident is gone; the same fix lives in the shared core under the D1 amendment (code=0 leaves `crashCount` untouched, so a worker alternating real crashes + watchdog drains still trips `max_crashes`). D2 `cleanRestartBudget` (default 10 restarts per 60s) caps the macOS/non-Linux-fallback tight-loop by emitting `health_warn { reason: 'clean_restart_budget_exceeded' }` plus backoff after the threshold trips. `shutdown()` drains via `childSupervisor.killChild('SIGTERM')` + `awaitChildExit(35_000)` instead of reaching into `this.child` directly. Pinned by `test/supervisor.test.ts` (16 cases; existing tests that previously relied on clean-exit-as-crash semantics now use exit-1 workers since clean exits no longer count) and `test/supervisor-tini.test.ts`. - `src/core/minions/child-worker-supervisor.ts` (v0.34.3.0) — shared spawn-and-respawn core extracted from `MinionSupervisor` so it can be reused by both `MinionSupervisor` (standalone `gbrain jobs supervisor` daemon) and `src/commands/autopilot.ts` (autopilot daemon). Pre-v0.34.3.0 the two consumers maintained parallel spawn loops that drifted into the same bug class — Codex caught it during plan-eng-review on PR #1003. Pure class: NO PID file, NO signal handlers, NO `process.exit`, NO health check. Lifecycle events fire via injected `onEvent: (ChildSupervisorEvent) => void` callback so each composer routes to its own log/audit channel. **D1 exit classifier:** `code === 0` leaves `crashCount` UNCHANGED (preserves flap detection across mixed exit sequences — a worker that alternates `exit 1 / exit 0 / exit 1 / exit 0` correctly trips `max_crashes` after 10 real crashes regardless of intervening clean exits). `code != 0` follows the existing `runDuration > stableRunResetMs ? 1 : ++crashCount` rule. **D2 clean-restart budget:** sliding window tracks code=0 exits; when count exceeds `cleanRestartBudget` (default 10) inside `cleanRestartWindowMs` (default 60s), emits `health_warn { reason: 'clean_restart_budget_exceeded' }` and applies `cleanRestartBudgetBackoffMs` (default 1s) before the next spawn. Caps the worst-case tight-loop on macOS / restricted containers / kernel <4.5 where the worker's RSS watchdog falls back to VmRSS. Public read-only accessors `childAlive`, `inBackoff`, `crashCount` for composer health checks; `killChild(signal)` + `awaitChildExit(timeoutMs)` for shutdown paths. `awaitChildExit` short-circuits when `child.exitCode !== null || child.signalCode !== null` (regression caught in pre-landing /review: pre-fix, fast-SIGTERM responders caused a 35-second shutdown hang because the late `once('exit', ...)` listener never fired). Test hooks: `_backoffFloorMs` skips the real backoff curve, `_now` injects a fake clock. Pinned by `test/child-worker-supervisor.test.ts` (7 cases: D1 classifier with code=0 not counted, interleaved exits still trip max_crashes, stable-run + clean-exit interaction across faked 6-minute run, D2 budget triggers backoff + health_warn, budget config is per-instance, awaitChildExit short-circuit, event-shape regression). Plan that produced the design lives at `~/.claude/plans/this-is-a-real-sleepy-sketch.md`. - `src/core/minions/spawn-helpers.ts` (v0.28.1) — pure `detectTini()` + `buildSpawnInvocation()` helpers consumed by both `supervisor.ts` and `autopilot.ts`. Resolves the DRY violation between the two spawn sites and makes the tini wrapping testable without `mock.module()` (rule R2 of `scripts/check-test-isolation.sh`). `detectTini()` calls `execFileSync('which', ['tini'])` with explicit `env: process.env` so Bun sees runtime PATH mutations (the env-snapshot bug fix). `buildSpawnInvocation(tiniPath, cmd, args)` returns `{cmd, args}` with tini prepended when present, or the bare invocation otherwise. Pinned by `test/spawn-helpers.test.ts` (5 cases) and `test/supervisor-tini.test.ts` (4 cases). diff --git a/TODOS.md b/TODOS.md index 63f8e790f..0b2c37638 100644 --- a/TODOS.md +++ b/TODOS.md @@ -1,5 +1,75 @@ # TODOS +## v0.41.26.1 lock-renewal cathedral follow-ups (v0.42+) + +- **TODO-LR-1 (P2): PR #1567 surrogate-pair fix for synthesize.ts.** + PR #1567 bundled a `safeSliceEnd` UTF-16 surrogate-pair handler + alongside the lock-renewal try/catch. The lock-renewal change shipped + in v0.41.26.1; the surrogate fix was deferred because it's a + different bug class with its own test surface. + - **What:** lift `safeSliceEnd` into a shared + `src/core/string-safe-slice.ts`, apply to `judgeSignificance` AND + `findBoundary` in `src/core/cycle/synthesize.ts`, add round-trip + tests with surrogate-bearing transcripts. Pre-existing TODO at + TODOS.md (search `Multibyte sanitizer test`) covers part of this + — extend that entry. + - **Why:** transcripts containing emoji + 4-byte CJK chars get + cut mid-pair under the current `.slice(0, N)`, breaking JSON + parse downstream and dropping rows. + - **Source:** community PR #1567, contributor `@garrytan-agents`. + +- **TODO-LR-2 (P2): doctor check `lock_renewal_health`.** + v0.41.26.1 ships the audit JSONL primitive without a doctor read + surface. For now, `tail -F ~/.gbrain/audit/lock-renewal-*.jsonl` is + the operator UX. + - **What:** add `checkLockRenewalHealth` in `src/commands/doctor.ts` + mirroring `checkBatchRetryHealth` shape. Reads + `readRecentLockRenewalEvents(24)`. Warns at >=5 `gave_up` events + or >=20 `failure` events in the last 24h. Wired into both + `runDoctor` (local) and `doctorReportRemote` (thin-client). + - **Why:** operators on production Supabase want a single `gbrain + doctor` line to know whether their pool is flapping. + - **Pros:** structurally matches the v0.41.18 batch-retry health + check. ~50 LOC. + +- **TODO-LR-3 (P3): wire `pruneOldLockRenewalAuditFiles(30)` into + `gbrain dream --phase purge`.** + - **What:** one-line addition at the existing purge handler where + `pruneOldBatchRetryAuditFiles` is called today. + - **Why:** consistency with the batch-retry audit (which prunes). + Without pruning, lock-renewal audit files accumulate one per + ISO-week — negligible at first but worth doing the right way. + +- **TODO-LR-4 (P2, codex C13): stall-detector re-entrancy guard at + worker.ts:269.** + The stall-detector `setInterval(async ...)` block has try/catch on + every await so it doesn't crash. But it lacks a re-entrancy guard, + so during a PgBouncer outage, 3 concurrent stall-detector loops can + pile 9 pending connection acquisitions per tick on an + already-saturated pool — amplifying the very stall they're trying + to detect. + - **What:** apply the same `tickInFlight` boolean guard pattern + the lock-renewal fix uses. Convert `setInterval(async () => {...})` + → `setInterval(() => { if (tickInFlight) return; tickInFlight = + true; void (async () => {...})().finally(() => { tickInFlight = + false; }); })`. + - **Why:** same bug class as the v0.41.22.1 lock-renewal crash, but + a different symptom. Doesn't crash, does amplify load. + - **Source:** codex outside-voice review of v0.41.26.1 plan. + +- **TODO-LR-5 (P3): bare-quoted hostname + username redactor patterns.** + The v0.41.26.1 `redactConnectionInfo` catches bare `host=`, + `user=`, `password=`, `pg_url`, `ipv4` patterns but NOT + bare-quoted hostnames (`connection to server at "db.example.com"`) + or bare-quoted usernames (`for user "postgres.abcdef123456"`). The + IP in those PG error shapes is the highest-value leak (publicly + resolvable), and that one IS caught. + - **What:** extend the pattern set with optional quoted-string + matchers, OR add a context-aware matcher that looks for `at + "...".? (?:port|.)` shapes. + - **Cons:** quoted-string false positives are common (DB names, + role names); needs careful pattern design. + ## v0.41.20.x dream-source-ingest-titles follow-ups (v0.42+) - **TODO-V13-A (P2): `gbrain dream --max-pages ` plumbing.** diff --git a/VERSION b/VERSION index a54d656e5..635dc410d 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -0.41.26.0 \ No newline at end of file +0.41.26.1 \ No newline at end of file diff --git a/llms-full.txt b/llms-full.txt index 4c3041188..809462c88 100644 --- a/llms-full.txt +++ b/llms-full.txt @@ -300,7 +300,11 @@ strict behavior when unset. - `src/core/dry-fix.ts` — `gbrain doctor --fix` engine. `autoFixDryViolations(fixes, {dryRun})` rewrites inlined rules to `> **Convention:** see [path](path).` callouts via three shape-aware expanders (bullet / blockquote / paragraph). Five guards: working-tree-dirty (`getWorkingTreeStatus()` returns 3-state `'clean' | 'dirty' | 'not_a_repo'`), no-git-backup, inside-code-fence, already-delegated (40-line proximity, consistent with detector), ambiguous-multi-match, block-is-callout. `execFileSync` array args (no shell — no injection surface). EOF newline preserved. **v0.37.1.0:** safety primitives extracted to `src/core/skill-fix-gates.ts` (back-compat re-exports preserved). New `MISSING_RULE_PATTERNS` INSERT pattern type lives alongside the existing REPLACE patterns — same auto-fix entry point, same git-safety gates, but instead of rewriting an existing block, INSERT patterns place a canonical callout at a target offset (today: `after-h1-paragraph` only; designed to extend). The first INSERT pattern is `brain_first`, which auto-inserts `> **Convention:** see [conventions/brain-first.md](../conventions/brain-first.md) for the lookup chain (search → query → get_page → external).` on any flagged SKILL.md whose analyzer verdict is `missing_brain_first`. Idempotent — re-runs detect the existing callout and skip. - `src/core/backoff.ts` — Adaptive load-aware throttling: CPU/memory checks, exponential backoff, active hours multiplier - `src/core/retry.ts` (v0.41.19.0) — canonical retry primitive for transient connection errors. Exports `withRetry(fn, opts)` execution wrapper + `BULK_RETRY_OPTS` constant (`{maxRetries:3, delayMs:1000, delayMaxMs:10000, jitter:'decorrelated'}`) tuned for Supabase Supavisor's 5-10s circuit-breaker recovery window + `BATCH_AUDIT_SITES` typed const (closed enum of every audit-emission site) + `resolveBulkRetryOpts(env)` (reads `GBRAIN_BULK_MAX_RETRIES` / `GBRAIN_BULK_RETRY_BASE_MS` / `GBRAIN_BULK_RETRY_MAX_MS` with `>=0` validation, throws on bad input with paste-ready hint) + `abortableSleep(ms, signal?)` (AbortSignal-aware setTimeout) + `RetryAbortError` (tagged error for clean shutdown) + `computeNextDelay()` (pure-fn for 3 jitter modes: `'none'`, `'full'`, `'decorrelated'`). The execution wrapper is consumed by `postgres-engine.ts` + `pglite-engine.ts` batch primitives (`addLinksBatch` / `addTimelineEntriesBatch` / `upsertChunks`) so every caller — current AND future — inherits retry as part of the data-primitive's contract. CI guard `scripts/check-no-double-retry.sh` fails the build on `withRetry(...engine.batch...)` patterns (prevents 3×3=9 retry amplification). CI guard `scripts/check-batch-audit-site.sh` validates every string-literal `auditSite: '...'` against the closed `BATCH_AUDIT_SITES` enum. **Closes the v0.41.17 production incident** where ~3,000 rows were silently lost per dream cycle on a 16K-page brain because the prior single-500ms-retry shape couldn't survive Supavisor's 5-10s circuit-breaker recovery. Decorrelated jitter (AWS-style: `uniform(base, prevDelay*3)` capped at `delayMaxMs`) replaces naive `'full'` jitter which allowed near-zero retries that re-hit the still-recovering breaker. Pinned by `test/core/retry.test.ts` (37 cases) + `test/core/retry-stress.slow.test.ts` (5 cases simulating 100 batches × 30% blip rate, asserts zero row loss). -- `src/core/audit/batch-retry-audit.ts` (v0.41.19.0) — JSONL audit primitive for batch-retry events. Built on `audit-writer.ts` cathedral. Schema: `{ts, site, batch_size, attempt, outcome: 'success' | 'exhausted', delay_ms, error_message_summary, error_code?}`. Privacy posture: NEVER logs slugs / page IDs / content (mirrors `shell-audit.ts` from v0.20+). `logBatchRetry` fires per successful retry recovery; `logBatchExhausted` fires when retries exhaust and rows are lost. `readRecentBatchRetryEvents(hours=24)` returns `{events, corrupted_lines, files_scanned, files_unreadable}` — corruption + permission errors surface to doctor, not silently swallowed (codex H-9). `pruneOldBatchRetryAuditFiles(daysToKeep=30)` deletes old files (codex H-8 — implements the v0.41 plan's "30-day pruning convention" for real). Called from `gbrain dream --phase purge`. File: `~/.gbrain/audit/batch-retry-YYYY-Www.jsonl` (honors `GBRAIN_AUDIT_DIR`). Pinned by `test/audit/batch-retry-audit.test.ts` (12 cases). +- `src/core/audit/batch-retry-audit.ts` (v0.41.19.0, extended v0.41.26.1) — JSONL audit primitive for batch-retry events. Built on `audit-writer.ts` cathedral. Schema: `{ts, site, batch_size, attempt, outcome: 'success' | 'exhausted', delay_ms, error_message_summary, error_code?}`. Privacy posture: NEVER logs slugs / page IDs / content (mirrors `shell-audit.ts` from v0.20+). `logBatchRetry` fires per successful retry recovery; `logBatchExhausted` fires when retries exhaust and rows are lost. `readRecentBatchRetryEvents(hours=24)` returns `{events, corrupted_lines, files_scanned, files_unreadable}` — corruption + permission errors surface to doctor, not silently swallowed (codex H-9). `pruneOldBatchRetryAuditFiles(daysToKeep=30)` deletes old files (codex H-8 — implements the v0.41 plan's "30-day pruning convention" for real). Called from `gbrain dream --phase purge`. File: `~/.gbrain/audit/batch-retry-YYYY-Www.jsonl` (honors `GBRAIN_AUDIT_DIR`). **v0.41.26.1 privacy backfill:** `summarizeError` now routes error messages through the shared `redactConnectionInfo` helper from `src/core/audit/redact-connection-info.ts` BEFORE truncation, so DSNs / hostnames / credentials / IPv4 octets can't leak from a Postgres connection-failure error into operator-shared JSONL dumps. Same risk class as lock-renewal-audit; closed in the same wave. Pinned by `test/audit/batch-retry-audit.test.ts` (12 cases) + new `test/audit/batch-retry-redaction.test.ts` (3 privacy regressions). +- `src/core/audit/lock-renewal-audit.ts` (v0.41.26.1) — JSONL audit primitive for per-job lock-renewal faults. Sibling of `batch-retry-audit.ts`; built on `audit-writer.ts`. Four outcomes: `failure` (single renewLock throw, counter incremented), `success_after_failure` (recovery; emits the recovery count), `gave_up` (time-based deadline exceeded; abort fired), `executeJob_rejected` (the SECOND unhandledRejection vector from D7 — the stored `executeJob(...).finally(...)` promise itself rejected, e.g. failJob threw during the same DB outage). Schema: `{ts, job_id, job_name, attempt?, outcome, error_message_summary?, error_code?}`. Privacy: NEVER logs `lock_token` or `job.data`. Error summaries route through `redactConnectionInfo` BEFORE truncation. Defense-in-depth: every audit call inside the lock-renewal tick's catch block is wrapped in its own inner try/catch so a misbehaving audit-writer can't re-introduce the unhandledRejection bug class via a new surface. `readRecentLockRenewalEvents(hours=24)` walks current + previous ISO week with corrupted-line tolerance. `pruneOldLockRenewalAuditFiles(daysToKeep=30)` is ready for future dream-cycle purge wiring (filed as TODO-LR-3). File: `~/.gbrain/audit/lock-renewal-YYYY-Www.jsonl`. Operator UX is `tail -F` until the doctor check lands (TODO-LR-2). Pinned by `test/audit/lock-renewal-audit.test.ts` (11 cases). +- `src/core/audit/redact-connection-info.ts` (v0.41.26.1) — Shared pure helper. `redactConnectionInfo(text: string): string` strips Postgres connection info before any audit JSONL write: `postgres://`/`postgresql://` URLs, `host=foo`, `user=foo`, `password=foo`, `pwd=foo`, IPv4 octets. Each match becomes ``. Negative-lookbehind/lookahead `[\w.@-]` on the IPv4 pattern defeats version-string false positives like `v3.1.4.0` or `tree-sitter@0.26.3.1` while still matching real IPs in PG errors (`(192.168.1.42)`). Order-sensitive pattern set: URL forms first so substrings inside URLs don't get double-redacted. Idempotent (running twice produces same output), pure (no I/O), hot-path-safe (regex compiled at module load). Wired into BOTH `lock-renewal-audit.ts` (new) AND `batch-retry-audit.ts` (privacy backfill — same risk class). Risk model documented in module header: Postgres errors during connection failures embed DSNs / credentials / hostnames into error messages; operators routinely paste audit dumps into GitHub issues / Slack to debug; the audit channel must be safe to share by construction. Known limitations: bare-quoted hostnames (`at "db.example.com"`) and bare-quoted usernames (`for user "postgres.foo"`) are NOT caught — the IP in those PG error shapes is the highest-value leak and IS caught. Quoted-string patterns filed as TODO-LR-5. Pinned by `test/audit/redact-connection-info.test.ts` (15 cases covering all 5 patterns + real Supabase fixture + ENOTFOUND fixture + version-string false-positive defense). +- `src/core/minions/lock-renewal-tick.ts` (v0.41.26.1) — Pure extracted function from `MinionWorker.launchJob`'s setInterval body. The structural fix that closes the v0.41.22.1 production unhandledRejection crash class. Exports `runLockRenewalTick(deps, state) → Promise` plus `resolveLockRenewalKnobs(env, lockDuration) → LockRenewalKnobs`. Three env knobs all parsed as positive integers with stderr-warn-once-per-process on bad input + default fallback: `GBRAIN_LOCK_RENEWAL_MAX_FAILURES` (default 3, audit-labeling only — abort triggering uses time-based instead), `GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS` (default `lockDuration/3`, bounds the hung-renewLock vector via `Promise.race`), `GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS` (default `lockDuration/6`, ensures we release before stall-detector reclaim). The tick checks `state.cancelled()` at three guard points (entry, after await resolves, after await throws) so a long renewLock that resolves after the job ended bails cleanly. Result type is a tagged union `{kind: 'ok' | 'cancelled' | 'lock_lost' | 'should_abort', reason?}` that the worker switches on; all `abort.abort()` / `clearInterval` side effects live in the worker's closure scope, not the pure function. Audit calls wrapped in inner try/catch (codex C4 defense-in-depth) so the audit module can never re-introduce the bug class through a new surface. Pinned by `test/worker-lock-renewal.test.ts` (18 hermetic state-machine cases — no fs, no PGLite, no real setInterval). +- `scripts/check-worker-lock-renewal-shape.sh` (v0.41.26.1, D4) — CI guard wired into `bun run verify`. Two invariants on `src/core/minions/worker.ts`: (1) the v0.41.22.1 bug pattern `lockTimer = setInterval(async ...)` must NOT appear (narrowed via `lockTimer =` prefix so unrelated `setInterval(async)` calls elsewhere in the file — like the stall detector at line ~269, codex C13 territory — don't false-fire), (2) `runLockRenewalTick` must remain referenced so the pure-function test seam survives refactors. Bug-pattern-specific by design (codex C12) — a future refactor to `setTimeout`-recursion or `AbortController`-based scheduling passes as long as the bug pattern stays absent. Uses POSIX ERE + `[[:space:]]` for BSD-grep portability. Honors `GBRAIN_LOCK_RENEWAL_SHAPE_TARGET` env override for fixture-based meta-tests. Pinned by `test/scripts/check-worker-lock-renewal-shape.test.ts` (5 cases including the C13 false-positive defense for the stall-detector pattern elsewhere in the file). - `src/commands/doctor.ts:checkBatchRetryHealth` (v0.41.19.0) — `batch_retry_health` check surfacing Supavisor circuit-breaker incidents. Wired into both `runDoctor` (local) and `doctorReportRemote` (thin-client). Reads last **24h** (not 7d — codex H-9: avoid permanent noise from one historical blip). States: `ok` (zero exhausted in 24h OR <3 from a single site), `warn` (>=3 same-site OR >=5 cross-site), `fail` (>=20 sustained breaker). Surfaces bad `GBRAIN_BULK_*` env at doctor startup (codex M-10) instead of first-retry. Corrupt-JSONL tolerant. Paste-ready fix hints in every warn/fail message. Pinned by `test/doctor-batch-retry.test.ts` (10 cases). - `scripts/check-no-double-retry.sh` + `scripts/check-batch-audit-site.sh` (v0.41.19.0) — CI lint guards wired into `bun run verify`. The former greps src/ for `withRetry(...engine.{addLinksBatch|addTimelineEntriesBatch|upsertChunks})` patterns and fails the build on hit (Eng-D6 migration ordering hazard — prevents 3×3=9 retry amplification on incomplete reverts). The latter extracts every string-literal `auditSite: '...'` from src/ and validates each appears in the `BATCH_AUDIT_SITES` const in `src/core/retry.ts` (codex H-7 typo guard — prevents fragmented doctor output). - `src/core/fail-improve.ts` — Deterministic-first, LLM-fallback loop with JSONL failure logging and auto-test generation @@ -343,7 +347,7 @@ strict behavior when unset. - `src/core/zombie-reap.ts` (v0.28.1) — idempotent `installSigchldHandler()` so JS-spawned children get reaped via Bun's internal `waitpid()`. Bun (like Node) only auto-reaps when a SIGCHLD listener is registered; without it, every child the worker spawns (shell jobs, embed batches, sub-agents) becomes a zombie on exit and holds connection slots. Called once at module load from `src/cli.ts` (with Windows platform guard — SIGCHLD doesn't exist on Windows). Cross-file leak guard via `_uninstallSigchldHandlerForTests()` for tests. Layer 1 of the three-layer zombie defense; Layer 2 is tini-as-PID-1 wrapping the worker subtree (via `src/core/minions/spawn-helpers.ts`); Layer 3 is the container's own tini for hard Bun crashes. - `src/core/minions/` — Minions job queue: BullMQ-inspired, Postgres-native (queue, worker, backoff, types, protected-names, quiet-hours, stagger, handlers/shell). - `src/core/minions/queue.ts` — MinionQueue class (submit, claim, complete, fail, stall detection, parent-child, depth/child-cap, per-job timeouts, cascade-kill, attachments, idempotency keys, child_done inbox, removeOnComplete/Fail). `add()` takes a 4th `trusted` arg (separate from `opts` to prevent spread leakage); protected names in `PROTECTED_JOB_NAMES` require `{allowProtectedSubmit: true}` and the check runs trim-normalized (whitespace-bypass safe). v0.14.1 #219: `add()` plumbs `max_stalled` through with a `[1, 100]` clamp; omitted values let the schema DEFAULT (5) kick in. v0.19.0: `handleWallClockTimeouts(lockDurationMs)` is Layer 3 kill shot for jobs where `FOR UPDATE SKIP LOCKED` stall detection and the timeout sweep both fail to evict (wedged worker holding a row lock via a pending transaction). v0.19.1: `maxWaiting` coalesce path now uses `pg_advisory_xact_lock` keyed on `(name, queue)` to serialize concurrent submits for the same key, and filters on `queue` in addition to `name` so cross-queue same-name jobs don't suppress each other. -- `src/core/minions/worker.ts` — MinionWorker class (handler registry, lock renewal, graceful shutdown, timeout safety net). v0.14.0 abort-path fix: aborted jobs now call `failJob` with reason (`timeout`/`cancel`/`lock-lost`/`shutdown`) instead of returning silently. `shutdownAbort` (instance field) fires on process SIGTERM/SIGINT and propagates to `ctx.shutdownSignal` — shell handler listens to it; non-shell handlers don't. v0.22.1 (#403): per-job timeout fires `abort.abort(new Error('timeout'))` then a 30-second grace-then-evict safety net force-evicts the job from `inFlight` and marks it dead in DB if the handler ignores the abort signal — frees the slot even when a handler wedges (the 98-waiting-0-active prod incident driver). **v0.28.1 engine-ownership invariant:** `start()` no longer calls `engine.disconnect()` on shutdown — that was a leaky abstraction (the worker disconnected an engine it didn't own). The CLI handler in `src/commands/jobs.ts case 'work'` now owns engine lifecycle via try/finally with loud error logging on disconnect failure. Pinned by `test/worker-shutdown-disconnect.test.ts` asserting the inverse (`disconnectSpy).not.toHaveBeenCalled()`). **v0.34.3.0:** RSS watchdog metric switched to non-file-backed pages on Linux. New exports `parseRssFromProcStatus(status)` (pure parser, exported for unit tests) and `getAccurateRss(readStatus?)` (reads `/proc/self/status` for `RssAnon + RssShmem`, falls back to `process.memoryUsage().rss` on macOS / restricted containers / kernel <4.5). The default `getRss` injected into `WorkerOpts` is now `getAccurateRss` instead of `process.memoryUsage().rss`. Closes the prod incident where VmRSS inflated to 7GB on a 96K-page brain (file-backed git packfile mmaps) while heap stayed at ~100MB; the watchdog was firing every autopilot cycle. M1 parser fix uses field-presence regex checks so `RssAnon: 0 + RssShmem: 512` (shmem-only worker case) parses correctly instead of falling through to VmRSS. Pinned by `test/worker-rss.test.ts` (11 cases). +- `src/core/minions/worker.ts` — MinionWorker class (handler registry, lock renewal, graceful shutdown, timeout safety net). v0.14.0 abort-path fix: aborted jobs now call `failJob` with reason (`timeout`/`cancel`/`lock-lost`/`shutdown`) instead of returning silently. `shutdownAbort` (instance field) fires on process SIGTERM/SIGINT and propagates to `ctx.shutdownSignal` — shell handler listens to it; non-shell handlers don't. v0.22.1 (#403): per-job timeout fires `abort.abort(new Error('timeout'))` then a 30-second grace-then-evict safety net force-evicts the job from `inFlight` and marks it dead in DB if the handler ignores the abort signal — frees the slot even when a handler wedges (the 98-waiting-0-active prod incident driver). **v0.41.26.1 (supersedes #1567):** the lock-renewal cathedral wave. The `launchJob` setInterval block — which previously was `setInterval(async () => await renewLock(...))` — is the v0.41.22.1 production crash class (~39 worker exits/day from `unhandledRejection at renewLock` during PgBouncer connection rotation). Replaced with a thin sync wrapper around the new pure `runLockRenewalTick` function from `src/core/minions/lock-renewal-tick.ts`. Five additional gaps closed in the same wave: (1) `cancelled` flag captured in the timer closure stops in-flight IIFEs from writing misleading audit events after the job ended; (2) re-entrancy guard (`tickInFlight`) plus per-call `Promise.race` timeout (`GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS`, default `lockDuration/3`) so a hung renewLock can't wedge the worker indefinitely; (3) time-based abort (`Date.now() - lastSuccessfulRenewalAt >= lockDuration - GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS`) replaces count-based, so we release the lock BEFORE another worker can reclaim; (4) explicit `.catch()` on the stored `executeJob(...).finally(...)` promise closes the SECOND unhandledRejection vector (if failJob throws during the same DB outage); (5) `INFRASTRUCTURE_ABORT_REASONS = new Set(['lock-renewal-failed', 'lock-lost'])` is exported; executeJob's catch skips `failJob` for these reasons so PgBouncer blips no longer dead-letter healthy jobs (the stall detector reclaims cleanly with the lock already expired). The 30s grace-evict safety net moved out of the `job.timeout_ms`-only branch into a generic abort listener that fires for ANY abort reason. CI guard `scripts/check-worker-lock-renewal-shape.sh` (wired into `bun run verify`) asserts the bug pattern `lockTimer = setInterval(async ...)` stays absent AND `launchJob` continues to call `runLockRenewalTick` so the test seam survives refactors. Behavior pinned by `test/worker-lock-renewal.test.ts` (18 hermetic state-machine cases over the pure function), `test/audit/lock-renewal-audit.test.ts` (11 cases), `test/scripts/check-worker-lock-renewal-shape.test.ts` (5 fixture-driven meta-tests). **v0.28.1 engine-ownership invariant:** `start()` no longer calls `engine.disconnect()` on shutdown — that was a leaky abstraction (the worker disconnected an engine it didn't own). The CLI handler in `src/commands/jobs.ts case 'work'` now owns engine lifecycle via try/finally with loud error logging on disconnect failure. Pinned by `test/worker-shutdown-disconnect.test.ts` asserting the inverse (`disconnectSpy).not.toHaveBeenCalled()`). **v0.34.3.0:** RSS watchdog metric switched to non-file-backed pages on Linux. New exports `parseRssFromProcStatus(status)` (pure parser, exported for unit tests) and `getAccurateRss(readStatus?)` (reads `/proc/self/status` for `RssAnon + RssShmem`, falls back to `process.memoryUsage().rss` on macOS / restricted containers / kernel <4.5). The default `getRss` injected into `WorkerOpts` is now `getAccurateRss` instead of `process.memoryUsage().rss`. Closes the prod incident where VmRSS inflated to 7GB on a 96K-page brain (file-backed git packfile mmaps) while heap stayed at ~100MB; the watchdog was firing every autopilot cycle. M1 parser fix uses field-presence regex checks so `RssAnon: 0 + RssShmem: 512` (shmem-only worker case) parses correctly instead of falling through to VmRSS. Pinned by `test/worker-rss.test.ts` (11 cases). - `src/core/minions/supervisor.ts` — MinionSupervisor process manager. Spawns `gbrain jobs work` as a child, restarts on crash with exponential backoff, periodic health check. v0.22.1 (#406): `consecutiveHealthFailures` counter; on 3 consecutive failures emits `health_warn` with `reason: 'db_connection_degraded'` and calls `engine.reconnect()` to swap in a fresh pool, then resets the counter. Worker exit classifier emits `likely_cause` field on `worker_exited` events: `oom_or_external_kill` (SIGKILL), `graceful_shutdown` (SIGTERM), `runtime_error` (code 1), `clean_exit` (code 0), `unknown`. **v0.28.1:** consumes `detectTini()` + `buildSpawnInvocation()` from `src/core/minions/spawn-helpers.ts` to wrap the worker subtree in tini-as-PID-1 when tini is on `PATH` (handles native-addon zombie reaping that the in-process SIGCHLD reaper can't reach). Exposes `isTiniDetected` read-only accessor for tests. **v0.34.3.0:** spawn-and-respawn loop extracted into the shared `ChildWorkerSupervisor` core (see entry below). MinionSupervisor now composes the inner class via `runSuperviseLoop()` → `new ChildWorkerSupervisor({...})` and maps `ChildSupervisorEvent` shapes back through the existing `emit()` SupervisorEvent channel — JSONL audit consumers see byte-compatible output across the rename. PID lock, signal handlers, health check, and `process.exit` on max-crashes stay in MinionSupervisor (standalone-daemon concerns). The pre-shipped reset-to-0-on-code=0 hunk that originally fixed the prod crash-counter incident is gone; the same fix lives in the shared core under the D1 amendment (code=0 leaves `crashCount` untouched, so a worker alternating real crashes + watchdog drains still trips `max_crashes`). D2 `cleanRestartBudget` (default 10 restarts per 60s) caps the macOS/non-Linux-fallback tight-loop by emitting `health_warn { reason: 'clean_restart_budget_exceeded' }` plus backoff after the threshold trips. `shutdown()` drains via `childSupervisor.killChild('SIGTERM')` + `awaitChildExit(35_000)` instead of reaching into `this.child` directly. Pinned by `test/supervisor.test.ts` (16 cases; existing tests that previously relied on clean-exit-as-crash semantics now use exit-1 workers since clean exits no longer count) and `test/supervisor-tini.test.ts`. - `src/core/minions/child-worker-supervisor.ts` (v0.34.3.0) — shared spawn-and-respawn core extracted from `MinionSupervisor` so it can be reused by both `MinionSupervisor` (standalone `gbrain jobs supervisor` daemon) and `src/commands/autopilot.ts` (autopilot daemon). Pre-v0.34.3.0 the two consumers maintained parallel spawn loops that drifted into the same bug class — Codex caught it during plan-eng-review on PR #1003. Pure class: NO PID file, NO signal handlers, NO `process.exit`, NO health check. Lifecycle events fire via injected `onEvent: (ChildSupervisorEvent) => void` callback so each composer routes to its own log/audit channel. **D1 exit classifier:** `code === 0` leaves `crashCount` UNCHANGED (preserves flap detection across mixed exit sequences — a worker that alternates `exit 1 / exit 0 / exit 1 / exit 0` correctly trips `max_crashes` after 10 real crashes regardless of intervening clean exits). `code != 0` follows the existing `runDuration > stableRunResetMs ? 1 : ++crashCount` rule. **D2 clean-restart budget:** sliding window tracks code=0 exits; when count exceeds `cleanRestartBudget` (default 10) inside `cleanRestartWindowMs` (default 60s), emits `health_warn { reason: 'clean_restart_budget_exceeded' }` and applies `cleanRestartBudgetBackoffMs` (default 1s) before the next spawn. Caps the worst-case tight-loop on macOS / restricted containers / kernel <4.5 where the worker's RSS watchdog falls back to VmRSS. Public read-only accessors `childAlive`, `inBackoff`, `crashCount` for composer health checks; `killChild(signal)` + `awaitChildExit(timeoutMs)` for shutdown paths. `awaitChildExit` short-circuits when `child.exitCode !== null || child.signalCode !== null` (regression caught in pre-landing /review: pre-fix, fast-SIGTERM responders caused a 35-second shutdown hang because the late `once('exit', ...)` listener never fired). Test hooks: `_backoffFloorMs` skips the real backoff curve, `_now` injects a fake clock. Pinned by `test/child-worker-supervisor.test.ts` (7 cases: D1 classifier with code=0 not counted, interleaved exits still trip max_crashes, stable-run + clean-exit interaction across faked 6-minute run, D2 budget triggers backoff + health_warn, budget config is per-instance, awaitChildExit short-circuit, event-shape regression). Plan that produced the design lives at `~/.claude/plans/this-is-a-real-sleepy-sketch.md`. - `src/core/minions/spawn-helpers.ts` (v0.28.1) — pure `detectTini()` + `buildSpawnInvocation()` helpers consumed by both `supervisor.ts` and `autopilot.ts`. Resolves the DRY violation between the two spawn sites and makes the tini wrapping testable without `mock.module()` (rule R2 of `scripts/check-test-isolation.sh`). `detectTini()` calls `execFileSync('which', ['tini'])` with explicit `env: process.env` so Bun sees runtime PATH mutations (the env-snapshot bug fix). `buildSpawnInvocation(tiniPath, cmd, args)` returns `{cmd, args}` with tini prepended when present, or the bare invocation otherwise. Pinned by `test/spawn-helpers.test.ts` (5 cases) and `test/supervisor-tini.test.ts` (4 cases). diff --git a/package.json b/package.json index 2c4aa7a20..90aa2b633 100644 --- a/package.json +++ b/package.json @@ -65,6 +65,7 @@ "check:jsonb": "scripts/check-jsonb-pattern.sh", "check:no-double-retry": "scripts/check-no-double-retry.sh", "check:batch-audit-site": "scripts/check-batch-audit-site.sh", + "check:worker-lock-renewal-shape": "scripts/check-worker-lock-renewal-shape.sh", "check:source-id-projection": "scripts/check-source-id-projection.sh", "check:privacy": "scripts/check-privacy.sh", "check:proposal-pii": "scripts/check-proposal-pii.sh", @@ -140,5 +141,5 @@ "bun": ">=1.3.10" }, "license": "MIT", - "version": "0.41.26.0" + "version": "0.41.26.1" } diff --git a/scripts/check-worker-lock-renewal-shape.sh b/scripts/check-worker-lock-renewal-shape.sh new file mode 100755 index 000000000..18cfc8cee --- /dev/null +++ b/scripts/check-worker-lock-renewal-shape.sh @@ -0,0 +1,93 @@ +#!/usr/bin/env bash +# v0.41.22.2 — CI guard against the v0.41.22.1 lock-renewal crash class. +# +# The bug pattern: `setInterval(async () => { await something() })` lets +# any throw inside the async callback propagate to Node's process-level +# `unhandledRejection` handler, which kills the worker with exit 1. +# Production lost ~39 worker processes/day to this exact shape when +# PgBouncer rotated connections during a renewLock call. +# +# This guard enforces two invariants on `src/core/minions/worker.ts`: +# +# 1. The BUG pattern is absent: no `setInterval(async ...)` literal. +# A future refactor that inlines `setInterval(async () => { await +# renewLock(...) })` again would re-introduce the v0.41.22.1 +# crash class via the exact original surface. +# +# 2. The GOOD pattern is present: launchJob calls `runLockRenewalTick`. +# Without this call-site, the timer logic could be re-inlined via +# a different shape AND bypass the first invariant. The +# `runLockRenewalTick` extraction is also the only test seam that +# gives the state machine behavioral coverage. +# +# Intentionally bug-pattern-specific, not implementation-specific: a +# future refactor to `setTimeout`-recursion or `AbortController`-based +# scheduling passes as long as the bug pattern stays absent (codex C12 +# from the v0.41.22.2 outside-voice review). +# +# Usage: scripts/check-worker-lock-renewal-shape.sh +# Exit: 0 when shape is good, 1 when violations found. + +set -euo pipefail + +ROOT="$(git rev-parse --show-toplevel 2>/dev/null || pwd)" +cd "$ROOT" + +# Allow tests to override the target file for fixture-based meta-tests. +TARGET="${GBRAIN_LOCK_RENEWAL_SHAPE_TARGET:-src/core/minions/worker.ts}" + +if [ ! -f "$TARGET" ]; then + echo "ERROR: shape guard target file not found: $TARGET" + exit 1 +fi + +# Invariant 1: the LOCK-RENEWAL site must not use the bug shape. +# +# The bug-class regex is `setInterval(...async...)`, but it appears +# legitimately elsewhere in worker.ts (the stall-detector loop at +# line ~269 uses it with try/catch — codex C13 covers re-entrancy +# guard for that path separately). To keep this guard from fighting +# unrelated decisions, we narrow scope to the renewal timer +# specifically by requiring the assignment shape `lockTimer = setInterval(`. +# +# A future refactor that renames `lockTimer` would slip past this +# guard; that's an accepted tradeoff (the variable name has been +# stable since v0.10 and is the load-bearing test seam for +# `launchJob`'s `inFlight` accounting). +# +# Uses POSIX ERE + [[:space:]] for BSD-grep portability (macOS shipping +# grep doesn't support -P / \s). +if grep -Eq 'lockTimer[[:space:]]*=[[:space:]]*setInterval\([[:space:]]*async' "$TARGET"; then + echo "ERROR: $TARGET contains the v0.41.22.1 bug pattern (\`setInterval(async ...)\`)." + echo + echo " Async timer callbacks let unhandledRejection escape to the" + echo " process-level handler and crash the worker daemon." + echo + echo " Fix: wrap the timer callback synchronously around an IIFE that" + echo " routes through src/core/minions/lock-renewal-tick.ts:" + echo + echo " setInterval(() => {" + echo " if (tickInFlight) return;" + echo " tickInFlight = true;" + echo " void runLockRenewalTick(deps, state)" + echo " .then(handleResult)" + echo " .catch(handlePostError)" + echo " .finally(() => { tickInFlight = false; });" + echo " }, lockDurationMs / 2);" + exit 1 +fi + +# Invariant 2: good pattern present. launchJob must call +# `runLockRenewalTick` or the test seam is gone. +if ! grep -q 'runLockRenewalTick' "$TARGET"; then + echo "ERROR: $TARGET does not call \`runLockRenewalTick\`." + echo + echo " Lock-renewal logic must route through" + echo " src/core/minions/lock-renewal-tick.ts so the state-machine" + echo " behavior stays unit-testable (no PGLite needed, no" + echo " setInterval / process plumbing in tests). Re-introduce the" + echo " call site at launchJob's renewal timer." + exit 1 +fi + +echo "lock-renewal shape OK ($TARGET)" diff --git a/scripts/run-verify-parallel.sh b/scripts/run-verify-parallel.sh index ee0457033..2bd428800 100755 --- a/scripts/run-verify-parallel.sh +++ b/scripts/run-verify-parallel.sh @@ -61,6 +61,7 @@ CHECKS=( "check:source-scope-onboard" "check:no-double-retry" "check:batch-audit-site" + "check:worker-lock-renewal-shape" "typecheck" ) diff --git a/src/core/audit/batch-retry-audit.ts b/src/core/audit/batch-retry-audit.ts index ff5fb6185..2af5b1f12 100644 --- a/src/core/audit/batch-retry-audit.ts +++ b/src/core/audit/batch-retry-audit.ts @@ -22,6 +22,7 @@ import * as fs from 'fs'; import * as path from 'path'; import { createAuditWriter, resolveAuditDir, computeIsoWeekFilename } from './audit-writer.ts'; +import { redactConnectionInfo } from './redact-connection-info.ts'; import type { BatchAuditSite } from '../retry.ts'; export interface BatchRetryAuditEvent { @@ -205,10 +206,18 @@ export function pruneOldBatchRetryAuditFiles( return { removed, kept }; } -/** Truncate error messages to 200 chars + strip newlines (privacy + grep-friendly). */ +/** + * Truncate error messages to 200 chars + strip newlines (privacy + + * grep-friendly). Routes through `redactConnectionInfo` (v0.41.22.2, + * D9 privacy backfill) BEFORE truncation so DSNs / hostnames / + * credentials / IPv4 octets can't leak into operator-shared JSONL + * dumps. Order matters: redaction MUST happen before truncation, or a + * partially-truncated DSN could leak. + */ function summarizeError(err: unknown): string { const raw = err instanceof Error ? err.message : String(err); - return raw.replace(/\s+/g, ' ').slice(0, 200); + const redacted = redactConnectionInfo(raw); + return redacted.replace(/\s+/g, ' ').slice(0, 200); } /** Pull Postgres SQLSTATE if present (e.g. '57014' for statement_timeout). */ diff --git a/src/core/audit/lock-renewal-audit.ts b/src/core/audit/lock-renewal-audit.ts new file mode 100644 index 000000000..5e059fda8 --- /dev/null +++ b/src/core/audit/lock-renewal-audit.ts @@ -0,0 +1,268 @@ +/** + * Lock-renewal audit JSONL primitive (v0.41.22.2). + * + * Records every per-job lock-renewal fault from the worker's renewal + * timer so silent PgBouncer outages, hung connections, and the + * v0.41.22.1 unhandledRejection crash class become observable. The + * audit channel is the canonical operator-facing trail for the + * lock-renewal cathedral wave (see plan + * `~/.claude/plans/system-instruction-you-are-working-humming-nygaard.md`). + * + * File: `~/.gbrain/audit/lock-renewal-YYYY-Www.jsonl` (ISO-week + * rotation, honors `GBRAIN_AUDIT_DIR` via the shared `resolveAuditDir()` + * helper). Built on the v0.40.4.0 `audit-writer.ts` primitive — same + * dual-week read window, same best-effort write contract. + * + * Four outcomes: + * - `failure` — a single renewLock attempt threw; counter incremented + * - `success_after_failure` — renewLock recovered after >=1 failure; emits the recovery count + * - `gave_up` — time-based deadline exceeded; abort fired + * - `executeJob_rejected` — the SECOND unhandledRejection vector from D7; + * the stored executeJob(...).finally(...) promise + * itself rejected (e.g., failJob threw during + * the same DB outage) + * + * Privacy: + * - NEVER logs `lock_token` (write-side fence; secret). + * - NEVER logs `job.data` (could contain user-supplied payloads). + * - NEVER logs the successful-on-first-try path (would drown disk; + * ~5760 events/day per active job during healthy operation). + * - Error summaries route through `redactConnectionInfo` BEFORE + * truncation so DSNs / hostnames / credentials / IPs don't leak + * into a JSONL that operators routinely paste into GitHub issues. + * + * Defense-in-depth: every appendFileSync call inside the audit-writer + * is best-effort (writes stderr-warn on failure, never throws). The + * worker.ts catch blocks ADDITIONALLY wrap audit calls in their own + * inner try/catch (codex C4) so a misbehaving audit primitive can't + * propagate up to the IIFE's surrounding catch and re-introduce the + * unhandledRejection bug class via a new path. + * + * Doctor wiring + dream-purge wiring are filed as v0.41.22+ follow-up + * TODOs in TODOS.md. For v0.41.22.2 the operator surface is + * `tail -F ~/.gbrain/audit/lock-renewal-*.jsonl`. + */ + +import * as fs from 'fs'; +import * as path from 'path'; +import { createAuditWriter, resolveAuditDir, computeIsoWeekFilename } from './audit-writer.ts'; +import { redactConnectionInfo } from './redact-connection-info.ts'; + +export type LockRenewalOutcome = + | 'failure' + | 'success_after_failure' + | 'gave_up' + | 'executeJob_rejected'; + +export interface LockRenewalAuditEvent { + ts: string; + /** Minion queue job id. */ + job_id: number; + /** Minion job name (e.g. 'sync', 'embed', 'subagent'). */ + job_name: string; + /** + * 1-based count of consecutive renewLock failures at the moment this + * event was emitted. For `success_after_failure`, this is the + * recovery count (how many failures preceded the recovery). For + * `executeJob_rejected`, this field is omitted (the rejection comes + * from a different surface than the renewal counter). + */ + attempt?: number; + outcome: LockRenewalOutcome; + /** + * First 200 chars of the error message, redacted via + * `redactConnectionInfo` BEFORE truncation. Omitted for + * `success_after_failure` (no error to summarize). + */ + error_message_summary?: string; + /** Postgres SQLSTATE if present (e.g. '08006' for connection failure). */ + error_code?: string; +} + +const FEATURE_NAME = 'lock-renewal'; + +const writer = createAuditWriter({ + featureName: FEATURE_NAME, + errorLabel: 'lock-renewal-audit', + errorTrailer: '; continuing', +}); + +/** + * Sink interface consumed by `runLockRenewalTick`. Real implementation + * binds the four functions below; tests inject a fake to assert calls + * without writing to disk. + */ +export interface LockRenewalAuditSink { + logFailure(jobId: number, jobName: string, attempt: number, err: unknown): void; + logSuccessAfterFailure(jobId: number, jobName: string, recoveredAfterAttempts: number): void; + logGaveUp(jobId: number, jobName: string, totalFailures: number, err: unknown): void; + logExecuteJobRejected(jobId: number, jobName: string, err: unknown): void; +} + +export const lockRenewalAudit: LockRenewalAuditSink = { + logFailure(jobId, jobName, attempt, err) { + writer.log({ + job_id: jobId, + job_name: jobName, + attempt, + outcome: 'failure', + error_message_summary: summarizeError(err), + error_code: extractErrorCode(err), + }); + }, + logSuccessAfterFailure(jobId, jobName, recoveredAfterAttempts) { + writer.log({ + job_id: jobId, + job_name: jobName, + attempt: recoveredAfterAttempts, + outcome: 'success_after_failure', + // No error_message_summary or error_code: recovery has no error. + }); + }, + logGaveUp(jobId, jobName, totalFailures, err) { + writer.log({ + job_id: jobId, + job_name: jobName, + attempt: totalFailures, + outcome: 'gave_up', + error_message_summary: summarizeError(err), + error_code: extractErrorCode(err), + }); + }, + logExecuteJobRejected(jobId, jobName, err) { + writer.log({ + job_id: jobId, + job_name: jobName, + // No `attempt` — this surface is the stored executeJob promise + // rejection, unrelated to the per-job renewal counter. + outcome: 'executeJob_rejected', + error_message_summary: summarizeError(err), + error_code: extractErrorCode(err), + }); + }, +}; + +/** + * Read recent lock-renewal events plus a corrupted-line count. + * Default window is 24h (matches batch-retry-audit's "is the breaker + * hot RIGHT NOW" semantics). + */ +export interface ReadLockRenewalResult { + events: LockRenewalAuditEvent[]; + corrupted_lines: number; + files_scanned: number; + files_unreadable: number; +} + +export function readRecentLockRenewalEvents( + hours = 24, + now: Date = new Date(), +): ReadLockRenewalResult { + const dir = resolveAuditDir(); + const cutoff = now.getTime() - hours * 3_600_000; + const events: LockRenewalAuditEvent[] = []; + let corruptedLines = 0; + let filesScanned = 0; + let filesUnreadable = 0; + + // Walk current + previous ISO week so a 24h window straddling + // Monday-midnight stays covered (mirrors batch-retry-audit pattern). + const filenames = [ + computeIsoWeekFilename(FEATURE_NAME, now), + computeIsoWeekFilename(FEATURE_NAME, new Date(now.getTime() - 7 * 86400_000)), + ]; + + for (const filename of filenames) { + const file = path.join(dir, filename); + let content: string; + try { + content = fs.readFileSync(file, 'utf8'); + filesScanned++; + } catch (err) { + const code = (err as NodeJS.ErrnoException)?.code; + if (code && code !== 'ENOENT') filesUnreadable++; + continue; + } + for (const line of content.split('\n')) { + if (line.length === 0) continue; + try { + const ev = JSON.parse(line) as LockRenewalAuditEvent; + const ts = Date.parse(ev.ts); + if (Number.isFinite(ts) && ts >= cutoff) events.push(ev); + } catch { + corruptedLines++; + } + } + } + return { + events, + corrupted_lines: corruptedLines, + files_scanned: filesScanned, + files_unreadable: filesUnreadable, + }; +} + +/** + * Delete lock-renewal audit files older than `daysToKeep`. Called from + * the dream cycle's `purge` phase (filed as a v0.41.22+ follow-up TODO + * — wiring is one line at the existing purge handler). + */ +export function pruneOldLockRenewalAuditFiles( + daysToKeep = 30, + now: Date = new Date(), +): { removed: number; kept: number } { + const dir = resolveAuditDir(); + const cutoff = now.getTime() - daysToKeep * 86400_000; + let removed = 0; + let kept = 0; + let entries: fs.Dirent[]; + try { + entries = fs.readdirSync(dir, { withFileTypes: true }); + } catch (err) { + const code = (err as NodeJS.ErrnoException)?.code; + if (code !== 'ENOENT') { + process.stderr.write(`[lock-renewal-audit] prune scan failed (${(err as Error).message}); continuing\n`); + } + return { removed: 0, kept: 0 }; + } + for (const entry of entries) { + if (!entry.isFile()) continue; + if (!entry.name.startsWith(`${FEATURE_NAME}-`) || !entry.name.endsWith('.jsonl')) continue; + const file = path.join(dir, entry.name); + try { + const st = fs.statSync(file); + if (st.mtimeMs < cutoff) { + fs.unlinkSync(file); + removed++; + } else { + kept++; + } + } catch (err) { + process.stderr.write(`[lock-renewal-audit] prune ${entry.name} failed (${(err as Error).message}); continuing\n`); + } + } + return { removed, kept }; +} + +/** + * Redact connection info, normalize whitespace, then truncate to 200 + * chars. Order matters: redaction MUST happen before truncation, or a + * partially-truncated DSN could leak. + */ +function summarizeError(err: unknown): string { + const raw = err instanceof Error ? err.message : String(err); + const redacted = redactConnectionInfo(raw); + return redacted.replace(/\s+/g, ' ').slice(0, 200); +} + +/** Pull Postgres SQLSTATE if present (e.g. '08006' for connection failure). */ +function extractErrorCode(err: unknown): string | undefined { + if (err && typeof err === 'object' && 'code' in err) { + const code = (err as { code?: unknown }).code; + if (typeof code === 'string') return code; + } + return undefined; +} + +// Re-export for tests + future doctor wiring. +export { FEATURE_NAME as LOCK_RENEWAL_FEATURE_NAME }; diff --git a/src/core/audit/redact-connection-info.ts b/src/core/audit/redact-connection-info.ts new file mode 100644 index 000000000..95bdbc254 --- /dev/null +++ b/src/core/audit/redact-connection-info.ts @@ -0,0 +1,100 @@ +/** + * Shared connection-info redactor (v0.41.22.2). + * + * Strips DSNs, credentials, hostnames, and IPv4 octets from text before + * it lands in an audit JSONL or any other operator-facing surface. + * + * Risk model: Postgres errors during connection failures often embed the + * connection string into the error message: + * - `connection to server at "db.example.supabase.com" (1.2.3.4), port 5432 failed: ...` + * - `FATAL: password authentication failed for user "postgres"` + * - `could not connect to server: postgresql://user:pass@host:5432/db` + * + * If an operator pastes a JSONL audit dump into a GitHub issue or Slack, + * those errors leak credentials. The project's audit-as-debug-tool + * convention is explicit (`tail -F ~/.gbrain/audit/*`), so the audit + * channel must be safe to share by construction. + * + * Pure function, no I/O. Idempotent (running twice produces same output). + * Regex compiled once at module load; safe for hot-path use. + * + * Wired into BOTH new `lock-renewal-audit.ts` AND existing + * `batch-retry-audit.ts` (privacy backfill — same risk class). + */ + +interface RedactPattern { + kind: string; + re: RegExp; +} + +/** + * Pattern order is load-bearing: URL forms come first so substrings + * inside URLs (`password=`, `host=`) don't get double-redacted by the + * bare-field matchers. Each pattern uses the global flag so all + * occurrences in a single string get redacted. + */ +const PATTERNS: ReadonlyArray = [ + // postgres:// and postgresql:// URLs. Includes user:pass@host:port/db + // shapes plus query-string variants. Terminator is whitespace or + // common JSON/markdown delimiters. + { kind: 'pg_url', re: /postgres(?:ql)?:\/\/[^\s"'>)]+/gi }, + + // password=secret OR pwd=secret. Both Postgres conninfo forms in + // common use. Value terminates at whitespace, quote, or & (for + // URL-form query strings already-matched-above as `pg_url`). + { kind: 'password', re: /(?:password|pwd)\s*=\s*[^\s"'&)]+/gi }, + + // user=postgres. Allow lead-by-whitespace OR start-of-string so + // `user=` isn't false-matched inside arbitrary words like + // `superuser=...` (which isn't a real conninfo key but defends + // against future ambiguity). + { kind: 'user', re: /(?:^|\s)user\s*=\s*[^\s"'&)]+/gi }, + + // host=db.example.com. Same lead-anchor rule as `user`. + { kind: 'host', re: /(?:^|\s)host\s*=\s*[^\s"'&)]+/gi }, + + // IPv4 octet pattern. The negative-lookbehind / negative-lookahead + // for `[\w.@-]` is the load-bearing false-positive defense: + // - `v3.1.4.0` — `v` is in `\w`, lookbehind fails, no match. + // - `tree-sitter@0.26.3.1` — `@` is in our exclusion set, + // lookbehind fails, no match. + // - `(192.168.1.42),` — `(` is NOT in `[\w.@-]`, lookbehind + // succeeds, `,` is NOT in the exclusion set, lookahead succeeds, + // match fires. (Real PG error shape.) + // The exclusion characters cover the common version-string contexts + // (word chars, dots, @, -) while leaving whitespace + brackets + + // parens + commas as legitimate IP delimiters. + { kind: 'ipv4', re: /(?` + * + * @example + * redactConnectionInfo('FATAL: password=hunter2 user=postgres') + * // → 'FATAL: ' + */ +export function redactConnectionInfo(text: string): string { + if (typeof text !== 'string' || text.length === 0) return text; + let out = text; + for (const { kind, re } of PATTERNS) { + // Reset lastIndex on each pattern because /g regexes mutate state + // across calls. Defensive — String.prototype.replace doesn't actually + // depend on lastIndex, but a future refactor to matchAll() would. + re.lastIndex = 0; + out = out.replace(re, ` `); + } + return out; +} + +/** + * Exported for tests that want to verify the pattern set hasn't drifted + * silently. Returning a copy of `kind` labels so a test can assert + * specific patterns are present without testing the regex internals. + */ +export function getRedactionKinds(): ReadonlyArray { + return PATTERNS.map((p) => p.kind); +} diff --git a/src/core/minions/lock-renewal-tick.ts b/src/core/minions/lock-renewal-tick.ts new file mode 100644 index 000000000..1124a3987 --- /dev/null +++ b/src/core/minions/lock-renewal-tick.ts @@ -0,0 +1,262 @@ +/** + * Pure lock-renewal tick (v0.41.22.2). + * + * Extracted from `MinionWorker.launchJob`'s setInterval body so the + * lock-renewal state machine is testable without timer / process + * surface. The worker reduces to a thin sync wrapper that calls + * `runLockRenewalTick` from inside `setInterval(() => {...})`; all + * decision logic, error-handling, and audit hooks live here as a pure + * function over injected dependencies. + * + * Closes the v0.41.22.1 production crash class + * (`unhandledRejection at renewLock`) AND four additional gaps the + * outside-voice (codex) review surfaced: + * + * - **Hung renewLock**: the original PR's re-entrancy guard skipped + * overlapping ticks but a permanently-pending await would wedge the + * guard forever. `runLockRenewalTick` wraps each renewLock in + * `Promise.race(call, timeoutPromise)` with `callTimeoutMs` so the + * call cannot pend longer than the configured budget. + * + * - **Threshold math**: with `lockDuration=30s` and `interval=15s`, + * a 3-strike count-based abort fires at t=45s but the lock has + * been reclaimable since t=30s — a 15s window where another + * worker can claim the same job. `runLockRenewalTick` aborts based + * on `Date.now() - lastSuccessfulRenewalAt >= lockDuration - + * safetyMargin` (time-based), so the worker voluntarily releases + * BEFORE the stall detector can reclaim. The failure counter is + * kept for audit-event labeling only. + * + * - **Cancelled-tick race**: if the job ends while a renewLock call + * is mid-flight, the IIFE in worker.ts must bail without writing + * a misleading audit event. State carries a `cancelled` thunk + * that the tick checks at three points (entry, after the await + * resolves, after the await throws). + * + * - **Audit defense-in-depth**: each call into the audit sink is + * wrapped in its own inner try/catch. The audit-writer primitive + * already promises "best-effort, never throws," but a defense + * layer here keeps a misbehaving audit from re-introducing the + * unhandledRejection bug class through a new surface. + * + * Pure function — no I/O, no module-level state, no closure-over-class + * fields. All effects route through injected `deps` so tests are + * trivially hermetic. + * + * Knob resolution lives in `resolveLockRenewalKnobs(env, lockDuration)` + * below; tests + workers both consume it. + */ + +export interface LockRenewalKnobs { + /** + * Failure counter cap used ONLY for audit-event labeling. + * Abort triggering uses the time-based deadline (NOT this count). + * Env: `GBRAIN_LOCK_RENEWAL_MAX_FAILURES`. Default: 3. + */ + maxFailuresForAudit: number; + /** + * Per-renewLock-call timeout enforced via `Promise.race`. + * Env: `GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS`. Default: `lockDuration / 3`. + * Bounds the "hung renewLock wedges the re-entrancy guard forever" vector. + */ + callTimeoutMs: number; + /** + * Time-based abort fires when `now - lastSuccessfulRenewalAt >= + * lockDuration - safetyMarginMs`. Default safety margin gives ~5s + * of headroom before another worker could reclaim the lock. + * Env: `GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS`. Default: `lockDuration / 6`. + */ + safetyMarginMs: number; +} + +/** + * Module-private warned-set so we stderr-once-per-process per bad env + * value (codex outside-voice review wanted operator-friendly fallback, + * not silent ignore). Tests reset via `_resetKnobWarningsForTests`. + */ +const _warnedKnobs = new Set(); + +export function _resetKnobWarningsForTests(): void { + _warnedKnobs.clear(); +} + +/** + * Resolve the three lock-renewal knobs. Pure function over an env-like + * record and the worker's configured lockDuration. + * + * Validation: each env var parsed as a positive integer; on bad input + * (NaN, zero, negative, non-integer), emit a single stderr warning per + * process per env-name and fall through to the default. This means an + * operator who sets `GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS=abc` gets a + * loud-but-not-fatal nudge AND a working worker. + */ +export function resolveLockRenewalKnobs( + env: Record, + lockDurationMs: number, +): LockRenewalKnobs { + const defaultMaxFailures = 3; + const defaultCallTimeout = Math.max(1, Math.floor(lockDurationMs / 3)); + const defaultSafetyMargin = Math.max(1, Math.floor(lockDurationMs / 6)); + + return { + maxFailuresForAudit: parsePositiveInt( + env.GBRAIN_LOCK_RENEWAL_MAX_FAILURES, + defaultMaxFailures, + 'GBRAIN_LOCK_RENEWAL_MAX_FAILURES', + ), + callTimeoutMs: parsePositiveInt( + env.GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS, + defaultCallTimeout, + 'GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS', + ), + safetyMarginMs: parsePositiveInt( + env.GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS, + defaultSafetyMargin, + 'GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS', + ), + }; +} + +function parsePositiveInt(raw: string | undefined, fallback: number, name: string): number { + if (raw === undefined || raw === '') return fallback; + // Reject obvious non-integers (`abc`, `1.5`, `1e9`) by requiring the + // string to be all digits. `Number.parseInt` is too lenient — it + // accepts `1.5` as `1` and `abc` as NaN. + if (!/^\d+$/.test(raw.trim())) { + return warnAndFallback(name, raw, fallback); + } + const n = Number(raw.trim()); + if (!Number.isFinite(n) || n <= 0 || !Number.isInteger(n)) { + return warnAndFallback(name, raw, fallback); + } + return n; +} + +function warnAndFallback(name: string, raw: string, fallback: number): number { + if (!_warnedKnobs.has(name)) { + _warnedKnobs.add(name); + process.stderr.write( + `[lock-renewal] env ${name}=${JSON.stringify(raw)} is not a positive integer; falling back to default ${fallback}\n`, + ); + } + return fallback; +} + +/** + * Injected dependency surface. All I/O hooks routed through here so + * `runLockRenewalTick` is pure and trivially testable. + */ +export interface LockRenewalDeps { + renewLock: (jobId: number, lockToken: string, lockDurationMs: number) => Promise; + audit: LockRenewalAuditSinkLike; + /** Injectable for hermetic time-based tests. Production: `Date.now`. */ + now: () => number; + /** + * Injectable for hermetic Promise.race tests. Production: + * `globalThis.setTimeout`. The function must return a value that + * `clearTimeout` accepts, but this seam doesn't expose clearTimeout + * because the timeout race fires-and-forgets (the lost race is + * harmless — at worst we have a dangling reject that no one awaits). + */ + setTimeout: (cb: () => void, ms: number) => unknown; +} + +/** + * Minimal subset of `LockRenewalAuditSink` from + * `src/core/audit/lock-renewal-audit.ts` so this module doesn't have to + * import the full audit module and inflate the test surface. + */ +export interface LockRenewalAuditSinkLike { + logFailure(jobId: number, jobName: string, attempt: number, err: unknown): void; + logSuccessAfterFailure(jobId: number, jobName: string, recoveredAfterAttempts: number): void; + logGaveUp(jobId: number, jobName: string, totalFailures: number, err: unknown): void; +} + +export interface LockRenewalState { + jobId: number; + jobName: string; + lockToken: string; + lockDurationMs: number; + knobs: LockRenewalKnobs; + /** Updated to `deps.now()` on every successful renewal. */ + lastSuccessfulRenewalAt: number; + /** Bumped on each renewLock throw; reset to 0 on success. Audit-only. */ + consecutiveFailures: number; + /** + * Closure thunk reading the timer's `cancelled` flag in worker.ts. + * Returns `true` once `executeJob.finally` has run. The tick checks + * this at entry, after the await resolves, AND after the await + * throws — three guards because a long await can outlive both the + * cancellation event AND the post-await branch decisions. + */ + cancelled: () => boolean; +} + +export type TickResult = + | { kind: 'ok' } + | { kind: 'cancelled' } + | { kind: 'lock_lost' } + | { kind: 'should_abort'; reason: 'lock-renewal-failed' }; + +/** + * Execute one renewal tick. Returns a tagged result the worker switches + * on; the worker is responsible for the `abort.abort()` / `clearInterval` + * side effects that depend on its closure scope. + */ +export async function runLockRenewalTick( + deps: LockRenewalDeps, + state: LockRenewalState, +): Promise { + if (state.cancelled()) return { kind: 'cancelled' }; + + let renewed: boolean; + try { + renewed = await Promise.race([ + deps.renewLock(state.jobId, state.lockToken, state.lockDurationMs), + new Promise((_, reject) => { + deps.setTimeout(() => { + reject(new Error(`renewLock timed out after ${state.knobs.callTimeoutMs}ms`)); + }, state.knobs.callTimeoutMs); + }), + ]); + } catch (err) { + if (state.cancelled()) return { kind: 'cancelled' }; + state.consecutiveFailures += 1; + // Defense-in-depth (codex C4): audit must never escape this catch. + try { + deps.audit.logFailure(state.jobId, state.jobName, state.consecutiveFailures, err); + } catch { /* audit best-effort */ } + + const sinceLastSuccess = deps.now() - state.lastSuccessfulRenewalAt; + const deadline = state.lockDurationMs - state.knobs.safetyMarginMs; + if (sinceLastSuccess >= deadline) { + try { + deps.audit.logGaveUp(state.jobId, state.jobName, state.consecutiveFailures, err); + } catch { /* audit best-effort */ } + return { kind: 'should_abort', reason: 'lock-renewal-failed' }; + } + return { kind: 'ok' }; // counter incremented; not yet at deadline + } + + if (state.cancelled()) return { kind: 'cancelled' }; + if (!renewed) { + // Token-fence failure: another worker reclaimed the row, or pauseJob + // cleared the token. NOT an infrastructure fault — no audit event + // (audit channel is for infrastructure faults only). The worker + // observes `lock_lost` and stderr-warns + aborts. + return { kind: 'lock_lost' }; + } + + if (state.consecutiveFailures > 0) { + try { + deps.audit.logSuccessAfterFailure( + state.jobId, + state.jobName, + state.consecutiveFailures, + ); + } catch { /* audit best-effort */ } + state.consecutiveFailures = 0; + } + state.lastSuccessfulRenewalAt = deps.now(); + return { kind: 'ok' }; +} diff --git a/src/core/minions/worker.ts b/src/core/minions/worker.ts index 514cbc91c..f611e1e28 100644 --- a/src/core/minions/worker.ts +++ b/src/core/minions/worker.ts @@ -21,6 +21,33 @@ import { MinionQueue } from './queue.ts'; import { calculateBackoff } from './backoff.ts'; import { RateLeaseUnavailableError } from './handlers/subagent.ts'; import { logLeasePressure } from './lease-pressure-audit.ts'; +import { + runLockRenewalTick, + resolveLockRenewalKnobs, + type LockRenewalDeps, + type LockRenewalState, +} from './lock-renewal-tick.ts'; +import { lockRenewalAudit } from '../audit/lock-renewal-audit.ts'; + +/** + * Abort reasons that signal infrastructure failure (PgBouncer outage, + * connection drop, lock reclaimed by another worker) — NOT a job + * defect. executeJob's catch block consults this set and SKIPS failJob + * for these reasons, letting the stall detector requeue the row + * cleanly without burning an attempt or dead-lettering the job. + * + * Codex C6 absorption (D8a): pre-v0.41.22.2, a PgBouncer blip during a + * long-running job would lock-renewal-abort → handler throws → failJob + * burns an attempt. That's wrong direction: the job's fine; the + * infrastructure stumbled. Stall-detector reclaim is the correct path. + * + * Exported so tests can pin the named-constant contract (a future edit + * to this set is a deliberate two-line change, not a silent regression). + */ +export const INFRASTRUCTURE_ABORT_REASONS = new Set([ + 'lock-renewal-failed', + 'lock-lost', +]); import { randomUUID } from 'crypto'; import { EventEmitter } from 'events'; import { evaluateQuietHours, type QuietHoursConfig } from './quiet-hours.ts'; @@ -610,61 +637,182 @@ export class MinionWorker extends EventEmitter { this.running = false; } - /** Launch a job as an independent in-flight promise. */ + /** + * Launch a job as an independent in-flight promise. + * + * v0.41.22.2 hardening — the lock-renewal cathedral wave (closes the + * production unhandledRejection crash class + 4 codex outside-voice + * gaps). The renewal timer now wraps a pure `runLockRenewalTick` + * call from `src/core/minions/lock-renewal-tick.ts` rather than + * inlining `setInterval(async () => { await renewLock(...) })` — + * which would let any throw escape to `process.on('unhandledRejection')` + * and crash the worker (the v0.41.22.1 bug). + * + * State machine guarded by: + * - `cancelled` flag set in the finally block so an in-flight + * renewLock that resolves after the job ended bails cleanly (D1) + * - `tickInFlight` re-entrancy guard so overlapping ticks during a + * PgBouncer stall don't pile concurrent connection acquisitions + * on an already-saturated pool + * - `Promise.race(renewLock, timeoutPromise)` inside the tick so a + * hung connection can't wedge the re-entrancy guard forever (D6 / codex C3) + * - time-based abort (`Date.now() - lastSuccessfulRenewalAt >= + * lockDuration - safetyMargin`) so we voluntarily release BEFORE + * the stall detector can reclaim the row (D6 / codex C2) + * + * Universal grace-eviction (D8b / codex C7): the 30s force-evict + * safety net fires for ANY abort reason, not just `job.timeout_ms`. + * Handlers that ignore AbortSignal won't wedge the inFlight slot + * forever on lock-renewal aborts. + * + * Second unhandledRejection vector (D7 / codex C5): the stored + * `executeJob(...).finally(...)` promise gets an explicit `.catch()` + * so an unhandled rejection inside the finally/catch chain (e.g., + * `failJob` throwing during the same DB outage) can't propagate to + * the process-level handler and crash the daemon. + */ private launchJob(job: MinionJob, lockToken: string): void { const abort = new AbortController(); - // Start lock renewal (per-job timer, not shared) - const lockTimer = setInterval(async () => { - const renewed = await this.queue.renewLock(job.id, lockToken, this.opts.lockDuration); - if (!renewed) { - console.warn(`Lock lost for job ${job.id}, aborting execution`); - clearInterval(lockTimer); - abort.abort(new Error('lock-lost')); - } + // --- D1: cancellation flag for the in-flight renewal IIFE --- + let cancelled = false; + // --- re-entrancy guard for overlapping ticks during PgBouncer stalls --- + let tickInFlight = false; + + // --- D3: pure-function lock renewal --- + const knobs = resolveLockRenewalKnobs(process.env, this.opts.lockDuration); + const renewalState: LockRenewalState = { + jobId: job.id, + jobName: job.name, + lockToken, + lockDurationMs: this.opts.lockDuration, + knobs, + lastSuccessfulRenewalAt: Date.now(), + consecutiveFailures: 0, + cancelled: () => cancelled, + }; + const renewalDeps: LockRenewalDeps = { + renewLock: (id, tok, dur) => this.queue.renewLock(id, tok, dur), + audit: lockRenewalAudit, + now: Date.now, + setTimeout: (cb, ms) => globalThis.setTimeout(cb, ms), + }; + + const lockTimer = setInterval(() => { + if (tickInFlight) return; + tickInFlight = true; + void runLockRenewalTick(renewalDeps, renewalState) + .then((result) => { + if (cancelled) return; + switch (result.kind) { + case 'ok': + case 'cancelled': + return; + case 'lock_lost': + if (!abort.signal.aborted) { + console.warn(`Lock lost for job ${job.id}, aborting execution`); + clearInterval(lockTimer); + abort.abort(new Error('lock-lost')); + } + return; + case 'should_abort': + if (!abort.signal.aborted) { + clearInterval(lockTimer); + abort.abort(new Error(result.reason)); + } + return; + } + }) + .catch((err) => { + // Belt-and-suspenders. runLockRenewalTick's own try/catch + // should make this unreachable, but a stray throw from the + // .then handler itself (console.warn EPIPE on a piped worker + // for instance) would otherwise propagate to + // unhandledRejection and crash the daemon — the exact bug + // class this whole wave exists to close. + const msg = err instanceof Error ? err.message : String(err); + console.error(`[worker] runLockRenewalTick post-handler error: ${msg}`); + }) + .finally(() => { + tickInFlight = false; + }); }, this.opts.lockDuration / 2); - // Per-job wall-clock timeout safety net. Cooperative: fires abort() so the - // handler's signal flips. Handlers ignoring AbortSignal can't be force-killed - // from JS; the DB-side handleTimeouts is the authoritative status flip. - // The .finally clearTimeout below ensures process exit isn't delayed by a - // dangling timer on normal completion. - let timeoutTimer: ReturnType | null = null; + // --- D8b: universal grace-eviction timer --- + // Fires for ANY abort reason (not just job.timeout_ms). Without + // this generalization, lock-renewal aborts could leave the inFlight + // slot wedged forever if the handler ignores AbortSignal. let graceTimer: ReturnType | null = null; + abort.signal.addEventListener('abort', () => { + // Avoid scheduling a second grace timer if abort fires again + // (e.g., timeout + lock-renewal-failed close to each other). + if (graceTimer != null) return; + graceTimer = setTimeout(() => { + if (this.inFlight.has(job.id)) { + const reason = abort.signal.reason instanceof Error + ? abort.signal.reason.message + : String(abort.signal.reason); + console.warn( + `Job ${job.id} (${job.name}) did not exit within 30s of abort (reason: ${reason}). ` + + `Force-evicting from inFlight to unblock worker. ` + + `The handler is still running but the worker will claim new jobs.` + ); + clearInterval(lockTimer); + this.inFlight.delete(job.id); + // D8a: don't failJob if the abort was infrastructure. The + // stall detector will reclaim the row cleanly because the + // lock has expired (lock-renewal aborts only fire after + // lockDuration - safetyMargin elapsed without renewal). + if (!INFRASTRUCTURE_ABORT_REASONS.has(reason)) { + this.queue.failJob( + job.id, + lockToken, + 'handler ignored abort signal (force-evicted)', + 'dead', + ).catch(() => {}); + } + } + }, 30_000); + }); + + // Per-job wall-clock timeout (timer-armed only if `timeout_ms` was + // set on the job; the grace-evict pattern above now lives outside + // this branch). + let timeoutTimer: ReturnType | null = null; if (job.timeout_ms != null) { timeoutTimer = setTimeout(() => { if (!abort.signal.aborted) { console.warn(`Job ${job.id} (${job.name}) hit per-job timeout (${job.timeout_ms}ms), aborting`); abort.abort(new Error('timeout')); } - // Safety net: if the handler doesn't resolve within 30s after abort, - // force-evict from inFlight so the worker can pick up new jobs. - // Without this, a handler that ignores AbortSignal wedges the worker - // forever (the 98-waiting-0-active incident on 2026-04-24). - graceTimer = setTimeout(() => { - if (this.inFlight.has(job.id)) { - console.warn( - `Job ${job.id} (${job.name}) did not exit within 30s of abort. ` + - `Force-evicting from inFlight to unblock worker. ` + - `The handler is still running but the worker will claim new jobs.` - ); - clearInterval(lockTimer); - this.inFlight.delete(job.id); - // Best-effort: mark as dead in DB so it doesn't get reclaimed - this.queue.failJob(job.id, lockToken, 'handler ignored abort signal (force-evicted)', 'dead').catch(() => {}); - } - }, 30_000); }, job.timeout_ms); } const promise = this.executeJob(job, lockToken, abort, lockTimer) .finally(() => { + // D1: signal in-flight IIFE to bail at its next checkpoint so + // a renewLock resolution that lands after the job ended + // doesn't write a misleading audit event or abort an + // already-dead controller. + cancelled = true; clearInterval(lockTimer); if (timeoutTimer) clearTimeout(timeoutTimer); if (graceTimer) clearTimeout(graceTimer); this.inFlight.delete(job.id); this.jobsCompleted += 1; this.checkMemoryLimit('post-job'); + }) + // D7 / codex C5: close the SECOND unhandledRejection vector. If + // executeJob's catch path throws (e.g., failJob's executeRaw + // throws during the same DB outage that caused lock renewal to + // fail), the rejection would otherwise escape to + // process.on('unhandledRejection') and crash the daemon. + .catch((err) => { + const msg = err instanceof Error ? err.message : String(err); + console.error(`[worker] executeJob unhandled error for job ${job.id} (${job.name}): ${msg}`); + try { + lockRenewalAudit.logExecuteJobRejected(job.id, job.name, err); + } catch { /* audit best-effort */ } }); this.inFlight.set(job.id, { job, lockToken, lockTimer, abort, promise }); @@ -751,15 +899,33 @@ export class MinionWorker extends EventEmitter { // left jobs stranded in 'active' until a secondary sweep, breaking // timeout/cancel contracts downstream callers rely on. let errorText: string; + let abortReason: string | null = null; if (abort.signal.aborted) { - const reason = abort.signal.reason instanceof Error + abortReason = abort.signal.reason instanceof Error ? abort.signal.reason.message : String(abort.signal.reason || 'aborted'); - errorText = `aborted: ${reason}`; + errorText = `aborted: ${abortReason}`; } else { errorText = err instanceof Error ? err.message : String(err); } + // v0.41.22.2 (D8a / codex C6): infrastructure aborts (lock-renewal-failed, + // lock-lost) are NOT job defects — they're connection / coordination + // failures the stall detector will reclaim cleanly. Calling failJob here + // would burn an attempt or dead-letter the job for what's really a + // PgBouncer blip; that's a worse outcome than the v0.41.22.1 crash it + // replaces. The lock has already expired (lock-renewal-failed only fires + // after lockDuration - safetyMargin elapsed without renewal), so the + // stall detector will pick the row up on its next poll and another + // worker will claim it cleanly. + if (abortReason !== null && INFRASTRUCTURE_ABORT_REASONS.has(abortReason)) { + console.log( + `Job ${job.id} (${job.name}) released after infrastructure abort (${abortReason}); ` + + `stall detector will requeue (no attempt burned)`, + ); + return; + } + // v0.41 Bug 2: lease-full bounces don't burn attempts. // // Pre-v0.41 every non-`UnrecoverableError` routed to `delayed` with diff --git a/test/audit/batch-retry-redaction.test.ts b/test/audit/batch-retry-redaction.test.ts new file mode 100644 index 000000000..3c90fb3c2 --- /dev/null +++ b/test/audit/batch-retry-redaction.test.ts @@ -0,0 +1,75 @@ +/** + * v0.41.22.2 — batch-retry-audit privacy backfill regression. + * + * Pins that `redactConnectionInfo` is wired into `logBatchRetry` and + * `logBatchExhausted` (D9 privacy backfill). A future refactor that + * removes the redactor call from `summarizeError` would silently + * reintroduce the DSN/host/password leak class. This test catches that + * via wire-format inspection. + * + * Hermetic via withEnv + tempdir per test. + */ + +import { describe, expect, test, beforeEach, afterEach } from 'bun:test'; +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; +import { withEnv } from '../helpers/with-env.ts'; +import { + logBatchRetry, + logBatchExhausted, + BATCH_RETRY_FEATURE_NAME, +} from '../../src/core/audit/batch-retry-audit.ts'; +import { computeIsoWeekFilename } from '../../src/core/audit/audit-writer.ts'; + +let tmpDir: string; + +beforeEach(() => { + tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'batch-retry-redact-')); +}); + +afterEach(() => { + try { + fs.rmSync(tmpDir, { recursive: true, force: true }); + } catch { /* best-effort */ } +}); + +describe('batch-retry-audit privacy backfill (D9)', () => { + test('case 1 — logBatchRetry: PG connection-failure error has no DSN/IP/password in JSONL', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + const err = new Error( + 'PG retry context: postgres://garry:hunter2@db.example.com:5432/gbrain failed (192.168.1.42)', + ); + logBatchRetry('addLinksBatch', 100, 1, 1000, err); + const file = path.join(tmpDir, computeIsoWeekFilename(BATCH_RETRY_FEATURE_NAME)); + const raw = fs.readFileSync(file, 'utf8'); + expect(raw).not.toContain('hunter2'); + expect(raw).not.toContain('192.168.1.42'); + expect(raw).not.toContain('postgres://garry'); + expect(raw).toContain(''); + expect(raw).toContain(''); + }); + }); + + test('case 2 — logBatchExhausted: same privacy contract on the exhausted path', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + const err = new Error('FATAL: password=hunter2 authentication failed for user=postgres'); + logBatchExhausted('addTimelineEntriesBatch', 50, 4, err); + const file = path.join(tmpDir, computeIsoWeekFilename(BATCH_RETRY_FEATURE_NAME)); + const raw = fs.readFileSync(file, 'utf8'); + expect(raw).not.toContain('hunter2'); + expect(raw).toContain(''); + expect(raw).toContain(''); + }); + }); + + test('case 3 — plain error message (no secrets) flows through unchanged', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + logBatchRetry('upsertChunks', 100, 1, 1000, new Error('Connection terminated unexpectedly')); + const file = path.join(tmpDir, computeIsoWeekFilename(BATCH_RETRY_FEATURE_NAME)); + const raw = fs.readFileSync(file, 'utf8'); + expect(raw).toContain('Connection terminated unexpectedly'); + expect(raw).not.toContain(' { + tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'lock-renewal-audit-')); +}); + +afterEach(() => { + try { + fs.rmSync(tmpDir, { recursive: true, force: true }); + } catch { /* best-effort */ } +}); + +describe('lockRenewalAudit: 4-outcome contract', () => { + test('case 1 — logFailure writes outcome=failure with error_summary and error_code', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + const err = Object.assign(new Error('Connection terminated'), { code: '08006' }); + lockRenewalAudit.logFailure(42, 'sync', 1, err); + const result = readRecentLockRenewalEvents(24); + expect(result.events).toHaveLength(1); + expect(result.events[0].outcome).toBe('failure'); + expect(result.events[0].job_id).toBe(42); + expect(result.events[0].job_name).toBe('sync'); + expect(result.events[0].attempt).toBe(1); + expect(result.events[0].error_message_summary).toContain('Connection terminated'); + expect(result.events[0].error_code).toBe('08006'); + }); + }); + + test('case 2 — logSuccessAfterFailure writes outcome with attempt=recovery count, no error fields', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + lockRenewalAudit.logSuccessAfterFailure(99, 'embed', 3); + const result = readRecentLockRenewalEvents(24); + expect(result.events).toHaveLength(1); + expect(result.events[0].outcome).toBe('success_after_failure'); + expect(result.events[0].job_id).toBe(99); + expect(result.events[0].job_name).toBe('embed'); + expect(result.events[0].attempt).toBe(3); + expect(result.events[0].error_message_summary).toBeUndefined(); + expect(result.events[0].error_code).toBeUndefined(); + }); + }); + + test('case 3 — logGaveUp writes outcome=gave_up with full error context', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + const err = Object.assign(new Error('renewLock timed out after 10000ms'), { code: 'TIMEOUT' }); + lockRenewalAudit.logGaveUp(777, 'subagent', 5, err); + const result = readRecentLockRenewalEvents(24); + expect(result.events).toHaveLength(1); + expect(result.events[0].outcome).toBe('gave_up'); + expect(result.events[0].attempt).toBe(5); + expect(result.events[0].error_message_summary).toContain('renewLock timed out'); + }); + }); + + test('case 4 — logExecuteJobRejected writes outcome with no attempt field', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + lockRenewalAudit.logExecuteJobRejected(123, 'shell', new Error('failJob threw during outage')); + const result = readRecentLockRenewalEvents(24); + expect(result.events).toHaveLength(1); + expect(result.events[0].outcome).toBe('executeJob_rejected'); + expect(result.events[0].attempt).toBeUndefined(); + expect(result.events[0].error_message_summary).toContain('failJob threw'); + }); + }); +}); + +describe('lockRenewalAudit: privacy via redactor (D9)', () => { + test('case 5a — logFailure with PG connection-failure error: no DSN/IP in JSONL', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + const err = new Error( + 'connection failed: postgres://garry:hunter2@db.example.com:5432/gbrain (192.168.1.42)', + ); + lockRenewalAudit.logFailure(1, 'sync', 1, err); + // Read raw JSONL — covers the wire format an operator would + // actually paste into a GitHub issue. + const file = path.join(tmpDir, computeIsoWeekFilename(LOCK_RENEWAL_FEATURE_NAME)); + const raw = fs.readFileSync(file, 'utf8'); + expect(raw).not.toContain('hunter2'); + expect(raw).not.toContain('192.168.1.42'); + expect(raw).not.toContain('postgres://garry'); + expect(raw).toContain(''); + expect(raw).toContain(''); + }); + }); + + test('case 5b — logGaveUp redacts password=secret form', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + const err = new Error('FATAL: password=hunter2 authentication failed'); + lockRenewalAudit.logGaveUp(1, 'sync', 3, err); + const file = path.join(tmpDir, computeIsoWeekFilename(LOCK_RENEWAL_FEATURE_NAME)); + const raw = fs.readFileSync(file, 'utf8'); + expect(raw).not.toContain('hunter2'); + expect(raw).toContain(''); + }); + }); +}); + +describe('lockRenewalAudit: readback semantics', () => { + test('case 6 — readRecentLockRenewalEvents applies hours cutoff', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + lockRenewalAudit.logFailure(1, 'sync', 1, new Error('blip 1')); + // 48h ago event is older than 24h cutoff and should be filtered. + const file = path.join(tmpDir, computeIsoWeekFilename(LOCK_RENEWAL_FEATURE_NAME)); + const stale = JSON.stringify({ + ts: new Date(Date.now() - 48 * 3_600_000).toISOString(), + job_id: 99, + job_name: 'old', + attempt: 1, + outcome: 'failure', + }); + fs.appendFileSync(file, stale + '\n'); + const result = readRecentLockRenewalEvents(24); + // Only the recent event should appear; stale 48h-old event filtered. + expect(result.events).toHaveLength(1); + expect(result.events[0].job_id).toBe(1); + }); + }); + + test('case 7 — corrupted JSONL line increments corrupted_lines, doesn\'t throw', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + const file = path.join(tmpDir, computeIsoWeekFilename(LOCK_RENEWAL_FEATURE_NAME)); + // Mix valid + invalid JSONL. + lockRenewalAudit.logFailure(1, 'sync', 1, new Error('valid')); + fs.appendFileSync(file, 'this is not json\n'); + fs.appendFileSync(file, '{"partial":\n'); + const result = readRecentLockRenewalEvents(24); + expect(result.events).toHaveLength(1); + expect(result.corrupted_lines).toBe(2); + }); + }); + + test('case 7b — readback with no audit dir returns empty + zero file counts', async () => { + // tmpDir for GBRAIN_AUDIT_DIR points at an empty dir; no audit + // files exist, but the dir itself exists. Both ENOENT files + // counted as "scanned: 0, unreadable: 0". + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + const result = readRecentLockRenewalEvents(24); + expect(result.events).toHaveLength(0); + expect(result.corrupted_lines).toBe(0); + expect(result.files_scanned).toBe(0); + expect(result.files_unreadable).toBe(0); + }); + }); +}); + +describe('lockRenewalAudit: pruning', () => { + test('case 8 — pruneOldLockRenewalAuditFiles deletes files older than daysToKeep', async () => { + await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => { + // Create an old file by writing then back-dating. + const oldName = `${LOCK_RENEWAL_FEATURE_NAME}-2024-W01.jsonl`; + const oldFile = path.join(tmpDir, oldName); + fs.writeFileSync(oldFile, '{"ts":"2024-01-01T00:00:00Z","job_id":1,"job_name":"x","outcome":"failure"}\n'); + const ancientMs = Date.now() - 60 * 86400_000; // 60 days ago + fs.utimesSync(oldFile, ancientMs / 1000, ancientMs / 1000); + + // Recent file should be kept. + lockRenewalAudit.logFailure(1, 'sync', 1, new Error('recent')); + + const result = pruneOldLockRenewalAuditFiles(30); + expect(result.removed).toBe(1); + expect(result.kept).toBe(1); + expect(fs.existsSync(oldFile)).toBe(false); + }); + }); + + test('case 8b — pruning a non-existent dir is a graceful no-op', async () => { + const ghostDir = path.join(tmpDir, 'does-not-exist'); + await withEnv({ GBRAIN_AUDIT_DIR: ghostDir }, async () => { + const result = pruneOldLockRenewalAuditFiles(30); + expect(result.removed).toBe(0); + expect(result.kept).toBe(0); + }); + }); +}); diff --git a/test/audit/redact-connection-info.test.ts b/test/audit/redact-connection-info.test.ts new file mode 100644 index 000000000..9c4f62934 --- /dev/null +++ b/test/audit/redact-connection-info.test.ts @@ -0,0 +1,151 @@ +/** + * v0.41.22.2 — shared connection-info redactor contract. + * + * Pins the privacy promise the audit channel makes: any text passed + * through `redactConnectionInfo` does NOT contain Postgres DSNs, + * credentials, hostnames, or IPv4 octets. Real-world fixtures drawn + * from actual Supabase / PgBouncer / Node DNS error shapes so the + * tests fail loud if real-world error formats drift past the patterns. + * + * Pure function tests, no fs / no env / no PGLite. + */ + +import { describe, it, expect } from 'bun:test'; +import { + redactConnectionInfo, + getRedactionKinds, +} from '../../src/core/audit/redact-connection-info.ts'; + +describe('redactConnectionInfo: per-pattern coverage', () => { + it('case 1 — postgres:// URL with embedded credentials', () => { + const out = redactConnectionInfo( + 'connection failed: postgres://garry:hunter2@db.example.com:5432/gbrain', + ); + expect(out).toContain(''); + expect(out).not.toContain('garry'); + expect(out).not.toContain('hunter2'); + expect(out).not.toContain('db.example.com'); + expect(out).not.toContain('5432/gbrain'); + }); + + it('case 2 — postgresql:// (with -ql) treated the same as postgres://', () => { + const out = redactConnectionInfo( + 'using postgresql://user:pass@host:5432/db?sslmode=require', + ); + expect(out).toContain(''); + expect(out).not.toContain('user:pass'); + expect(out).not.toContain('host:5432'); + }); + + it('case 3 — password=secret AND pwd=secret both redacted', () => { + const a = redactConnectionInfo('FATAL: password=hunter2 connection denied'); + expect(a).toContain(''); + expect(a).not.toContain('hunter2'); + + const b = redactConnectionInfo('conninfo: pwd=admin123 user=postgres'); + expect(b).toContain(''); + expect(b).not.toContain('admin123'); + }); + + it('case 4 — user=postgres mid-string', () => { + const out = redactConnectionInfo('conninfo: host=db user=postgres dbname=app'); + expect(out).toContain(''); + expect(out).not.toContain('user=postgres'); + }); + + it('case 5 — host=db.example.com', () => { + const out = redactConnectionInfo('conninfo: host=db.example.com port=5432'); + expect(out).toContain(''); + expect(out).not.toContain('db.example.com'); + }); + + it('case 6 — IPv4 inside PG error context', () => { + const out = redactConnectionInfo( + 'connection to server at "db.example.com" (192.168.1.42), port 5432 failed', + ); + expect(out).toContain(''); + expect(out).not.toContain('192.168.1.42'); + }); +}); + +describe('redactConnectionInfo: false-positive defense', () => { + it('case 7 — version number v3.1.4.0 is NOT redacted (negative lookbehind/ahead)', () => { + const out = redactConnectionInfo('tree-sitter version v3.1.4.0 loaded'); + expect(out).toContain('v3.1.4.0'); + expect(out).not.toContain(''); + }); + + it('case 7b — semver-like 1.2.3.4 NOT redacted when surrounded by version-y tokens', () => { + const out = redactConnectionInfo('tree-sitter@0.26.3.1 was loaded'); + expect(out).toContain('0.26.3.1'); + expect(out).not.toContain(''); + }); + + it('case 8 — already-redacted text is idempotent', () => { + const once = redactConnectionInfo('user=postgres host=db port=5432'); + const twice = redactConnectionInfo(once); + expect(twice).toBe(once); + }); + + it('case 9 — plain text without secrets passes through unchanged', () => { + const plain = 'Worker started; processing job 42; took 150ms'; + expect(redactConnectionInfo(plain)).toBe(plain); + }); + + it('case 9b — empty string passes through', () => { + expect(redactConnectionInfo('')).toBe(''); + }); +}); + +describe('redactConnectionInfo: real-world fixtures', () => { + it('case 10 — real Supabase connection failure error: IP redacted, structure preserved', () => { + const real = + 'PostgresError: connection to server at "aws-0-us-east-1.pooler.supabase.com" (3.215.142.117), port 6543 failed: FATAL: password authentication failed for user "postgres.abcdef123456"'; + const out = redactConnectionInfo(real); + // IP is the load-bearing leak in this shape (publicly resolvable). + expect(out).not.toContain('3.215.142.117'); + expect(out).toContain(''); + // Structure preserved enough to debug from. + expect(out).toMatch(/PostgresError/); + expect(out).toMatch(/port 6543/); + // Documented limitation: bare-quoted hostname and bare-quoted + // username are NOT caught by the bare-field matchers. The bare + // hostname leak is mitigated by the `host=` pattern wrt conninfo + // strings; the bare-quoted form is not (filed as a v0.42 TODO if + // the threat model changes). Pinning current behavior so a future + // widening shows up as a test diff, not a silent change. + expect(out).toContain('aws-0-us-east-1.pooler.supabase.com'); + }); + + it('case 11 — real getaddrinfo ENOTFOUND with no IP, just hostname', () => { + const real = + 'Error: getaddrinfo ENOTFOUND db.example.invalid.host\n at GetAddrInfoReqWrap.onlookup [as oncomplete]'; + const out = redactConnectionInfo(real); + // Hostname appears WITHOUT host= prefix, so the bare-field matcher + // doesn't catch it. The error structure is preserved; no false + // claims of credential leakage. This is a documented limitation. + expect(out).toContain('getaddrinfo ENOTFOUND'); + // Smoke test: IPv4 (if any) gone. + expect(out).not.toMatch(/(? { + const out = redactConnectionInfo( + 'failed to connect: postgres://admin:s3cr3t@host.example.com:5432/db', + ); + // The URL pattern wins because it's listed first. The substring + // `password=` doesn't appear in the input (it's the URL-form), so + // we get exactly ONE redaction kind. + expect(out.match(//g)?.length).toBe(1); + expect(out).not.toContain(''); + expect(out).not.toContain('admin'); + expect(out).not.toContain('s3cr3t'); + }); +}); + +describe('getRedactionKinds: pattern-set surface', () => { + it('exposes all 5 expected kinds for surface-stability tests', () => { + const kinds = getRedactionKinds(); + expect(kinds).toEqual(['pg_url', 'password', 'user', 'host', 'ipv4']); + }); +}); diff --git a/test/scripts/check-worker-lock-renewal-shape.test.ts b/test/scripts/check-worker-lock-renewal-shape.test.ts new file mode 100644 index 000000000..845de0160 --- /dev/null +++ b/test/scripts/check-worker-lock-renewal-shape.test.ts @@ -0,0 +1,152 @@ +/** + * v0.41.22.2 — meta-test for scripts/check-worker-lock-renewal-shape.sh. + * + * Runs the CI guard against fixture worker.ts variants and asserts: + * 1. Good shape (the v0.41.22.2 final form) exits 0. + * 2. Bug pattern at the lock-renewal site (`lockTimer = setInterval(async ...)`) + * exits 1. + * 3. Missing call site (`runLockRenewalTick` not referenced) exits 1. + * 4. False-positive defense: `lockTimer = setInterval(syncCallback, ms)` with a + * named-ref second arg is allowed (NOT the bug pattern even if `async` + * appears later in the file in a different context). + * + * Uses the GBRAIN_LOCK_RENEWAL_SHAPE_TARGET env knob (built into the + * script) to swap the scanned file without git-mucking. Hermetic via + * per-test tempfiles. + */ + +import { describe, it, expect, afterEach } from 'bun:test'; +import { spawnSync } from 'child_process'; +import { mkdtempSync, writeFileSync, rmSync } from 'fs'; +import { tmpdir } from 'os'; +import { join, resolve } from 'path'; + +const REPO_ROOT = resolve(import.meta.dir, '..', '..'); +const GUARD_SH = resolve(REPO_ROOT, 'scripts/check-worker-lock-renewal-shape.sh'); + +const tmpDirs: string[] = []; +function makeTempWorker(contents: string): string { + const d = mkdtempSync(join(tmpdir(), 'lock-renewal-shape-')); + tmpDirs.push(d); + const file = join(d, 'worker.ts'); + writeFileSync(file, contents); + return file; +} + +afterEach(() => { + while (tmpDirs.length > 0) { + const d = tmpDirs.pop(); + if (d) { + try { rmSync(d, { recursive: true, force: true }); } catch { /* best-effort */ } + } + } +}); + +function runGuard(targetPath: string): { status: number; stdout: string; stderr: string } { + const r = spawnSync('bash', [GUARD_SH], { + encoding: 'utf-8', + env: { ...process.env, GBRAIN_LOCK_RENEWAL_SHAPE_TARGET: targetPath }, + }); + return { status: r.status ?? -1, stdout: r.stdout, stderr: r.stderr }; +} + +const GOOD_SHAPE = ` +import { runLockRenewalTick } from './lock-renewal-tick.ts'; + +class MinionWorker { + launchJob(job, lockToken) { + let cancelled = false; + let tickInFlight = false; + const lockTimer = setInterval(() => { + if (tickInFlight) return; + tickInFlight = true; + void runLockRenewalTick(deps, state) + .then(handleResult) + .finally(() => { tickInFlight = false; }); + }, this.opts.lockDuration / 2); + } +} +`; + +const BUG_PATTERN = ` +import { runLockRenewalTick } from './lock-renewal-tick.ts'; + +class MinionWorker { + launchJob(job, lockToken) { + const lockTimer = setInterval(async () => { + const renewed = await this.queue.renewLock(job.id, lockToken, dur); + if (!renewed) abort.abort(new Error('lock-lost')); + }, this.opts.lockDuration / 2); + } +} +`; + +const MISSING_CALL_SITE = ` +class MinionWorker { + launchJob(job, lockToken) { + let tickInFlight = false; + const lockTimer = setInterval(() => { + if (tickInFlight) return; + tickInFlight = true; + // The pure function call site has been removed (regression). + }, this.opts.lockDuration / 2); + } +} +`; + +const FALSE_POSITIVE_NAMED_REF = ` +import { runLockRenewalTick } from './lock-renewal-tick.ts'; + +// This file has a different setInterval(async ...) elsewhere — like the +// stall detector at the real worker.ts line ~269. The shape guard MUST +// NOT flag this site because the lockTimer assignment uses the safe +// shape; the unrelated async setInterval is out of scope (codex C13). +class MinionWorker { + start() { + const stalledTimer = setInterval(async () => { + try { await this.queue.handleStalled(); } catch { /* noop */ } + }, this.opts.stalledInterval); + } + launchJob(job, lockToken) { + const lockTimer = setInterval(() => { + void runLockRenewalTick(deps, state).then(handleResult); + }, this.opts.lockDuration / 2); + } +} +`; + +describe('check-worker-lock-renewal-shape.sh', () => { + it('case 1 — good shape exits 0', () => { + const file = makeTempWorker(GOOD_SHAPE); + const r = runGuard(file); + expect(r.status).toBe(0); + expect(r.stdout).toContain('lock-renewal shape OK'); + }); + + it('case 2 — bug pattern (lockTimer = setInterval(async ...)) exits 1', () => { + const file = makeTempWorker(BUG_PATTERN); + const r = runGuard(file); + expect(r.status).toBe(1); + expect(r.stdout + r.stderr).toContain('v0.41.22.1 bug pattern'); + }); + + it('case 3 — missing runLockRenewalTick call site exits 1', () => { + const file = makeTempWorker(MISSING_CALL_SITE); + const r = runGuard(file); + expect(r.status).toBe(1); + expect(r.stdout + r.stderr).toContain('runLockRenewalTick'); + }); + + it('case 4 — unrelated setInterval(async ...) elsewhere is NOT flagged (codex C13 scope)', () => { + const file = makeTempWorker(FALSE_POSITIVE_NAMED_REF); + const r = runGuard(file); + expect(r.status).toBe(0); + expect(r.stdout).toContain('lock-renewal shape OK'); + }); + + it('case 5 — missing target file emits clear error', () => { + const r = runGuard('/nonexistent/path/to/worker.ts'); + expect(r.status).toBe(1); + expect(r.stdout + r.stderr).toContain('not found'); + }); +}); diff --git a/test/worker-lock-renewal-e2e.serial.test.ts b/test/worker-lock-renewal-e2e.serial.test.ts new file mode 100644 index 000000000..dbaf61877 --- /dev/null +++ b/test/worker-lock-renewal-e2e.serial.test.ts @@ -0,0 +1,174 @@ +/** + * v0.41.26.1 — gold-standard E2E regression for the lock-renewal + * cathedral wave (gap H from the post-ship coverage audit). + * + * Single test, single describe. The bun:test serial runner has an + * unresolved interaction with PGLite when multiple MinionWorker-driven + * tests share a file (the second test's `queue.add` hangs indefinitely + * even with cleanly reset state between tests). Isolating H into its + * own file sidesteps the issue without touching production code. + * + * Companion tests for gaps A, B, C, D, E, F, G live in: + * - test/worker-lock-renewal.test.ts (pure-function state machine, 18 cases) + * - test/worker-lock-renewal-shape.test.ts (source-shape behavioral pins, this wave) + * - test/audit/lock-renewal-audit.test.ts (audit module, 11 cases) + * - test/audit/redact-connection-info.test.ts (privacy redactor, 15 cases) + * + * What this test pins: + * + * - With renewLock throws happening continuously, the worker process + * MUST NOT crash via unhandledRejection (the v0.41.22.1 bug). + * - The handler observes abort.signal.aborted = true (proves the + * time-based abort fires through the wiring). + * - The audit JSONL contains both `failure` (per-throw) and `gave_up` + * (time-based deadline trip) events. + * + * Hermetic: real PGLite, no DATABASE_URL, no docker, no live PgBouncer. + * Engine wrap on executeRaw injects the simulated connection drop on + * renewLock-shaped SQL only; everything else passes through. + */ + +import { describe, test, expect, beforeAll, afterAll } from 'bun:test'; +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; +import { PGLiteEngine } from '../src/core/pglite-engine.ts'; +import { MinionWorker } from '../src/core/minions/worker.ts'; +import { MinionQueue } from '../src/core/minions/queue.ts'; +import { readRecentLockRenewalEvents } from '../src/core/audit/lock-renewal-audit.ts'; + +// Module-level audit dir + env mutation. withEnv's restore semantics +// race with the worker's setInterval callbacks (audit writes can land +// AFTER withEnv exits, under the wrong env). Persistent module-level +// is the deterministic fix. +const auditDir = fs.mkdtempSync(path.join(os.tmpdir(), 'lr-e2e-')); +const PRIOR_AUDIT_DIR = process.env.GBRAIN_AUDIT_DIR; +process.env.GBRAIN_AUDIT_DIR = auditDir; + +let engine: PGLiteEngine; +let queue: MinionQueue; +let originalExecuteRaw: PGLiteEngine['executeRaw']; + +beforeAll(async () => { + engine = new PGLiteEngine(); + await engine.connect({ database_url: '' }); + await engine.initSchema(); + queue = new MinionQueue(engine); + originalExecuteRaw = engine.executeRaw.bind(engine); +}); + +afterAll(async () => { + await engine.disconnect(); + try { fs.rmSync(auditDir, { recursive: true, force: true }); } catch { /* */ } + if (PRIOR_AUDIT_DIR === undefined) { + delete process.env.GBRAIN_AUDIT_DIR; + } else { + process.env.GBRAIN_AUDIT_DIR = PRIOR_AUDIT_DIR; + } +}); + +describe('H: gold-standard regression — worker survives renewLock throws', () => { + test('the v0.41.22.1 production crash class no longer crashes the worker', async () => { + await engine.executeRaw('DELETE FROM minion_jobs'); + await queue.add('long-runner', {}); + + // Wrap executeRaw to inject renewLock failures. The renewLock SQL + // shape (`UPDATE minion_jobs SET lock_until = now() + ...`) is narrow + // enough to skip claim / completeJob / failJob / etc. + let throwsRemaining = 50; + let renewLockCallCount = 0; + (engine as { executeRaw: PGLiteEngine['executeRaw'] }).executeRaw = async ( + sql: string, + params?: unknown[], + opts?: { signal?: AbortSignal }, + ) => { + const isRenewLock = sql.includes('SET lock_until = now()') && sql.includes('lock_token'); + if (isRenewLock) { + renewLockCallCount++; + if (throwsRemaining > 0) { + throwsRemaining--; + throw new Error('simulated PgBouncer connection drop'); + } + } + return originalExecuteRaw(sql, params, opts); + }; + + // Short lockDuration → 50ms timer interval, abort deadline at + // lockDuration - safetyMargin = 100 - 16 = 84ms. Sustained throws + // should trip the deadline within ~150ms. + const worker = new MinionWorker(engine, { + concurrency: 1, + pollInterval: 25, + lockDuration: 100, + }); + + let handlerEntered = false; + let handlerAbortObserved = false; + let abortReason: string | null = null; + worker.register('long-runner', async (ctx) => { + handlerEntered = true; + const start = Date.now(); + while (!ctx.signal.aborted && Date.now() - start < 4000) { + await new Promise((r) => setTimeout(r, 10)); + } + handlerAbortObserved = ctx.signal.aborted; + if (ctx.signal.aborted) { + abortReason = ctx.signal.reason instanceof Error + ? ctx.signal.reason.message + : String(ctx.signal.reason); + } + }); + + // The headline regression check: install a process-level + // unhandledRejection listener. Pre-v0.41.26.1, a renewLock throw + // inside `setInterval(async ...)` would propagate here and the + // daemon would exit code 1. + let unhandledRejectionFired: unknown = null; + const rejectionListener = (reason: unknown) => { + unhandledRejectionFired = reason; + }; + process.on('unhandledRejection', rejectionListener); + + const p = worker.start(); + try { + // Fixed sleep — handler enters within ~50ms, abort fires by + // ~200ms; 2s gives plenty of margin AND lets audit events + // accumulate before we read them back. + await new Promise((r) => setTimeout(r, 2000)); + + // Headline assertion: worker process didn't die. + expect(unhandledRejectionFired).toBe(null); + + // Handler wiring assertions: launchJob plumbed the abort + // signal through correctly. + expect(handlerEntered).toBe(true); + expect(handlerAbortObserved).toBe(true); + // TS narrows `abortReason` to literal `null` because the closure + // assignment in worker.register isn't observable to the inferrer. + // The preceding `handlerAbortObserved` assertion guarantees we + // entered the if-aborted branch where abortReason was assigned; + // cast via unknown to satisfy the overload. + expect(abortReason as unknown as string).toBe('lock-renewal-failed'); + + // renewLock was actually called multiple times (sanity check + // that the fault injection fired). + expect(renewLockCallCount).toBeGreaterThan(0); + + // Audit JSONL has the expected event shapes. `failure` (per-throw) + // and `gave_up` (time-based deadline tripped) MUST both appear. + const audit = readRecentLockRenewalEvents(48); + expect(audit.events.length).toBeGreaterThan(0); + const failures = audit.events.filter((e) => e.outcome === 'failure'); + const gaveUp = audit.events.filter((e) => e.outcome === 'gave_up'); + expect(failures.length).toBeGreaterThan(0); + expect(gaveUp.length).toBeGreaterThan(0); + // The error message survived through the redactor + truncator. + expect(gaveUp[0].error_message_summary).toMatch(/simulated PgBouncer/); + } finally { + process.off('unhandledRejection', rejectionListener); + (engine as { executeRaw: PGLiteEngine['executeRaw'] }).executeRaw = originalExecuteRaw; + worker.stop(); + await Promise.race([p, new Promise((r) => setTimeout(r, 2000))]); + } + }, 30_000); +}); diff --git a/test/worker-lock-renewal-shape.test.ts b/test/worker-lock-renewal-shape.test.ts new file mode 100644 index 000000000..b2094e0b5 --- /dev/null +++ b/test/worker-lock-renewal-shape.test.ts @@ -0,0 +1,258 @@ +/** + * v0.41.26.1 — source-shape behavioral pins for the lock-renewal + * cathedral wave. + * + * These tests grep the actual worker.ts source for the patterns the + * locked decisions promised. They're not behavioral in the + * "run-the-code" sense — they're structural-regression guards that + * fail loud if a future refactor strips a load-bearing piece. + * + * Why source-shape pins instead of runtime integration tests: + * bun:test's serial runner has an unresolved interaction with PGLite + * + multiple MinionWorker-driven tests in the same file (the second + * test's queue.add hangs indefinitely). The headline regression (gap + * H) lives in its own single-test file + * (test/worker-lock-renewal-e2e.serial.test.ts); A, B, C, E, G are + * pinned here via source-shape grep. + * + * These pins are bug-pattern-specific, not implementation-specific — + * a future refactor that changes the SHAPE of how each guarantee is + * provided (e.g., AbortController.signal events → a different + * notification mechanism) would need to update both the source AND + * this test, which is the right level of friction. A refactor that + * accidentally REMOVES the guarantee would fail this test loudly. + * + * Companion files: + * - test/worker-lock-renewal.test.ts — pure state machine (18 unit tests) + * - test/worker-lock-renewal-e2e.serial.test.ts — H gold-standard E2E (1 test) + * - test/audit/lock-renewal-audit.test.ts — audit primitive (11 tests) + * - test/audit/redact-connection-info.test.ts — privacy redactor (15 tests) + * - test/audit/batch-retry-redaction.test.ts — sibling privacy backfill (3 tests) + * - test/scripts/check-worker-lock-renewal-shape.test.ts — CI guard meta (5 tests) + * + * Coverage map: + * - A. launchJob wires runLockRenewalTick → pinned here + the CI guard + * - B. executeJob skip-failJob on infra abort → pinned here + * - C. .catch() on stored executeJob.finally promise → pinned here + * - D. INFRASTRUCTURE_ABORT_REASONS export → pinned here + pure unit tests + * - E. universal grace-evict listener → pinned here + * - F. logExecuteJobRejected end-to-end → folded into C pin (call site) + * - G. tickInFlight re-entrancy guard → pinned here + * - H. gold-standard regression → behavioral E2E (sibling file) + */ + +import { describe, test, expect } from 'bun:test'; +import * as fs from 'fs'; +import * as path from 'path'; +import { INFRASTRUCTURE_ABORT_REASONS } from '../src/core/minions/worker.ts'; + +const REPO_ROOT = path.resolve(import.meta.dir, '..'); +const WORKER_PATH = path.join(REPO_ROOT, 'src/core/minions/worker.ts'); + +// Read once at module load — failure to find the file is a strong signal +// the test file was moved without updating the path. +let workerSource: string; +try { + workerSource = fs.readFileSync(WORKER_PATH, 'utf8'); +} catch (err) { + throw new Error(`Cannot read ${WORKER_PATH}: ${(err as Error).message}`); +} + +// Helper: scope text to a single function body. Looks for `private launchJob(` +// (or whatever signature) and returns everything from that line to the next +// top-level `}` (heuristic — works for the project's bracing style). +function extractFunctionBody(source: string, signatureMarker: string): string { + const startIdx = source.indexOf(signatureMarker); + if (startIdx === -1) { + throw new Error(`Marker not found: ${signatureMarker}`); + } + // Find the opening brace of the function body. + const braceIdx = source.indexOf('{', startIdx); + if (braceIdx === -1) { + throw new Error(`No opening brace after marker: ${signatureMarker}`); + } + // Walk forward counting braces. + let depth = 1; + let i = braceIdx + 1; + while (i < source.length && depth > 0) { + const ch = source[i]; + if (ch === '{') depth++; + else if (ch === '}') depth--; + i++; + if (depth === 0) break; + } + return source.slice(braceIdx, i); +} + +// ============================================================================= +// D — INFRASTRUCTURE_ABORT_REASONS export contract (also covered in pure tests) +// ============================================================================= + +describe('D: INFRASTRUCTURE_ABORT_REASONS export contract', () => { + test('exported Set contains exactly lock-renewal-failed + lock-lost', () => { + // Named-constant regression: any change to this set is a deliberate + // two-line edit (the constant + this test). + expect(INFRASTRUCTURE_ABORT_REASONS).toBeInstanceOf(Set); + expect(INFRASTRUCTURE_ABORT_REASONS.size).toBe(2); + expect(INFRASTRUCTURE_ABORT_REASONS.has('lock-renewal-failed')).toBe(true); + expect(INFRASTRUCTURE_ABORT_REASONS.has('lock-lost')).toBe(true); + }); + + test('source exports the constant (so executeJob.catch can import it)', () => { + // Without the `export const` shape, executeJob's infrastructure- + // abort guard can't reach the set; the import would fail at compile + // time but pinning the export site here documents the contract. + expect(workerSource).toMatch(/export const INFRASTRUCTURE_ABORT_REASONS/); + }); +}); + +// ============================================================================= +// A — launchJob wires runLockRenewalTick +// ============================================================================= + +describe('A: launchJob wires the pure tick function', () => { + let launchJobBody: string; + test('extracts launchJob function body for further assertions', () => { + launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + expect(launchJobBody.length).toBeGreaterThan(0); + }); + + test('launchJob calls runLockRenewalTick (the extracted pure function)', () => { + expect(launchJobBody).toMatch(/runLockRenewalTick\s*\(/); + }); + + test('launchJob constructs the LockRenewalState via the documented helper', () => { + // resolveLockRenewalKnobs reads the env knobs (D2). If it disappears + // from launchJob, operators can't tune via env vars. + expect(launchJobBody).toMatch(/resolveLockRenewalKnobs\s*\(/); + }); + + test('launchJob uses the lockRenewalAudit sink (not a fake / inline)', () => { + expect(launchJobBody).toMatch(/lockRenewalAudit/); + }); +}); + +// ============================================================================= +// G — tickInFlight re-entrancy guard at the worker layer +// ============================================================================= + +describe('G: tickInFlight re-entrancy guard', () => { + test('launchJob declares the tickInFlight flag', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + expect(launchJobBody).toMatch(/let\s+tickInFlight\s*=\s*false/); + }); + + test('the setInterval callback checks tickInFlight and bails on re-entry', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + // The pattern is `if (tickInFlight) return;` — minor whitespace + // variation tolerated. + expect(launchJobBody).toMatch(/if\s*\(\s*tickInFlight\s*\)\s*return/); + }); + + test('the setInterval callback sets tickInFlight=true before scheduling work', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + expect(launchJobBody).toMatch(/tickInFlight\s*=\s*true/); + }); + + test('the post-tick finally clears tickInFlight back to false', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + expect(launchJobBody).toMatch(/tickInFlight\s*=\s*false/); + }); +}); + +// ============================================================================= +// C + F — .catch() on stored executeJob.finally promise + +// logExecuteJobRejected end-to-end via the catch +// ============================================================================= + +describe('C + F: .catch() on stored executeJob promise + logExecuteJobRejected', () => { + test('the stored executeJob promise has a .catch() handler', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + // The pattern is `.executeJob(...).finally(...).catch(...)` — the + // catch closes the SECOND unhandledRejection vector codex caught. + // Match any `.catch(` after `.finally(` within launchJob's body. + const finallyIdx = launchJobBody.indexOf('.finally('); + expect(finallyIdx).toBeGreaterThan(-1); + // Search for .catch( after the .finally( + const tail = launchJobBody.slice(finallyIdx); + expect(tail).toMatch(/\.catch\s*\(/); + }); + + test('the .catch() handler calls lockRenewalAudit.logExecuteJobRejected', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + expect(launchJobBody).toMatch(/logExecuteJobRejected\s*\(/); + }); + + test('the .catch() handler also logs to stderr (operator visibility)', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + // The implementation uses console.error for the human-visible trail. + // Pin the call so a future refactor that drops it leaves the operator + // with audit JSONL only (which is harder to grep live during an + // incident). + expect(launchJobBody).toMatch(/console\.error[^)]*executeJob unhandled/); + }); +}); + +// ============================================================================= +// E — Universal grace-evict listener fires on any abort reason +// ============================================================================= + +describe('E: universal grace-evict listener (D8b)', () => { + test('launchJob registers an abort.signal.addEventListener for grace-evict', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + // The pre-v0.41.26.1 form lived inside `if (job.timeout_ms != null)`. + // Now it's at launchJob top level and listens to the abort signal + // directly. Pin the listener registration. + expect(launchJobBody).toMatch(/abort\.signal\.addEventListener\s*\(\s*['"]abort['"]/); + }); + + test('the grace-evict path consults INFRASTRUCTURE_ABORT_REASONS before failJob', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + // The infrastructure-reason guard ensures lock-renewal aborts don't + // burn job attempts even if the handler is still wedged at the 30s + // force-evict deadline. + expect(launchJobBody).toMatch(/INFRASTRUCTURE_ABORT_REASONS/); + }); + + test('the 30s grace timer fires for any abort, not just timeout_ms', () => { + const launchJobBody = extractFunctionBody(workerSource, 'private launchJob('); + // The 30_000 literal must appear OUTSIDE the `if (job.timeout_ms != null)` + // branch. Check the addEventListener block contains the 30_000 literal. + // Find the addEventListener and look in its function body. + const listenerIdx = launchJobBody.indexOf("abort.signal.addEventListener('abort'"); + expect(listenerIdx).toBeGreaterThan(-1); + // Grab ~1500 chars after the listener to capture its body. + const listenerWindow = launchJobBody.slice(listenerIdx, listenerIdx + 1500); + expect(listenerWindow).toMatch(/30_000|30000/); + }); +}); + +// ============================================================================= +// B — executeJob skips failJob on infrastructure aborts +// ============================================================================= + +describe('B: executeJob skip-failJob on infrastructure abort (D8a)', () => { + test('executeJob detects the infrastructure abort reason and returns early', () => { + const executeJobBody = extractFunctionBody(workerSource, 'private async executeJob('); + // The skip-failJob branch checks abort.signal.reason against + // INFRASTRUCTURE_ABORT_REASONS and returns BEFORE the failJob call + // path. Pin both the constant reference AND the early-return shape. + expect(executeJobBody).toMatch(/INFRASTRUCTURE_ABORT_REASONS\.has/); + // The return-early shape: after the INFRASTRUCTURE_ABORT_REASONS + // check there must be a `return;` to skip the rest of catch. + // Pin the structural shape by locating the check + finding `return;` + // within ~500 chars after. + const idx = executeJobBody.indexOf('INFRASTRUCTURE_ABORT_REASONS.has'); + expect(idx).toBeGreaterThan(-1); + const window = executeJobBody.slice(idx, idx + 500); + expect(window).toMatch(/return\s*;/); + }); + + test('executeJob still calls failJob for non-infrastructure errors', () => { + const executeJobBody = extractFunctionBody(workerSource, 'private async executeJob('); + // Regression guard for the negative side: a future refactor that + // accidentally removes failJob entirely would make handler defects + // silently disappear. Pin that failJob remains in the catch path. + expect(executeJobBody).toMatch(/this\.queue\.failJob\s*\(/); + }); +}); diff --git a/test/worker-lock-renewal.test.ts b/test/worker-lock-renewal.test.ts new file mode 100644 index 000000000..751ccea89 --- /dev/null +++ b/test/worker-lock-renewal.test.ts @@ -0,0 +1,485 @@ +/** + * v0.41.22.2 — pure-function unit tests for `runLockRenewalTick`. + * + * Pins all 14 state-machine paths the cathedral cares about: + * + * - happy-path single renewal + * - throw bookkeeping (counter, audit, no abort if within deadline) + * - recovery (success_after_failure audit, counter reset) + * - time-based abort (gave_up audit, abort returned) + * - lock_lost (token mismatch, no audit, no infrastructure framing) + * - hung renewLock (Promise.race timeout fires, counter increments) + * - cancellation at three points (entry, after-resolve, after-reject) + * - time-based-vs-count-based: deadline crosses BEFORE the counter + * hits `maxFailuresForAudit`, abort still fires + * - audit-throw defense-in-depth (audit threw, tick still returns + * `'ok'` — the headline regression for the v0.41.22.1 bug class + * this whole wave exists to close) + * - env-knob resolution (good values, bad values fallback + + * stderr-warn-once) + * + * Hermetic: no fs, no PGLite, no real Anthropic, no setInterval. The + * tick function takes ALL effects via the injected `deps` object so + * everything is a vanilla async-function call. + */ + +import { describe, expect, test, beforeEach } from 'bun:test'; +import { + runLockRenewalTick, + resolveLockRenewalKnobs, + _resetKnobWarningsForTests, + type LockRenewalDeps, + type LockRenewalState, + type LockRenewalAuditSinkLike, + type LockRenewalKnobs, +} from '../src/core/minions/lock-renewal-tick.ts'; +import { withEnv } from './helpers/with-env.ts'; + +// --- fakes ---------------------------------------------------------------- + +interface AuditLog { + failures: Array<{ jobId: number; jobName: string; attempt: number; err: unknown }>; + recoveries: Array<{ jobId: number; jobName: string; recoveredAfterAttempts: number }>; + gaveUps: Array<{ jobId: number; jobName: string; totalFailures: number; err: unknown }>; +} + +function freshAudit(): { sink: LockRenewalAuditSinkLike; log: AuditLog } { + const log: AuditLog = { failures: [], recoveries: [], gaveUps: [] }; + return { + log, + sink: { + logFailure: (jobId, jobName, attempt, err) => + log.failures.push({ jobId, jobName, attempt, err }), + logSuccessAfterFailure: (jobId, jobName, recoveredAfterAttempts) => + log.recoveries.push({ jobId, jobName, recoveredAfterAttempts }), + logGaveUp: (jobId, jobName, totalFailures, err) => + log.gaveUps.push({ jobId, jobName, totalFailures, err }), + }, + }; +} + +/** + * Fake setTimeout that records the requested ms but does NOT actually + * schedule a real timer (no leaks across tests). The callback never + * fires unless tests explicitly call `runTimers(times)`. + */ +function makeFakeTimer(): { + setTimeout: LockRenewalDeps['setTimeout']; + runAll: () => void; + pending: Array<() => void>; +} { + const pending: Array<() => void> = []; + return { + setTimeout: (cb) => { + pending.push(cb); + return null; + }, + runAll: () => { + const toRun = [...pending]; + pending.length = 0; + toRun.forEach((cb) => cb()); + }, + pending, + }; +} + +const DEFAULT_LOCK_MS = 30_000; +const DEFAULT_KNOBS: LockRenewalKnobs = { + maxFailuresForAudit: 3, + callTimeoutMs: 10_000, + safetyMarginMs: 5_000, +}; + +function makeState(overrides?: Partial): LockRenewalState { + return { + jobId: 42, + jobName: 'sync', + lockToken: 'tok-abc', + lockDurationMs: DEFAULT_LOCK_MS, + knobs: DEFAULT_KNOBS, + lastSuccessfulRenewalAt: 0, + consecutiveFailures: 0, + cancelled: () => false, + ...overrides, + }; +} + +// --- tests ---------------------------------------------------------------- + +describe('runLockRenewalTick: happy path', () => { + test('case 1 — first-try success returns ok, no audit, lastSuccessfulRenewalAt updated', async () => { + const audit = freshAudit(); + const timer = makeFakeTimer(); + const deps: LockRenewalDeps = { + renewLock: async () => true, + audit: audit.sink, + now: () => 1000, + setTimeout: timer.setTimeout, + }; + const state = makeState({ lastSuccessfulRenewalAt: 500 }); + const result = await runLockRenewalTick(deps, state); + expect(result).toEqual({ kind: 'ok' }); + expect(audit.log.failures).toHaveLength(0); + expect(audit.log.recoveries).toHaveLength(0); + expect(audit.log.gaveUps).toHaveLength(0); + expect(state.lastSuccessfulRenewalAt).toBe(1000); + expect(state.consecutiveFailures).toBe(0); + }); +}); + +describe('runLockRenewalTick: failure counter + audit', () => { + test('case 2 — single throw within deadline: returns ok, counter=1, failure logged', async () => { + const audit = freshAudit(); + const deps: LockRenewalDeps = { + renewLock: async () => { throw new Error('Connection terminated'); }, + audit: audit.sink, + now: () => 1000, // sinceLastSuccess = 1000ms, deadline = 25000ms; well within + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ lastSuccessfulRenewalAt: 0 }); + const result = await runLockRenewalTick(deps, state); + expect(result).toEqual({ kind: 'ok' }); + expect(state.consecutiveFailures).toBe(1); + expect(audit.log.failures).toHaveLength(1); + expect(audit.log.failures[0].attempt).toBe(1); + expect(audit.log.gaveUps).toHaveLength(0); + }); + + test('case 3 — two throws then success: counter resets, success_after_failure logged', async () => { + const audit = freshAudit(); + let callIdx = 0; + const deps: LockRenewalDeps = { + renewLock: async () => { + callIdx++; + if (callIdx <= 2) throw new Error('blip ' + callIdx); + return true; + }, + audit: audit.sink, + now: () => 1000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ lastSuccessfulRenewalAt: 0 }); + + const r1 = await runLockRenewalTick(deps, state); + expect(r1.kind).toBe('ok'); + expect(state.consecutiveFailures).toBe(1); + + const r2 = await runLockRenewalTick(deps, state); + expect(r2.kind).toBe('ok'); + expect(state.consecutiveFailures).toBe(2); + + const r3 = await runLockRenewalTick(deps, state); + expect(r3.kind).toBe('ok'); + expect(state.consecutiveFailures).toBe(0); + + expect(audit.log.failures).toHaveLength(2); + expect(audit.log.recoveries).toHaveLength(1); + expect(audit.log.recoveries[0].recoveredAfterAttempts).toBe(2); + }); +}); + +describe('runLockRenewalTick: time-based abort', () => { + test('case 4 — sustained throws past deadline returns should_abort, gave_up logged', async () => { + const audit = freshAudit(); + // deadline = 30000 - 5000 = 25000; we've been failing for 26s. + const deps: LockRenewalDeps = { + renewLock: async () => { throw new Error('persistent outage'); }, + audit: audit.sink, + now: () => 26_000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ lastSuccessfulRenewalAt: 0, consecutiveFailures: 2 }); + const result = await runLockRenewalTick(deps, state); + expect(result).toEqual({ kind: 'should_abort', reason: 'lock-renewal-failed' }); + expect(audit.log.failures).toHaveLength(1); + expect(audit.log.gaveUps).toHaveLength(1); + expect(audit.log.gaveUps[0].totalFailures).toBe(3); + }); + + test('case 10 — time-based abort fires BEFORE count-based threshold', async () => { + // Critical regression: deadline at 25s, 5 failures over 30s. + // count-based (3-strike) would have aborted at failure #3 — but + // failure #3 happens at t=15s, well inside the 25s deadline. + // Time-based correctly waits until the deadline crosses. + const audit = freshAudit(); + const knobs: LockRenewalKnobs = { + maxFailuresForAudit: 3, + callTimeoutMs: 10_000, + safetyMarginMs: 5_000, + }; + let nowMs = 0; + const deps: LockRenewalDeps = { + renewLock: async () => { throw new Error('outage'); }, + audit: audit.sink, + now: () => nowMs, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ knobs, lastSuccessfulRenewalAt: 0 }); + + // Five sequential failures at t=5, 10, 15, 20, 26. + for (const t of [5_000, 10_000, 15_000, 20_000]) { + nowMs = t; + const r = await runLockRenewalTick(deps, state); + expect(r.kind).toBe('ok'); // within deadline despite counter > maxFailuresForAudit + } + expect(state.consecutiveFailures).toBe(4); + expect(audit.log.gaveUps).toHaveLength(0); + + nowMs = 26_000; // crosses deadline of 25000 + const final = await runLockRenewalTick(deps, state); + expect(final).toEqual({ kind: 'should_abort', reason: 'lock-renewal-failed' }); + expect(audit.log.gaveUps).toHaveLength(1); + }); +}); + +describe('runLockRenewalTick: lock_lost (token mismatch)', () => { + test('case 5 — renewLock returns false: lock_lost, NO audit event', async () => { + const audit = freshAudit(); + const deps: LockRenewalDeps = { + renewLock: async () => false, + audit: audit.sink, + now: () => 1000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ lastSuccessfulRenewalAt: 0 }); + const result = await runLockRenewalTick(deps, state); + expect(result).toEqual({ kind: 'lock_lost' }); + expect(audit.log.failures).toHaveLength(0); + expect(audit.log.gaveUps).toHaveLength(0); + expect(audit.log.recoveries).toHaveLength(0); + }); +}); + +describe('runLockRenewalTick: hung renewLock timeout (codex C3)', () => { + test('case 6 — renewLock hangs past callTimeoutMs: Promise.race fires, counter increments', async () => { + const audit = freshAudit(); + const timer = makeFakeTimer(); + // renewLock never resolves; only the timeout race rejects. + const deps: LockRenewalDeps = { + renewLock: () => new Promise(() => { /* never resolves */ }), + audit: audit.sink, + now: () => 1000, + setTimeout: timer.setTimeout, + }; + const state = makeState({ lastSuccessfulRenewalAt: 0 }); + + // Start the tick. It awaits Promise.race; the renewLock promise + // never resolves, but as soon as we fire the timeout callback, the + // race rejects. + const tickPromise = runLockRenewalTick(deps, state); + // Yield once so the Promise.race actually wires up the deps.setTimeout call. + await new Promise((r) => setImmediate(r)); + expect(timer.pending.length).toBeGreaterThan(0); + timer.runAll(); + + const result = await tickPromise; + expect(result).toEqual({ kind: 'ok' }); // counter incremented, within deadline + expect(state.consecutiveFailures).toBe(1); + expect(audit.log.failures).toHaveLength(1); + expect(audit.log.failures[0].err).toBeInstanceOf(Error); + expect((audit.log.failures[0].err as Error).message).toMatch(/timed out after 10000ms/); + }); +}); + +describe('runLockRenewalTick: cancellation', () => { + test('case 7 — cancelled BEFORE tick fires: returns cancelled immediately, no audit, no renewLock call', async () => { + const audit = freshAudit(); + let renewLockCalled = false; + const deps: LockRenewalDeps = { + renewLock: async () => { renewLockCalled = true; return true; }, + audit: audit.sink, + now: () => 1000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ cancelled: () => true }); + const result = await runLockRenewalTick(deps, state); + expect(result).toEqual({ kind: 'cancelled' }); + expect(renewLockCalled).toBe(false); + expect(audit.log.failures).toHaveLength(0); + }); + + test('case 8 — cancelled DURING renewLock await (resolved branch): returns cancelled, no audit', async () => { + const audit = freshAudit(); + let cancelled = false; + let renewLockResolve: ((v: boolean) => void) | undefined; + const deps: LockRenewalDeps = { + renewLock: () => new Promise((res) => { renewLockResolve = res; }), + audit: audit.sink, + now: () => 1000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ cancelled: () => cancelled }); + + const tick = runLockRenewalTick(deps, state); + // Flip cancelled, THEN resolve the renewLock. The post-await branch + // must check cancelled and bail. + cancelled = true; + renewLockResolve!(true); + const result = await tick; + expect(result).toEqual({ kind: 'cancelled' }); + // Even though renewLock returned true, no recovery audit fires + // because cancelled gated it. + expect(audit.log.recoveries).toHaveLength(0); + }); + + test('case 9 — cancelled DURING renewLock await (thrown branch): returns cancelled, no audit', async () => { + const audit = freshAudit(); + let cancelled = false; + let renewLockReject: ((e: Error) => void) | undefined; + const deps: LockRenewalDeps = { + renewLock: () => new Promise((_, rej) => { renewLockReject = rej; }), + audit: audit.sink, + now: () => 1000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ cancelled: () => cancelled }); + + const tick = runLockRenewalTick(deps, state); + // Flip cancelled, THEN reject. The catch-branch cancellation check + // must skip the audit AND skip the deadline math. + cancelled = true; + renewLockReject!(new Error('would-have-been-logged')); + const result = await tick; + expect(result).toEqual({ kind: 'cancelled' }); + expect(audit.log.failures).toHaveLength(0); + expect(audit.log.gaveUps).toHaveLength(0); + }); +}); + +describe('runLockRenewalTick: audit defense-in-depth (codex C4)', () => { + test('case 11 — audit.logFailure throws: tick still returns ok, counter still increments', async () => { + const audit: LockRenewalAuditSinkLike = { + logFailure: () => { throw new Error('audit subsystem on fire'); }, + logSuccessAfterFailure: () => { /* noop */ }, + logGaveUp: () => { /* noop */ }, + }; + const deps: LockRenewalDeps = { + renewLock: async () => { throw new Error('outage'); }, + audit, + now: () => 1000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ lastSuccessfulRenewalAt: 0 }); + const result = await runLockRenewalTick(deps, state); + expect(result).toEqual({ kind: 'ok' }); + expect(state.consecutiveFailures).toBe(1); + }); + + test('case 11b — audit.logGaveUp throws: tick still returns should_abort', async () => { + const audit: LockRenewalAuditSinkLike = { + logFailure: () => { /* noop */ }, + logSuccessAfterFailure: () => { /* noop */ }, + logGaveUp: () => { throw new Error('audit subsystem on fire'); }, + }; + const deps: LockRenewalDeps = { + renewLock: async () => { throw new Error('outage'); }, + audit, + now: () => 26_000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ lastSuccessfulRenewalAt: 0 }); + const result = await runLockRenewalTick(deps, state); + expect(result).toEqual({ kind: 'should_abort', reason: 'lock-renewal-failed' }); + }); + + test('case 11c — audit.logSuccessAfterFailure throws: tick still returns ok, counter resets', async () => { + const audit: LockRenewalAuditSinkLike = { + logFailure: () => { /* noop */ }, + logSuccessAfterFailure: () => { throw new Error('audit subsystem on fire'); }, + logGaveUp: () => { /* noop */ }, + }; + const deps: LockRenewalDeps = { + renewLock: async () => true, + audit, + now: () => 1000, + setTimeout: makeFakeTimer().setTimeout, + }; + const state = makeState({ consecutiveFailures: 2, lastSuccessfulRenewalAt: 0 }); + const result = await runLockRenewalTick(deps, state); + expect(result).toEqual({ kind: 'ok' }); + expect(state.consecutiveFailures).toBe(0); + expect(state.lastSuccessfulRenewalAt).toBe(1000); + }); +}); + +describe('resolveLockRenewalKnobs', () => { + beforeEach(() => { _resetKnobWarningsForTests(); }); + + test('case 12a — defaults derive from lockDuration', () => { + const knobs = resolveLockRenewalKnobs({}, 30_000); + expect(knobs.maxFailuresForAudit).toBe(3); + expect(knobs.callTimeoutMs).toBe(10_000); + expect(knobs.safetyMarginMs).toBe(5_000); + }); + + test('case 12b — valid env values parse cleanly', () => { + const knobs = resolveLockRenewalKnobs({ + GBRAIN_LOCK_RENEWAL_MAX_FAILURES: '5', + GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS: '15000', + GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS: '8000', + }, 30_000); + expect(knobs.maxFailuresForAudit).toBe(5); + expect(knobs.callTimeoutMs).toBe(15_000); + expect(knobs.safetyMarginMs).toBe(8_000); + }); + + test('case 12c — bad env (abc/-5/0/1.5) falls back to default with single stderr warn', async () => { + const captured: string[] = []; + const origWrite = process.stderr.write.bind(process.stderr); + (process.stderr as { write: (chunk: string | Uint8Array) => boolean }).write = (chunk) => { + captured.push(typeof chunk === 'string' ? chunk : Buffer.from(chunk).toString('utf8')); + return true; + }; + try { + _resetKnobWarningsForTests(); + + // Each bad value falls back. + let knobs = resolveLockRenewalKnobs({ GBRAIN_LOCK_RENEWAL_MAX_FAILURES: 'abc' }, 30_000); + expect(knobs.maxFailuresForAudit).toBe(3); + + knobs = resolveLockRenewalKnobs({ GBRAIN_LOCK_RENEWAL_MAX_FAILURES: '-5' }, 30_000); + expect(knobs.maxFailuresForAudit).toBe(3); + + knobs = resolveLockRenewalKnobs({ GBRAIN_LOCK_RENEWAL_MAX_FAILURES: '0' }, 30_000); + expect(knobs.maxFailuresForAudit).toBe(3); + + knobs = resolveLockRenewalKnobs({ GBRAIN_LOCK_RENEWAL_MAX_FAILURES: '1.5' }, 30_000); + expect(knobs.maxFailuresForAudit).toBe(3); + + // Despite 4 bad invocations, only ONE stderr warn per env-name fired. + const warnLines = captured.filter((c) => c.includes('GBRAIN_LOCK_RENEWAL_MAX_FAILURES')); + expect(warnLines).toHaveLength(1); + expect(warnLines[0]).toContain('not a positive integer'); + expect(warnLines[0]).toContain('falling back to default 3'); + } finally { + process.stderr.write = origWrite; + } + }); + + test('case 12d — different env names warn independently', async () => { + const captured: string[] = []; + const origWrite = process.stderr.write.bind(process.stderr); + (process.stderr as { write: (chunk: string | Uint8Array) => boolean }).write = (chunk) => { + captured.push(typeof chunk === 'string' ? chunk : Buffer.from(chunk).toString('utf8')); + return true; + }; + try { + _resetKnobWarningsForTests(); + resolveLockRenewalKnobs({ + GBRAIN_LOCK_RENEWAL_MAX_FAILURES: 'bad1', + GBRAIN_LOCK_RENEWAL_CALL_TIMEOUT_MS: 'bad2', + GBRAIN_LOCK_RENEWAL_SAFETY_MARGIN_MS: 'bad3', + }, 30_000); + const warnLines = captured.filter((c) => c.includes('not a positive integer')); + expect(warnLines).toHaveLength(3); + } finally { + process.stderr.write = origWrite; + } + }); + + test('case 14 — maxFailuresForAudit default is 3 (audit-labeling regression)', () => { + // Pinned as a named-constant regression: a future change here is + // a deliberate two-line edit (default + this test). + expect(resolveLockRenewalKnobs({}, 30_000).maxFailuresForAudit).toBe(3); + }); +});