Windows: SDK broker can hold session-index lock indefinitely and block startup after 600 attempts

[honb0704]

Environment

• GJC: 0.13.2
• Bun: 1.3.14
• OS: Windows 11 Pro 10.0.26200 x64

Problem

gjc repeatedly fails during startup:

Error: Failed to acquire lock for
C:\Users\<user>\.gjc\agent\sdk\sessions\index.jsonl
after 600 attempts

The lock owner is a live detached SDK broker process. Because the owner is alive, stale-lock recovery correctly refuses to remove the lock, but the broker does not release it before other launches exhaust the full 600-attempt budget.

Reproduction

1. Start one or more GJC sessions on Windows.
2. Leave the SDK broker running long enough for heartbeat, audit, or compaction work to execute.
3. Start another gjc.
4. Startup waits through all 600 lock attempts and crashes.

This reproduced repeatedly across several broker PIDs.

Evidence

One recurrence had this lock metadata:

{"pid":22076,"start_time":"unknown","timestamp":1786683086258}

PID 22076 was still alive and broker.json heartbeat continued updating, but index.jsonl.lock remained held long enough for another GJC process to exhaust the lock budget. The crash log recorded the same failure from multiple launch PIDs.

Relationship to #4250 / #4254

The released v0.13.2 source still contains the read-only snapshot fsync fixed by #4254. Applying the equivalent writable-handle change locally allowed snapshot rotation to complete, but the same broker later held the canonical index lock indefinitely again without creating a new snapshot temp file.

This suggests another awaited operation inside the locked heartbeat/audit/append path can stall on Windows. The exact operation still needs instrumentation; the lock timeout is the observed downstream failure.

Local diagnostic workaround

After stopping the stuck broker, I locally skipped Windows FileHandle.sync() calls in the normal session-index append/snapshot paths and skipped the Windows directory-sync barrier. Two complete GJC startup probes separated by 70 seconds then succeeded, and the lock directory was absent afterward:

OK
OK

This workaround weakens durability and is not proposed as the production fix. It only narrows the suspected stall to a Windows sync operation executed while the machine-global session-index lock is held.

Expected behavior

• No filesystem await should hold the machine-global session-index lock indefinitely.
• A live but wedged broker must not block every new GJC launch.
• Windows durability should remain intact where supported.
• Unsupported or hanging sync operations need bounded handling and diagnostics identifying the exact operation.
• Startup should recover without manually killing the broker or deleting lock state.

Suggested investigation

Instrument each awaited operation inside the locked session-index append, audit, snapshot, rotation, and directory-sync paths. Add a real-Windows regression that runs periodic heartbeat/audit/compaction work and concurrently launches a second session beyond one sweep interval.

Related: #4250, #4254, #4272.

[Dayoooun]

Independent reproduction on a second Windows machine, with the instrumentation this issue asks for. Same failure signature: Failed to acquire lock for ...\sdk\sessions\index.jsonl after 600 attempts, recorded from four separate launch PIDs.

Environment. GJC 0.13.2, Bun 1.3.14, Windows 11 Home 10.0.26200 x64.

Disclosure: I am running a locally patched 0.13.2 — I applied the writable-handle change (fs.open(tmp, "r") → "r+") plus a finally that removes the temp file, before finding #4250/#4254. So snapshot rotation completes here; the lock behaviour below is what remains after that. This matches your report that the writable-handle change alone does not resolve the lock hold.

---

1. Hold distribution (180 s, 1608 samples, 100 ms polling, read-only)

Polled the lock directory and its info record without touching any broker process:

metric	value
occupancy	66.5 %
distinct holds	5
distinct owner PIDs	1 (single broker)
hold p50	25,941 ms
hold p90 / max	43,498 ms
long holds	6.0 s, 42.4 s, 43.4 s, 25.8 s

Worth noting for triage: a single broker PID owned every hold. This is not multi-broker contention.

2. The hold is independent of index size — "log accumulation" is not the cause

When the crash first occurred, index.jsonl had grown to 7,556 lines / 3.69 MB (no snapshot had ever been published, because of #4250). I compacted it to 0 bytes + a 385 KB snapshot, then re-measured.

	before	after
index.jsonl	3.69 MB / 7,556 lines	11.8 KB / 25 lines
observed hold	~29 s	25.9 s p50 / 43.5 s max

A 312× reduction in log size did not shorten the hold. For completeness I also timed replay directly against the original 3.69 MB log: #replayUnderLock() over all 7,552 entries takes 464 ms. Replay is not where the time goes.

3. Where the time actually goes: processIncarnation() inside the lock

checkpointLiveHeartbeats() calls processIncarnation(row.pid) (session-index.ts:1034) for every row that passes alive(), while holding the canonical index lock.

On Windows processIncarnation() returns in ~0 ms when the native binding can read the process, but falls back to spawning a full PowerShell process (process-incarnation.ts:60-69) when it cannot.

Measured over the actual population — the PIDs from this machine's session events that pass alive(), not arbitrary system processes:

session-event PIDs 184  ->  alive() passes 12   (of which 5 pass only via EPERM)

pid 44040   1994 ms  windows:1343116432450908
pid 25004   1774 ms  undefined   [EPERM]
pid 20448   1842 ms  undefined   [EPERM]
pid  2268   1913 ms  undefined   [EPERM]
pid 16444      0 ms  windows:1343114194082768
pid  6628   1736 ms  undefined   [EPERM]
pid 36760      0 ms  windows:1343114370754906
pid  6068   1807 ms  undefined   [EPERM]
pid 35452      0 ms  windows:1343116379954991
pid 41648      0 ms  windows:1343116388425184
pid 34084      0 ms  windows:1343116390532053
pid 42316      0 ms  windows:1343116396842326

total 11,066 ms   |   6 of 12 took >500 ms

Half the rows hit the PowerShell fallback, and the expensive half is almost entirely wasted work:

• alive() (session-index.ts:526-533) treats EPERM from process.kill(pid, 0) as alive. On Windows that admits dead-but-reused PIDs and processes owned by other users.
• Those rows reach line 1034 and pay ~1.8 s each to spawn PowerShell.
• PowerShell cannot read them either, so processIncarnation returns undefined.
• Line 1035 (if (current === undefined || current !== recordedIncarnation) continue) then discards the row.

So ~9 s of a single sweep is spent, under the machine-global lock, producing results that are immediately thrown away. This gets worse over time: as sessions accumulate, so do these ghost PIDs.

I also saw one outlier while sampling unrelated system PIDs — a single processIncarnation() call took 352 s. I observed that once and would not treat it as typical, but the fallback appears to have no upper bound.

4. Sweep cadence is drifting, which is consistent with contention

host_heartbeat events written by this broker, grouped by ts (one group = one checkpointLiveHeartbeats call):

15:51:53 N=2        15:59:43 N=3  (+133 s)     16:08:08 N=3  (+104 s)
15:53:04 N=3 (+71s) 16:00:59 N=3  (+76 s)      16:09:26 N=3  (+78 s)
15:54:20 N=3 (+76s) 16:02:58 N=3  (+120 s)     16:10:31 N=3  (+65 s)
15:55:40 N=3 (+81s) 16:05:12 N=3  (+134 s)     16:11:45 N=3  (+74 s)
15:57:30 N=3 (+110s)16:06:24 N=3  (+72 s)      16:13:09 N=3  (+84 s)

Design target is SESSION_HEARTBEAT_INTERVAL_MS = 60 s; actual spacing is 65–134 s.

5. Scope of what this explains

This accounts for the p50 hold (11 s measured against 25.9 s observed, same order of magnitude, and the sweep-time sample is one snapshot of a set that changes). It does not fully account for the 43.5 s maximum — there are eight other index.refresh() call sites in broker.ts that also take the lock, and I have not instrumented those. I am reporting the mechanism I could measure, not a complete accounting.

Suggested directions, in case they are useful: hoist processIncarnation() out of the locked region (resolve identities before acquiring), bound the PowerShell fallback with a timeout, and negative-cache PIDs where the fallback already returned undefined so the same ghost row is not re-probed every sweep.

Separately and much smaller: checkpointLiveHeartbeats line 1052 does for (const event of events) await appendSync(...), one fsync per event, still under the lock — 189 events measured at 2,011 ms versus 31 ms for a single batched write. That is ~2 s of a ~26 s problem, so it is a footnote rather than a fix.

All measurements are read-only; no broker process was signalled or stopped.

[Dayoooun]

Correction to my previous comment, and a one-line fix that removes the hold entirely on this host.

I attributed the cost to processIncarnation() called from checkpointLiveHeartbeats() (session-index.ts:1034). That attribution was wrong. When I finally instrumented the phases separately instead of inferring, line 1034 measured 0 ms. The expensive call is in reduceEvents(), which checkpointLiveHeartbeats() invokes at line 1026 — still under the canonical index lock, so the symptom is the same, but the line is different.

Phase breakdown of one checkpointLiveHeartbeats() call

(a) #replayUnderLock                    78 ms
(b) reduceEvents(199 sessions)      46,727 ms   <-- the hold
(c) alive() x165 + processIncarnation()  1 ms   (7 pass alive, all resolve natively)

Cause

reduceEvents probes the incarnation for every session row:

const pidAlive = alive(latest.pid);                                    // line 329
...
const recordedIncarnation = effectiveIncarnation(latest);
const currentIncarnation = recordedIncarnation === undefined
    ? undefined
    : processIncarnation(latest.pid);                                  // line 340
...
live: !terminal && pidAlive && heartbeatFresh && incarnationMatches,   // line 358

pidAlive is computed 11 lines above and never consulted at line 340. On this host the index holds 199 sessions, 177 of them with dead pids. Each dead pid misses the native reader and spawns PowerShell (~1.3–2.0 s), and every one of those results is then discarded, because line 358 already forces live: false via pidAlive. currentIncarnation is used nowhere else.

So the lock is held for ~47 s per sweep to compute a value that cannot change the outcome. The cost scales with accumulated dead sessions, which is why this worsens over time and why compacting the log (which does not reduce the session count) did nothing.

Fix

const currentIncarnation =
    recordedIncarnation === undefined || !pidAlive ? undefined : processIncarnation(latest.pid);

Short-circuit on the pidAlive value that is already in scope. No behavioural change: when pidAlive is false, live is false regardless of incarnationMatches, and currentIncarnation has no other reader. The pid-reuse fence is untouched for live pids — they still get a real probe and still must match recordedIncarnation.

Measured effect (same host, same index, 199 sessions)

	before	after
reduceEvents	46,727 ms	1,488 ms
checkpointLiveHeartbeats (1st)	52,216 ms	1,453 ms
checkpointLiveHeartbeats (2nd)	53,482 ms	33 ms

Against the 60 s lock budget (retries: 600 × 100 ms) that moves the hold from "about to expire" to roughly 40× of headroom.

Two things I tried and backed out, in case they save someone time

• Raising retries 600 → 3000. Converts the crash into a hang: measured 134.6 s of startup wait before the lock came free. Not a fix; reverted.
• Excluding EPERM from alive() in the heartbeat loop. EPERM pids here were all reused, unrelated processes (e.g. SUEngine.exe), never session hosts. But after the line-340 fix this measured no difference at all (1,418 ms vs 1,453 ms), so it was pure semantic change for nothing; reverted.

I also added timeout: 2500 to the Bun.spawnSync in runProcessIncarnationCommand (process-incarnation.ts). That is not needed for the numbers above — it bounds the 352 s outlier I reported earlier. A timed-out spawn yields exitCode: null, which line 151's exitCode === 0 check already funnels into the same undefined every caller handles.

Disclosure: still on a locally patched 0.13.2 (the "r+" writable-handle change from #4250/#4254 plus a temp-file finally). Measurements are read-only; no broker process was signalled or stopped.

[Yeachan-Heo]

Issue #4544 status — fix in review, bounded hold on merge

Disposition owner (this lane): issue #4544 only. PR #4555 has a separate dedicated exact-head mutation owner; no further source/branch mutation from this lane.

Root cause (independently reproduced)

A live detached Windows SDK broker held <agentDir>/sdk/sessions/index.jsonl.lock across unbounded work inside the locked critical section, and every new gjc launch exhausted the full 600-attempt lock budget (~60s) and crashed with:

Error: Failed to acquire lock for C:\Users\<user>\.gjc\agent\sdk\sessions\index.jsonl after 600 attempts

Deterministic baseline-red harness (Linux seam, production withFileLock + SessionIndex.open()): live wedged owner → launch exhausts 600 attempts in 60.6s and crashes with exactly the reported error.

Fix carried by PR #4555

• OS process-incarnation probes (win32 fallback spawns powershell.exe) moved before the machine-global index lock in the heartbeat checkpoint pass, the own-pid registration derivation, and the locked projection (reduceEvents/projectIdentity accept a probed-incarnation map). Identity evidence gathered before a delayed lock acquisition is discarded and the cycle writes no heartbeat — fail-closed; the OS is never probed under the lock in any path.
• PowerShell incarnation fallback bounded (timeout: 5000, killSignal: SIGKILL).
• All locked index transactions flow through one named choke point logging an actionable slow-operation warning (timer armed inside the callback, measuring only actual critical-section duration).
• Lock-exhaustion errors now identify the live owner (pid, liveness, lock path) plus the explicit never-displaced guarantee.
• Stale-lock safety unchanged: a proven-live owner's lock is never stolen (fix(state-writer): serialize updateJsonAtomic with cross-process lock (#646) #652 discipline).

Evidence

• Deterministic regression suite packages/coding-agent/test/sdk-session-index-lock-contention.test.ts (live-owner retention without stealing + diagnostics; probes provably outside the lock-held section; throw-inside-critical-section release; aborted-acquisition fail-fast; concurrent-launch convergence).
• Local: index suites ×5 repeated (no flake), broker/router/gc suites (182 pass), sdk-broker-lifecycle-e2e (82 pass), bun check clean, live-broker contention harness green.
• dev CI on the reviewed head: all 34 jobs green including the real windows-latest Windows dev:doctor + session-path regression job running the new suite; the sole red is the intentional needs-human exact-head PR-contract block pending independent authenticated review.

Current hold

PR #4555 is open at head 7171a4f7f78e with a single needs-human verdict line and no approving review yet. This issue closes only after PR #4555 merges into dev and merged-history verification proves the fix is contained in dev. Holding here; no mutation of the PR from this lane.

—
[repo owner's gaebal-gajae (clawdbot) 🦞]