From 192eb1dfbda6b4ca20bc785d4e7bce7d3a8084a8 Mon Sep 17 00:00:00 2001 From: Tom Boucher Date: Sat, 29 Aug 2026 13:27:14 -0400 Subject: [PATCH] fix(#3886): git commit timeout reported as commit_timeout; stale lock surfaced; 30s band (#4046) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * test(#3886): a timed-out git commit reports commit_timeout, not commit_failed (failing first) * fix(#3886): git commit timeout reported as commit_timeout; 30s band; stale-lock surfaced cmdCommit's git commit invocation did not distinguish a spawnSync timeout from a real non-zero exit (#2608 fixed this for the staging loop only): a slow pre-commit hook crossing the 10s cap was SIGTERM'd mid-hook and reported as reason commit_failed with whatever partial stderr git had flushed (in the reporter's case an incidental CRLF warning), while the kill left a stale .git/index.lock blocking the next attempt. All three commit sites now check isSpawnTimeout before the nothing-to-commit/ordinary-failure branches: cmdCommit reports reason commit_timeout + timed_out:true and names the stale lock's path (surfaced, not auto-deleted — deleting a lock a live git holds is destructive; the caller recovers deliberately); the subrepo counterparts do the same within their per-repo result / rollback error. The commit calls also move to the 30s band the push call already uses — husky+lint-staged alone idles ~4s on Windows before any task runs. * fix(#3886): review fold-ins — git-path lock resolution, shared band constant, executor contract row, precedence pin - The stale-lock path is resolved via git rev-parse --git-path index.lock, never a literal .git/index.lock join (#3588 row 8's class: a linked worktree's .git is a FILE, so the literal path cannot exist there while the real lock — under /worktrees// — blocks the next commit; this repo leans on linked worktrees). - COMMIT_TIMEOUT_MS hoisted; all three sites and their messages build from it (the subrepo variant also regains the stdout fallback the primary site had). - agents/gsd-executor.md's commit-result contract gains the commit_timeout row with the OPPOSITE retry advice from staging_timeout (remove the stale lock, then retry once) — an executor matching the doc previously had no handling for the new reason. - Precedence pin: a timeout whose partial output contains 'nothing to commit' must still read as a timeout (branch-reorder mutant). Emitted-Drift-Ack-Growth: gsd-executor.md — #3886: +commit_timeout row to the commit-result contract with the retry guidance OPPOSITE staging_timeout's (remove the stale lock, then retry once); the executor previously had no handling for the new reason. * chore(#3886): changeset fragment (pr number backfilled after PR creation) * chore(#3886): backfill changeset PR number (4046) --------- Co-authored-by: sim --- .changeset/lucky-ibex-rally.md | 5 ++ agents/gsd-executor.md | 6 ++ src/commands.cts | 81 +++++++++++++++++++- tests/commit-files-pathspec.test.cjs | 108 +++++++++++++++++++++++++++ 4 files changed, 197 insertions(+), 3 deletions(-) create mode 100644 .changeset/lucky-ibex-rally.md diff --git a/.changeset/lucky-ibex-rally.md b/.changeset/lucky-ibex-rally.md new file mode 100644 index 000000000..bc0b5c96b --- /dev/null +++ b/.changeset/lucky-ibex-rally.md @@ -0,0 +1,5 @@ +--- +type: Fixed +pr: 4046 +--- +a timed-out git commit is now reported as commit_timeout with the stale .git/index.lock path surfaced in the error, instead of commit_failed with the killed hook's partial stderr; the commit call also moves to the 30s band the push call uses (pre-commit hooks alone can exceed the old 10s cap) (#3886) diff --git a/agents/gsd-executor.md b/agents/gsd-executor.md index b153f5943..b7794a979 100644 --- a/agents/gsd-executor.md +++ b/agents/gsd-executor.md @@ -806,6 +806,12 @@ one of these shapes: success path.** Record "skipped (.planning gitignored)" and move on. - `{committed: false, reason: 'nothing_to_commit' | 'commit_failed', ...}` — no-op / genuine failure; surface in the completion notes. +- `{committed: false, reason: 'commit_timeout', timed_out: true, error}` — + `git commit` itself was timeout-killed mid-hook (#3886). Nothing committed. + Unlike `staging_timeout`, a retry CAN succeed after removing the stale lock + the error names (`…/index.lock`): verify no git process is running, remove + it, address why the pre-commit hook exceeded the band (or stage fewer + changes), then retry once. - `{committed: false, reason: 'staging_failed' | 'staging_timeout', file, error}` — `git add` itself failed (#2608), e.g. an unwritable index. Nothing committed, index rolled back. Surface `file` + `error` (git's stderr); do not retry — a diff --git a/src/commands.cts b/src/commands.cts index ebccd015b..897ce3c65 100644 --- a/src/commands.cts +++ b/src/commands.cts @@ -103,6 +103,8 @@ interface CommitToSubrepoRepoResult { files: string[]; reason?: string; error?: string; + /** #3886: true when the repo's git commit was timeout-killed (reason commit_timeout). */ + timed_out?: boolean; } interface EffortSyncChange { @@ -1820,8 +1822,26 @@ function cmdCommit(cwd: string, message: string | undefined, files: string[] | u if (canScope) { commitArgs.push('--', ...stagedPaths); } - const commitResult = execGit(commitArgs, { cwd }); + // #3886: `git commit` runs pre-commit hooks (husky/lint-staged routinely + // idles ~4s on Windows before any task) — 10s is too tight, and a timeout + // kill is NOT an ordinary failure. Same band as the push call below. + const commitResult = execGit(commitArgs, { cwd, timeout: COMMIT_TIMEOUT_MS }); if (commitResult.exitCode !== 0) { + // #3886: a SIGTERM'd git commit is a timeout, not commit_failed — the + // partial stderr it flushed (often incidental CRLF warnings) is noise, + // and the kill can leave a stale index.lock that blocks the next + // attempt. Report the distinct reason and surface the lock path. + if (isSpawnTimeout(commitResult)) { + const result = { + committed: false, + hash: null, + reason: 'commit_timeout', + timed_out: true, + error: commitTimeoutMessage(cwd, commitResult.stderr, commitResult.stdout), + }; + output(result, raw, 'failed'); + return; + } if (commitResult.stdout.includes('nothing to commit') || commitResult.stderr.includes('nothing to commit')) { const result = { committed: false, hash: null, reason: 'nothing_to_commit' }; output(result, raw, 'nothing'); @@ -1969,8 +1989,21 @@ function cmdCommitToSubrepo(cwd: string, message: string | undefined, files: str const commitArgs = canScopeSub ? ['commit', '-m', message as string, '--', ...stagedRelPaths] : ['commit', '-m', message as string]; - const commitResult = execGit(commitArgs, { cwd: repoCwd }); + const commitResult = execGit(commitArgs, { cwd: repoCwd, timeout: COMMIT_TIMEOUT_MS }); if (commitResult.exitCode !== 0) { + if (isSpawnTimeout(commitResult)) { + // #3886 (subrepo counterpart): timeout ≠ error; surface the stale-lock + // path a killed commit can leave in the subrepo. + repos[repo] = { + committed: false, + hash: null, + files: repoFiles, + reason: 'commit_timeout', + timed_out: true, + error: commitTimeoutMessage(repoCwd, commitResult.stderr, commitResult.stdout), + }; + continue; + } if (commitResult.stdout.includes('nothing to commit') || commitResult.stderr.includes('nothing to commit')) { repos[repo] = { committed: false, hash: null, files: repoFiles, reason: 'nothing_to_commit' }; continue; @@ -2124,9 +2157,17 @@ function cmdPrSubrepo( const commitArgs = canScopePr ? ['commit', '-m', commitMessage as string, '--', ...changedFiles] : ['commit', '-m', commitMessage as string]; - const commitResult = execGit(commitArgs, { cwd: repoCwd }); + const commitResult = execGit(commitArgs, { cwd: repoCwd, timeout: COMMIT_TIMEOUT_MS }); if (commitResult.exitCode !== 0) { rollback(); + if (isSpawnTimeout(commitResult)) { + // #3886 (PR-subrepo counterpart): name the timeout and the stale lock + // instead of echoing the killed hook's partial stderr. + error( + `git commit timed out after ${COMMIT_TIMEOUT_MS / 1000}s in ${repo} (killed mid-hook; ` + + `a stale lock may remain at ${resolveIndexLockPath(repoCwd)} — remove it if no git process is running)`, + ); + } error(`Failed to commit in ${repo}: ${commitResult.stderr}`); } @@ -2996,6 +3037,40 @@ interface HooksDirResolution { reason?: string; } +/** + * #3886: the timeout band for `git commit` — pre-commit hooks (husky + + * lint-staged idles ~4s on Windows before any task) routinely exceed the 10s + * plumbing default; 30s is the same band the push call uses. Shared by all + * three commit sites AND their timeout messages, so the number and the text + * cannot drift apart. + */ +const COMMIT_TIMEOUT_MS = 30_000; + +/** + * #3886: resolve where a killed `git commit` would leave its stale + * index.lock — via `git rev-parse --git-path index.lock`, never a literal + * `.git/index.lock` join (#3588 row 8's class: a linked worktree's `.git` is + * a FILE pointing at `/worktrees//`, so the literal path + * cannot exist there while the real lock blocks the next commit). Best + * effort: any resolution failure falls back to the literal join, and the + * message already hedges with "may remain". + */ +function resolveIndexLockPath(cwd: string): string { + const result = execGit(['rev-parse', '--git-path', 'index.lock'], { cwd }); + if (result.exitCode !== 0) return path.join(cwd, '.git', 'index.lock'); + const raw = result.stdout.trim(); + return raw ? (path.isAbsolute(raw) ? raw : path.join(cwd, raw)) : path.join(cwd, '.git', 'index.lock'); +} + +/** #3886: shared timeout message shape for all three commit sites. */ +function commitTimeoutMessage(cwd: string, stderr: string, stdout: string): string { + return ( + `git commit timed out after ${COMMIT_TIMEOUT_MS / 1000}s (killed mid-hook; a stale lock may remain at ` + + `${resolveIndexLockPath(cwd)} — remove it if no git process is running). ` + + `Partial stderr: ${stderr || stdout || '(none)'}` + ); +} + /** * Resolve the real git hooks directory for `cwd` via `git rev-parse * --git-path hooks` — never a literal `.git/hooks` join (#3588 row 8: a diff --git a/tests/commit-files-pathspec.test.cjs b/tests/commit-files-pathspec.test.cjs index 755480a50..1538b48cc 100644 --- a/tests/commit-files-pathspec.test.cjs +++ b/tests/commit-files-pathspec.test.cjs @@ -19,6 +19,7 @@ const path = require('path'); const os = require('os'); const { spawnSync } = require('child_process'); const { createTempGitProject, cleanup, runGsdTools } = require('./helpers.cjs'); +const { execFileSync } = require('node:child_process'); const { gitOrThrow } = require('./helpers/git-fixture.cjs'); // #3145: class-norm timeout, not a per-suite value — see helpers/timeouts.cjs. const { GIT_TIMEOUT_MS } = require('./helpers/timeouts.cjs'); @@ -2643,3 +2644,110 @@ describe('workflow call sites declare --files (#2269)', () => { }); }); }); + +// ─── #3886: git commit timeout is a commit_timeout, not a commit_failed ───── + +describe('commit timeout reporting (#3886)', () => { + // Same in-process execGit interception family as #2608's staging harness + // above, verb-swapped to `commit`: the killed `git commit` surfaces the + // SIGTERM+ETIMEDOUT shape (posix) or the ETIMEDOUT-only shape (Windows — + // #3050: signal is not reliably reported there). + function commitWithTimedOutCommit({ cwd, files, stderr = "warning: LF will be replaced by CRLF", timeoutShape = 'posix' }) { + const script = ` +const path = require('path'); +const LIB = ${JSON.stringify(LIB)}; +const projection = require(path.join(LIB, 'shell-command-projection.cjs')); +const { cmdCommit } = require(path.join(LIB, 'commands.cjs')); +const timeoutShape = ${JSON.stringify(timeoutShape)}; +const stderrText = ${JSON.stringify(stderr)}; +const real = projection.execGit; +projection.execGit = (args, opts) => { + if (args[0] === 'commit') { + const e = new Error('spawnSync git ETIMEDOUT'); + e.code = 'ETIMEDOUT'; + return { exitCode: 1, stdout: '', stderr: stderrText, signal: timeoutShape === 'posix' ? 'SIGTERM' : null, error: e }; + } + return real(args, opts); +}; +cmdCommit(${JSON.stringify(cwd)}, 'docs: probe', ${JSON.stringify(files)}, false, false, false); +`; + const run = spawnSync(process.execPath, ['-e', script], { encoding: 'utf-8', timeout: 15_000 }); + if (run.status !== 0 && !run.stdout) { + throw new Error(`probe crashed: ${run.stderr}`); + } + return { result: JSON.parse(run.stdout) }; + } + + let tmpDir; + beforeEach(() => { + tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'gsd-3886-')); + fs.mkdirSync(path.join(tmpDir, '.planning'), { recursive: true }); + fs.writeFileSync(path.join(tmpDir, '.planning', 'STATE.md'), '# State\n'); + execFileSync('git', ['init', '-b', 'main'], { cwd: tmpDir, timeout: 15_000 }); + execFileSync('git', ['config', 'user.email', 't@example.com'], { cwd: tmpDir, timeout: 15_000 }); + execFileSync('git', ['config', 'user.name', 'T'], { cwd: tmpDir, timeout: 15_000 }); + }); + afterEach(() => cleanup(tmpDir)); + + for (const shape of ['posix', 'windows']) { + test(`a timed-out git commit reports commit_timeout (${shape} shape), naming the stale lock`, () => { + const { result } = commitWithTimedOutCommit({ cwd: tmpDir, files: ['.planning/STATE.md'], timeoutShape: shape }); + assert.equal(result.committed, false); + assert.equal(result.reason, 'commit_timeout', `a timeout must not read as commit_failed (${shape})`); + assert.equal(result.timed_out, true); + assert.ok( + (result.error || '').includes('index.lock'), + 'the error must surface the stale .git/index.lock a killed git commit can leave behind' + ); + }); + } + + test('a timeout whose partial output contains "nothing to commit" is still a timeout (precedence pin)', () => { + // #3886 review: the isSpawnTimeout gate runs BEFORE the nothing-to-commit + // branch — a killed commit can have flushed anything, including the + // nothing-to-commit text, and must still read as a timeout. Reordering + // the branches would silently revert to the misroute this fix retires. + const script = ` +const path = require('path'); +const LIB = ${JSON.stringify(LIB)}; +const projection = require(path.join(LIB, 'shell-command-projection.cjs')); +const { cmdCommit } = require(path.join(LIB, 'commands.cjs')); +const real = projection.execGit; +projection.execGit = (args, opts) => { + if (args[0] === 'commit') { + const e = new Error('spawnSync git ETIMEDOUT'); + e.code = 'ETIMEDOUT'; + return { exitCode: 1, stdout: 'nothing to commit, working tree clean', stderr: '', signal: 'SIGTERM', error: e }; + } + return real(args, opts); +}; +cmdCommit(${JSON.stringify(tmpDir)}, 'docs: probe', ['.planning/STATE.md'], false, false, false); +`; + const run = spawnSync(process.execPath, ['-e', script], { encoding: 'utf-8', timeout: 15_000 }); + const result = JSON.parse(run.stdout); + assert.equal(result.reason, 'commit_timeout', 'the timeout gate must win over the nothing-to-commit text in partial output'); + assert.equal(result.timed_out, true); + }); + + test('an ordinary commit failure still reports commit_failed (no regression)', () => { + const script = ` +const path = require('path'); +const LIB = ${JSON.stringify(LIB)}; +const projection = require(path.join(LIB, 'shell-command-projection.cjs')); +const { cmdCommit } = require(path.join(LIB, 'commands.cjs')); +const real = projection.execGit; +projection.execGit = (args, opts) => { + if (args[0] === 'commit') { + return { exitCode: 128, stdout: '', stderr: 'fatal: injected commit failure', signal: null, error: null }; + } + return real(args, opts); +}; +cmdCommit(${JSON.stringify(tmpDir)}, 'docs: probe', ['.planning/STATE.md'], false, false, false); +`; + const run = spawnSync(process.execPath, ['-e', script], { encoding: 'utf-8', timeout: 15_000 }); + const result = JSON.parse(run.stdout); + assert.equal(result.committed, false); + assert.equal(result.reason, 'commit_failed'); + assert.equal(result.timed_out, undefined); + }); +});