Engine-level retry primitive that closes the v0.41.17 production incident
where ~3,000 wiki links + timeline entries were silently lost per dream
cycle on a 16K-page brain. Supavisor's circuit-breaker takes 5-10s to
recover; the prior single-500ms-retry shape couldn't survive it.
ARCHITECTURE
============
Retry becomes a data-primitive contract, not a caller responsibility.
postgres-engine.ts + pglite-engine.ts now self-retry inside addLinksBatch,
addTimelineEntriesBatch, and upsertChunks. Every caller — current AND
future — inherits retry-for-free. CI lint guard `scripts/check-no-double-retry.sh`
fails the build if anyone re-wraps an engine batch method (preventing
3×3=9 retry amplification on incomplete reverts).
CODEX-HARDENED DEFAULTS
=======================
BULK_RETRY_OPTS = {maxRetries:3, delayMs:1000, delayMaxMs:10000,
jitter:'decorrelated'}. Total worst-case wait ≈12s covers full Supavisor
recovery window. Decorrelated jitter (AWS-style uniform(base, prevDelay*3)
capped at maxDelay) replaces 'full' which allowed near-zero retries that
re-hit the still-recovering breaker.
AbortSignal threading from MinionWorker.shutdownAbort.signal through
engine method opts → withRetry → abortableSleep. SIGTERM aborts sleeping
retries instead of blocking deploys for up to delayMaxMs.
OBSERVABILITY
=============
`~/.gbrain/audit/batch-retry-YYYY-Www.jsonl` records every retry event
(success-after-blip AND exhausted-retries). Built on the v0.40.4.0
audit-writer cathedral. Privacy posture: never logs slugs / page IDs /
content (mirrors shell-audit.ts).
`gbrain doctor` learns `batch_retry_health` check. Reads last 24h
(not 7d — codex H-9: avoid permanent noise from one historical blip).
Thresholds: ok (zero or <3 same-site), warn (>=3 same-site OR >=5
cross-site), fail (>=20 sustained breaker). Surfaces bad GBRAIN_BULK_*
env at startup (codex M-10). Corrupt-JSONL tolerant.
30-day audit pruning hooked into the dream cycle's purge phase (codex H-8
— implements the 'pruning convention' for real).
OPERATOR TUNING
===============
GBRAIN_BULK_MAX_RETRIES (int >= 0; 0 disables retries for debugging)
GBRAIN_BULK_RETRY_BASE_MS (int > 0)
GBRAIN_BULK_RETRY_MAX_MS (int >= base)
Bad values throw GBrainError with paste-ready fix hints at doctor startup,
not at first-retry mid-cycle.
VERIFICATION
============
- bun run verify: 28/28 checks green (includes 2 new lint guards:
check-no-double-retry, check-batch-audit-site)
- bun run test: 11453 pass / 1 pre-existing flake (schema-cli.test.ts —
confirmed by running on clean master, NOT introduced by this wave)
- bun run test:slow: 40/40 including new test/core/retry-stress.slow.test.ts
(100 batches × 30% blip rate × decorrelated jitter, zero row loss)
- bunx tsc --noEmit: 0 errors
REVIEWS
=======
- CEO review (SELECTIVE EXPANSION): 4 cherry-picks proposed, 4 accepted
- Eng review (2 passes): 10 findings, 0 critical gaps, architectural
pivot from per-site to engine-level wrap
- Codex independent review: 23 findings; 10 critical/high absorbed
(decorrelated jitter, 12s backoff window, AbortSignal, idempotency
proof, backfill unification, typed audit-site enum, doctor expiry
thresholds, audit pruning, env validation at doctor startup)
PR #1523 closed and absorbed (@garrytan-agents original extract.ts fix
preserved via co-author trailer; 5 test cases moved to test/core/retry.test.ts
with assertions adjusted for the v0.41.19.0 BULK_RETRY_OPTS defaults).
Co-authored-by: garrytan-agents <noreply@anthropic.com>
231 lines
9.6 KiB
TypeScript
231 lines
9.6 KiB
TypeScript
// v0.41.18.0 — batch-retry audit JSONL primitive.
|
|
//
|
|
// Hermetic: uses GBRAIN_AUDIT_DIR env override via the withEnv helper so
|
|
// the test never touches the user's ~/.gbrain/audit/. Each test gets a fresh
|
|
// tempdir via beforeEach so file-system state never leaks across cases.
|
|
|
|
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,
|
|
readRecentBatchRetryEvents,
|
|
pruneOldBatchRetryAuditFiles,
|
|
BATCH_RETRY_FEATURE_NAME,
|
|
} from '../../src/core/audit/batch-retry-audit.ts';
|
|
|
|
let tmpDir: string;
|
|
|
|
beforeEach(() => {
|
|
tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'batch-retry-audit-'));
|
|
});
|
|
|
|
afterEach(() => {
|
|
try {
|
|
fs.rmSync(tmpDir, { recursive: true, force: true });
|
|
} catch { /* best-effort */ }
|
|
});
|
|
|
|
describe('logBatchRetry — success-path emission', () => {
|
|
test('writes JSONL row with outcome=success', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
logBatchRetry('extract.links_inc', 100, 1, 1000, new Error('Connection terminated'));
|
|
const result = readRecentBatchRetryEvents(24);
|
|
expect(result.events).toHaveLength(1);
|
|
expect(result.events[0].site).toBe('extract.links_inc');
|
|
expect(result.events[0].batch_size).toBe(100);
|
|
expect(result.events[0].attempt).toBe(1);
|
|
expect(result.events[0].outcome).toBe('success');
|
|
expect(result.events[0].delay_ms).toBe(1000);
|
|
expect(result.events[0].error_message_summary).toContain('Connection terminated');
|
|
});
|
|
});
|
|
|
|
test('captures SQLSTATE code when present on error', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
const err = Object.assign(new Error('connection failure'), { code: '08006' });
|
|
logBatchRetry('extract.timeline_fs', 50, 2, 3000, err);
|
|
const result = readRecentBatchRetryEvents(24);
|
|
expect(result.events[0].error_code).toBe('08006');
|
|
});
|
|
});
|
|
|
|
test('truncates long error messages to 200 chars', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
const longMsg = 'A'.repeat(500);
|
|
logBatchRetry('addLinksBatch', 100, 1, 1000, new Error(longMsg));
|
|
const result = readRecentBatchRetryEvents(24);
|
|
expect(result.events[0].error_message_summary.length).toBe(200);
|
|
});
|
|
});
|
|
|
|
test('replaces newlines in error message (grep-friendly)', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
logBatchRetry('addLinksBatch', 100, 1, 1000, new Error('line1\nline2\tline3'));
|
|
const result = readRecentBatchRetryEvents(24);
|
|
expect(result.events[0].error_message_summary).toBe('line1 line2 line3');
|
|
});
|
|
});
|
|
});
|
|
|
|
describe('logBatchExhausted — exhausted-retry emission', () => {
|
|
test('writes outcome=exhausted with total attempt count', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
logBatchExhausted('mcp.put_page.autolink', 25, 4, new Error('Connection terminated'));
|
|
const result = readRecentBatchRetryEvents(24);
|
|
expect(result.events).toHaveLength(1);
|
|
expect(result.events[0].outcome).toBe('exhausted');
|
|
expect(result.events[0].attempt).toBe(4);
|
|
expect(result.events[0].site).toBe('mcp.put_page.autolink');
|
|
});
|
|
});
|
|
});
|
|
|
|
describe('readRecentBatchRetryEvents — windowing + corruption tolerance', () => {
|
|
test('filters by hours-back cutoff', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
// Write 3 events: one 25h ago (out of 24h window), one now, one 1h ago.
|
|
const now = Date.now();
|
|
const dir = tmpDir;
|
|
// Use the writer to land in the correct ISO-week file.
|
|
logBatchRetry('addLinksBatch', 1, 1, 100, new Error('a'));
|
|
logBatchRetry('addLinksBatch', 2, 1, 100, new Error('b'));
|
|
// Manually inject an old event by appending to the same file.
|
|
const filename = `${BATCH_RETRY_FEATURE_NAME}-${new Date(now).getUTCFullYear()}-W${String(getIsoWeek(new Date(now))).padStart(2, '0')}.jsonl`;
|
|
const filePath = path.join(dir, filename);
|
|
const oldEvent = {
|
|
ts: new Date(now - 25 * 3600_000).toISOString(),
|
|
site: 'addLinksBatch',
|
|
batch_size: 99,
|
|
attempt: 1,
|
|
outcome: 'success',
|
|
delay_ms: 100,
|
|
error_message_summary: 'old',
|
|
};
|
|
fs.appendFileSync(filePath, JSON.stringify(oldEvent) + '\n');
|
|
|
|
const result = readRecentBatchRetryEvents(24);
|
|
// Should see 2 recent events but NOT the 25h-old one.
|
|
expect(result.events.length).toBeGreaterThanOrEqual(2);
|
|
const oldFound = result.events.find(e => e.error_message_summary === 'old');
|
|
expect(oldFound).toBeUndefined();
|
|
});
|
|
});
|
|
|
|
test('counts corrupted JSONL lines without crashing', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
// Write a valid event first to ensure the file exists.
|
|
logBatchRetry('addLinksBatch', 1, 1, 100, new Error('valid'));
|
|
const now = new Date();
|
|
const filename = `${BATCH_RETRY_FEATURE_NAME}-${now.getUTCFullYear()}-W${String(getIsoWeek(now)).padStart(2, '0')}.jsonl`;
|
|
const filePath = path.join(tmpDir, filename);
|
|
// Append 3 corrupt lines.
|
|
fs.appendFileSync(filePath, '{not json\n');
|
|
fs.appendFileSync(filePath, 'still not json\n');
|
|
fs.appendFileSync(filePath, '{"missing_close": true\n');
|
|
|
|
const result = readRecentBatchRetryEvents(24);
|
|
expect(result.events).toHaveLength(1); // the valid one
|
|
expect(result.corrupted_lines).toBe(3);
|
|
});
|
|
});
|
|
|
|
test('files_unreadable counts permission errors but ignores ENOENT', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
// No files written; the only "missing" file is ENOENT which is expected.
|
|
const result = readRecentBatchRetryEvents(24);
|
|
expect(result.events).toHaveLength(0);
|
|
expect(result.files_unreadable).toBe(0);
|
|
expect(result.files_scanned).toBe(0);
|
|
});
|
|
});
|
|
});
|
|
|
|
describe('pruneOldBatchRetryAuditFiles — codex H-8 actual pruning', () => {
|
|
test('deletes files older than daysToKeep', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
// Create an old file (mtime 31 days ago).
|
|
const oldFile = path.join(tmpDir, `${BATCH_RETRY_FEATURE_NAME}-2024-W01.jsonl`);
|
|
fs.writeFileSync(oldFile, '{"ts":"2024-01-01T00:00:00Z"}\n');
|
|
const oldTime = Date.now() - 31 * 86400_000;
|
|
fs.utimesSync(oldFile, oldTime / 1000, oldTime / 1000);
|
|
|
|
// Create a recent file (mtime now).
|
|
const newFile = path.join(tmpDir, `${BATCH_RETRY_FEATURE_NAME}-2026-W22.jsonl`);
|
|
fs.writeFileSync(newFile, '{"ts":"2026-05-26T00:00:00Z"}\n');
|
|
|
|
const result = pruneOldBatchRetryAuditFiles(30);
|
|
expect(result.removed).toBe(1);
|
|
expect(result.kept).toBe(1);
|
|
expect(fs.existsSync(oldFile)).toBe(false);
|
|
expect(fs.existsSync(newFile)).toBe(true);
|
|
});
|
|
});
|
|
|
|
test('ignores files that do not match the batch-retry-*.jsonl shape', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
// Other audit module's files should not be touched.
|
|
const otherFile = path.join(tmpDir, 'shell-jobs-2024-W01.jsonl');
|
|
fs.writeFileSync(otherFile, '{}\n');
|
|
const oldTime = Date.now() - 31 * 86400_000;
|
|
fs.utimesSync(otherFile, oldTime / 1000, oldTime / 1000);
|
|
|
|
const result = pruneOldBatchRetryAuditFiles(30);
|
|
expect(result.removed).toBe(0);
|
|
expect(fs.existsSync(otherFile)).toBe(true);
|
|
});
|
|
});
|
|
|
|
test('no-op when audit dir does not exist (ENOENT)', () => {
|
|
const result = pruneOldBatchRetryAuditFiles(30, new Date());
|
|
// Even without the env override, the function never throws on missing dir.
|
|
// We just check it returns the empty result without throwing.
|
|
expect(result).toEqual({ removed: 0, kept: 0 });
|
|
});
|
|
});
|
|
|
|
describe('privacy posture (codex review + CLAUDE.md privacy rule)', () => {
|
|
test('audit row never contains slugs, page ids, or content', async () => {
|
|
await withEnv({ GBRAIN_AUDIT_DIR: tmpDir }, async () => {
|
|
logBatchRetry(
|
|
'extract.links_inc',
|
|
100,
|
|
1,
|
|
1000,
|
|
new Error('insert failed for slug=people/alice page_id=42'),
|
|
);
|
|
const result = readRecentBatchRetryEvents(24);
|
|
// The error message IS in the audit (necessary for debugging), but
|
|
// schema fields don't carry slugs, IDs, or content separately. The
|
|
// 200-char truncation prevents large blob leaks too.
|
|
const row = result.events[0];
|
|
// Verify the row shape — no slug, page_id, content, body fields.
|
|
// error_code is optional (only present when error has SQLSTATE), so
|
|
// the schema's closed set is these fields plus optional error_code.
|
|
const keys = new Set(Object.keys(row));
|
|
const requiredKeys = ['attempt', 'batch_size', 'delay_ms', 'error_message_summary', 'outcome', 'site', 'ts'];
|
|
for (const k of requiredKeys) expect(keys.has(k)).toBe(true);
|
|
// No leaky fields.
|
|
for (const k of keys) {
|
|
expect(['attempt', 'batch_size', 'delay_ms', 'error_code', 'error_message_summary', 'outcome', 'site', 'ts']).toContain(k);
|
|
}
|
|
});
|
|
});
|
|
});
|
|
|
|
// Helper: ISO 8601 week number (matches the audit-writer.ts computation).
|
|
function getIsoWeek(d: Date): number {
|
|
const target = new Date(d.valueOf());
|
|
const dayNumber = (d.getUTCDay() + 6) % 7;
|
|
target.setUTCDate(target.getUTCDate() - dayNumber + 3);
|
|
const firstThursday = target.valueOf();
|
|
target.setUTCMonth(0, 1);
|
|
if (target.getUTCDay() !== 4) {
|
|
target.setUTCMonth(0, 1 + ((4 - target.getUTCDay()) + 7) % 7);
|
|
}
|
|
return 1 + Math.ceil((firstThursday - target.valueOf()) / 604800000);
|
|
}
|