From 093563d6765074b3313df2a04e45edc818ced24a Mon Sep 17 00:00:00 2001 From: Garry Tan Date: Tue, 28 Jul 2026 13:20:27 -0700 Subject: [PATCH] fix(test): correct the deadline inversion in the durability-hook serial tests (#2943) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three layers, verified by 10-run tallies (master: 7 pass/3 fail; branch: 10/10): 1. Deadline inversion: the hook tests' internal 8s poll deadlines sat behind bun's 5000ms default because no third-arg timeout was passed — and bun 1.3.14 ignores bunfig.toml's `timeout` key, so bare `bun test` runs died at 5s with the 8s budget unreachable. All three tests now pass 60_000 explicitly; deadlines raised to 30s for loaded-shard headroom. Same class fixed in test/e2e/jsonb-roundtrip.test.ts (four tests had no explicit timeout). 2. Root cause of the CI assertion failures: the test's git() helper spawned git WITHOUT `env: process.env`. Bun snapshots process.env at startup (the #2747 quirk), so the post-commit hook under test resolved GBRAIN_HOME to the operator's real ~/.gbrain — writing its log there (polluting the real brain-push.log every run) while the test polled the temp log. The LOCAL-ONLY assertion only passed when beforeEach's scaffolding hook push happened to still be in flight, lose the ref race, and retry after origin pointed at the dead path — a load-dependent accident. env is now passed everywhere, making the intended signal deterministic (~1s). 3. index.lock race (the third observed CI form): beforeEach now waits for the scaffolding commit's detached brain_push to write its terminal log line before handing the repo to the test, so its pull-rebase fallback can't take .git/index.lock under the test body's own git calls. Poll loops untouched — they were already correct; the 150 is the poll interval. Co-Authored-By: Claude Opus 5 --- test/brain-durability-hook.serial.test.ts | 58 +++++++++++++++++++---- test/e2e/jsonb-roundtrip.test.ts | 8 ++-- 2 files changed, 52 insertions(+), 14 deletions(-) diff --git a/test/brain-durability-hook.serial.test.ts b/test/brain-durability-hook.serial.test.ts index 38aff4df9..4a0a81db3 100644 --- a/test/brain-durability-hook.serial.test.ts +++ b/test/brain-durability-hook.serial.test.ts @@ -11,15 +11,34 @@ import { tmpdir } from 'os'; import { execFileSync } from 'child_process'; import { hardenBrainRepo } from '../src/core/brain-repo-durability.ts'; +// #2943 root cause: `env: process.env` is REQUIRED here. Bun snapshots +// process.env at startup, so without it the spawned git — and any post-commit +// hook it fires — is blind to beforeEach's HOME/GBRAIN_HOME mutations (the +// same Bun quirk as #2747, see resolveGbrainCliPath in brain-repo-durability). +// Pre-fix, the hook under test resolved ${GBRAIN_HOME:-$HOME/.gbrain} to the +// OPERATOR'S REAL ~/.gbrain: it wrote its log lines there (polluting the real +// brain-push.log on every run), the LOCAL-ONLY test never saw them in the +// temp log it polls, and the assertion only passed when the scaffolding push +// from beforeEach (spawned by hardenBrainRepo WITH explicit env) happened to +// still be in flight, lose the ref race, and retry AFTER the test had pointed +// origin at the dead path — an accidental, load-dependent signal. That race +// is the CI flake. function git(cwd: string, ...args: string[]): string { return execFileSync('git', ['-C', cwd, '-c', 'protocol.file.allow=always', ...args], { - stdio: ['ignore', 'pipe', 'pipe'], encoding: 'utf-8', + stdio: ['ignore', 'pipe', 'pipe'], encoding: 'utf-8', env: process.env, }).trim(); } function originHead(bare: string): string { return git(bare, 'rev-parse', 'refs/heads/main'); } -async function waitForOrigin(bare: string, expectSha: string, ms = 8000): Promise { +// #2943: 30s poll deadlines (was 8s) for headroom under loaded CI shards — +// the unreachable-origin path runs ~6 sequential process spawns after the +// hook detaches. Every hook test also passes an explicit 60_000 third-arg +// timeout: bun 1.3.14 IGNORES bunfig.toml's `timeout` key, so a bare +// `bun test` enforces its 5000ms default and killed these tests before the +// internal deadline could even elapse (the runner scripts pass --timeout +// explicitly, which is why the inversion only bit direct local runs). +async function waitForOrigin(bare: string, expectSha: string, ms = 30_000): Promise { const deadline = Date.now() + ms; while (Date.now() < deadline) { try { if (originHead(bare) === expectSha) return true; } catch { /* */ } @@ -28,6 +47,24 @@ async function waitForOrigin(bare: string, expectSha: string, ms = 8000): Promis return false; } +/** #2943 (index.lock form): hardenBrainRepo installs the post-commit hook + * BEFORE committing the scaffolding, so that commit fires the hook and + * detaches a background brain_push. If that push loses the ref race against + * hardenBrainRepo's own synchronous push, it falls back to `git pull + * --rebase`, which takes .git/index.lock — racing the test body's first git + * calls ("Unable to create '.../.git/index.lock': File exists"). Wait for the + * detached push's terminal log line before handing the repo to the test. */ +async function waitForHookPushSettled(ms = 30_000): Promise { + const log = join(process.env.GBRAIN_HOME!, 'brain-push.log'); + const terminal = /\[push\] (ok|lock-timeout|LOCAL-ONLY)/; + const deadline = Date.now() + ms; + while (Date.now() < deadline) { + if (existsSync(log) && terminal.test(readFileSync(log, 'utf-8'))) return; + await new Promise(r => setTimeout(r, 150)); + } + throw new Error(`detached hook push did not settle within ${ms}ms (${log})`); +} + let root: string, work: string, bare: string; let oldHome: string | undefined, oldGbrainHome: string | undefined; @@ -38,14 +75,15 @@ beforeEach(async () => { process.env.GBRAIN_HOME = join(process.env.HOME, '.gbrain'); process.env.GBRAIN_GIT_ALLOW_FILE_TRANSPORT = '1'; bare = mkdtempSync(join(root, 'origin-')) + '.git'; - execFileSync('git', ['init', '-q', '--bare', '-b', 'main', bare], { stdio: 'ignore' }); + execFileSync('git', ['init', '-q', '--bare', '-b', 'main', bare], { stdio: 'ignore', env: process.env }); work = mkdtempSync(join(root, 'work-')); - execFileSync('git', ['-c', 'protocol.file.allow=always', 'clone', '-q', bare, work], { stdio: 'ignore' }); + execFileSync('git', ['-c', 'protocol.file.allow=always', 'clone', '-q', bare, work], { stdio: 'ignore', env: process.env }); git(work, 'config', 'user.email', 't@t.t'); git(work, 'config', 'user.name', 'tester'); writeFileSync(join(work, 'README.md'), 'init\n'); git(work, 'add', 'README.md'); git(work, 'commit', '-qm', 'init'); git(work, 'push', '-q', 'origin', 'main'); git(work, 'remote', 'set-head', 'origin', 'main'); await hardenBrainRepo({ repoPath: work, sourceId: 'wiki', pat: 'ghp_x', installCron: false }); + await waitForHookPushSettled(); }); afterEach(() => { if (oldHome === undefined) delete process.env.HOME; else process.env.HOME = oldHome; @@ -65,7 +103,7 @@ describe('brain-commit-push.sh (D13 guarantee)', () => { expect(originHead(bare)).toBe(git(work, 'rev-parse', 'HEAD')); // origin actually has the file const verify = mkdtempSync(join(root, 'verify-')); - execFileSync('git', ['-c', 'protocol.file.allow=always', 'clone', '-q', bare, verify], { stdio: 'ignore' }); + execFileSync('git', ['-c', 'protocol.file.allow=always', 'clone', '-q', bare, verify], { stdio: 'ignore', env: process.env }); expect(existsSync(join(verify, 'people', 'alice.md'))).toBe(true); }); @@ -102,7 +140,7 @@ describe('brain-commit-push.sh (D13 guarantee)', () => { rmSync(join(work, '.git', 'hooks', 'post-commit')); // Advance the remote from a second clone so a pull is genuinely needed. const other = mkdtempSync(join(root, 'other-')); - execFileSync('git', ['-c', 'protocol.file.allow=always', 'clone', '-q', bare, other], { stdio: 'ignore' }); + execFileSync('git', ['-c', 'protocol.file.allow=always', 'clone', '-q', bare, other], { stdio: 'ignore', env: process.env }); git(other, 'config', 'user.email', 'o@o.o'); git(other, 'config', 'user.name', 'other'); writeFileSync(join(other, 'remote.md'), 'from other\n'); git(other, 'add', 'remote.md'); git(other, 'commit', '-qm', 'remote change'); git(other, 'push', '-q', 'origin', 'main'); @@ -128,26 +166,26 @@ describe('post-commit hook (D9 local, D7 self-contained)', () => { git(work, 'add', 'note.md'); git(work, 'commit', '-qm', 'note'); // fires .git/hooks/post-commit const head = git(work, 'rev-parse', 'HEAD'); expect(await waitForOrigin(bare, head)).toBe(true); - }); + }, 60_000); test('the hook works even with the committed helper deleted (self-contained)', async () => { rmSync(join(work, 'scripts', 'brain-commit-push.sh')); git(work, 'add', '-A'); git(work, 'commit', '-qm', 'remove helper'); const head = git(work, 'rev-parse', 'HEAD'); expect(await waitForOrigin(bare, head)).toBe(true); - }); + }, 60_000); test('logs a clear LOCAL-ONLY line when origin is unreachable', async () => { git(work, 'remote', 'set-url', 'origin', join(root, 'gone2.git')); writeFileSync(join(work, 'orphan.md'), 'o\n'); git(work, 'add', 'orphan.md'); git(work, 'commit', '-qm', 'orphan'); const log = join(process.env.GBRAIN_HOME!, 'brain-push.log'); - const deadline = Date.now() + 8000; + const deadline = Date.now() + 30_000; let found = false; while (Date.now() < deadline) { if (existsSync(log) && readFileSync(log, 'utf-8').includes('NEEDS ATTENTION')) { found = true; break; } await new Promise(r => setTimeout(r, 150)); } expect(found).toBe(true); - }); + }, 60_000); }); diff --git a/test/e2e/jsonb-roundtrip.test.ts b/test/e2e/jsonb-roundtrip.test.ts index 9abb276f7..9834d52e0 100644 --- a/test/e2e/jsonb-roundtrip.test.ts +++ b/test/e2e/jsonb-roundtrip.test.ts @@ -69,7 +69,7 @@ describeE2E('E2E: JSONB roundtrip — v0.12.1 reliability wave', () => { `; expect(row.t).toBe('object'); expect(row.marker).toBe('rawdata-value'); - }); + }, 30_000); test('logIngest writes pages_updated as array, not double-encoded string', async () => { const engine = getEngine(); @@ -91,7 +91,7 @@ describeE2E('E2E: JSONB roundtrip — v0.12.1 reliability wave', () => { expect(row.t).toBe('array'); expect(Number(row.n)).toBe(3); expect(row.first).toBe('test/a'); - }); + }, 30_000); // files.ts:254 (uploadRaw's cloud-upload branch) was changed from // `${JSON.stringify({...})}::jsonb` to `${sql.json({...})}` in v0.12.1. @@ -114,7 +114,7 @@ describeE2E('E2E: JSONB roundtrip — v0.12.1 reliability wave', () => { expect(row.t).toBe('object'); expect(row.type).toBe('pdf'); expect(row.method).toBe('TUS resumable'); - }); + }, 30_000); // Source-level tripwire: if anyone re-introduces the old `${JSON.stringify(x)}::jsonb` // pattern for the fixed sites, fail loudly. Greps actual source files per the @@ -129,5 +129,5 @@ describeE2E('E2E: JSONB roundtrip — v0.12.1 reliability wave', () => { const source = await Bun.file(new URL(rel, import.meta.url)).text(); expect(source.match(bad)?.[0] ?? null).toBeNull(); } - }); + }, 30_000); });