[Bug] 3.11.2: Parallel subagents fail with `database is locked` — every usage-fact write also runs a `begin immediate` retention prune on a 7.5 GB session store, and required writes have no lock retry

提交前确认 · Pre-submission checklist

• I searched existing issues and confirmed this isn't a duplicate (no open or closed issue mentions database is locked).
• I've read CONTRIBUTING.md.

问题类别 · Category

稳定性 / 崩溃 · Stability / Crash

涉及的 Agent 框架 · Agent framework

ZCode Agent（自研）

严重程度 · Severity

阻塞使用 · Blocking (无法使用核心功能 / core function unusable)

复现频率 · Reproducibility

偶现 · Sometimes

问题描述 · Description

When a session dispatches several subagents in parallel (a 10-lane PR review, or two reviewer shards), one or more Agent tool calls come back to the parent with the text database is locked in place of the subagent's report (that is how the client rendered it in my session; the underlying events are below). The parent has to re-dispatch the lane, and the re-dispatch usually succeeds because the burst has passed.

On 2026-09-12 a single session produced, in ~/.zcode/cli/log/zcode-2026-09-12.jsonl:

snapshot (UTC)	log records containing database is locked	distinct subagent ids	distinct session ids
first 75 records, ending 13:45:59	75	28	7 trace ids
14:32	148	48
15:32	226	59	67

The two previous days' logs contain zero such records.

The lock is on ZCode's own session store. Reading the shipped 3.11.2 bundle, the runtime amplifies its own contention: after every successful usage-fact upsert (model_usage, turn_usage, tool_usage) it runs a retention prune that opens a second begin immediate transaction and executes three delete ... where started_at < ? statements over the same 7.5 GB database; the store's only lock handling is the 5-second busy timeout passed to DatabaseSync; there is no retry or back-off on SQLITE_BUSY for the required writes on the turn path, and no checkpoint policy.

复现步骤 · Steps to reproduce

1. Use a session store that has grown large. Mine, at the time of the snapshot: 7,750 sessions, 356,626 message rows, 1,454,899 part rows, 341,128 tool_usage rows, 7,031 turn_usage rows, 220,001 model_usage rows.
2. Open a workspace in ZCode 3.11.2 and start a task that fans out subagents in parallel (a PR review with 10 Explore lanes, or two general-purpose reviewer shards dispatched at once).
3. Let the subagents run tool calls concurrently for a few minutes.
4. One or more Agent results come back as database is locked; the parent either halts on that lane or must re-dispatch it.

The same workload with 1 or 2 subagents did not reproduce it for me.

期望表现 · Expected behavior

• A transient SQLITE_BUSY while persisting usage facts or turn state should never surface as the result of a subagent dispatch. Required writes should wait with back-off and retry; if persistence still fails, the runtime should log it and still deliver the subagent's report to the parent.
• Retention pruning should not run on the hot path of every usage write against a multi-gigabyte database.
• The session store should have an explicit lock-retry and checkpoint policy sized for parallel subagents.

实际表现 · Actual behavior

Trimmed excerpts from ~/.zcode/cli/log/zcode-2026-09-12.jsonl for one failing lane (same traceId; the turn.failed record's parentSpanId is the usage-write failure's spanId):

{"timestamp":"2026-09-12T13:14:50.358Z","level":"warn","event":"usage.tool.write.failed","module":"core.runtime","message":"Usage tool fact write failed","traceId":"c74ee356-...","spanId":"ea34facf-333e-43","sessionId":"sess_subagent_agent_39ad4b49-...","context":{"agentType":"Explore","errorMessage":"database is locked"}}
{"timestamp":"2026-09-12T13:14:56.032Z","level":"error","event":"turn.failed","module":"core.runtime","message":"Turn failed","traceId":"c74ee356-...","spanId":"59343c1b-bbcc-4f","parentSpanId":"ea34facf-333e-43","sessionId":"sess_subagent_agent_39ad4b49-...","error":{"cause":{"message":"database is locked"}}}
{"timestamp":"2026-09-12T13:14:58.330Z","level":"error","event":"tool.call.failed","module":"core.tool.executor","message":"Tool call failed","traceId":"c74ee356-...","sessionId":"sess_8df71469-...","toolCallId":"call_ae1ee6046abe4c85a261791c","durationMs":25008,"status":"failed"}

Event counts for the lock-bearing records:

event	module	first 75	at 15:32 UTC
usage.tool.write.failed	core.runtime	17	98
turn.failed	core.runtime	25	54
tool.call.failed	core.tool.executor	14	28
usage.model.write.failed	core.runtime	3	16
usage.turn.write.failed	core.runtime	5	10
tool.streaming.execution_failed	core.runtime	5	10
subagent.background.failed	core.subagent	6	9
zcode_protocol.v4.gateway_error		0	1

Within the first 75 records the failures cluster by minute (8 at 13:14, 12 at 13:38, 9 at 13:40 UTC), matching the moments when many lanes finished tool calls together. In 3 of the 7 traces the usage-write warning is the first failure in the trace; in the other 4 an earlier model-network or tool failure preceded the first lock. The turn.failed record's error.cause carries only the message database is locked, not the SQL statement or a stack, so which required write actually threw is an inference (see item 4 below).

What the 3.11.2 bundle does

1. One lock budget, no retry on the write path. SqliteSessionStore opens ~/.zcode/cli/db/db.sqlite with new DatabaseSync(this.dbPath, {timeout: r}), r = t.startupLockTimeoutMs ?? J9e, J9e = 5e3 (bundle line 1480). That timeout is the SQLite busy timeout for the connection, so writers wait up to 5 s for a lock and then throw. The bundle contains no wal_checkpoint call; pragma journal_mode = wal is set at open (line 892).

2. Lock errors are only recognised during migrations. isSqliteLockError (b6t, line 892) is used to classify a migration-lock failure (Timed out waiting for SQLite migration lock), and the migration path m4n has its own wait/retry. No runtime write path uses it.

3. Every successful usage upsert also prunes. The tool_usage upsert ends with .run(...U4n(t)), await AK(e) (line 1406); the successful turn_usage and model_usage upserts end the same way. AK(e) is:

   async function AK(e,t={}){let r=t.beforeTime??Date.now()-z4n;e.exec("begin immediate");try{
     e.prepare("delete from model_usage where started_at < ?").run(r),
     e.prepare("delete from turn_usage where started_at < ?").run(r),
     e.prepare("delete from tool_usage where started_at < ?").run(r),
     e.exec("commit")}catch(n){throw e.exec("rollback"),n}}
   

   with F4n = 30, z4n = F4n*24*60*60*1e3 (30-day retention). So each tool call, each turn and each model request performs a second exclusive write transaction with three range deletes, from every parallel subagent, against the same file. With a 30-day window the deletes almost always match zero rows but still take the write lock.

4. Usage writes fail open, but the turn does not. The usage writers are wrapped in try/catch blocks that only log usage.model.write.failed, usage.turn.write.failed and usage.tool.write.failed (four catch sites: lines 2669 and 2711). The turn.failed record therefore comes from a different, required write. The turn path calls xG(... logEvent:"turn.failed" ...) and then Dw(...) (line 2738), and the message/part persistence function bNt (line 1147: e.exec("begin immediate"); try { await TK(e, t.message); ... commit }) has no retry. My reading is that a required persistence write on that path hit SQLITE_BUSY after the 5-second wait and failed the turn; the log does not name the statement, so please treat that attribution as an inference to confirm on your side.

ZCode 版本 · ZCode version

3.11.2 (ZCode.exe 3.11.2.6792; bundle resources/glm/zcode.cjs built 2026-09-04, win32-x64)

设备 / 系统 / 浏览器 · Device / OS / Browser

Desktop PC / Windows 11 Enterprise 10.0.26200.9445 / ZCode desktop app (Electron) with the bundled CLI runtime; model builtin:zai-coding-plan/GLM-5.3-Flash. Session store %USERPROFILE%\.zcode\cli\db\db.sqlite: 7,568,957,440 bytes, WAL, 4,096-byte pages, 1,847,900 pages, -wal 119,751,952 bytes, wal_autocheckpoint 1000 (read-only snapshot 2026-09-12 15:32 UTC).

截图 / 录屏 / 日志 · Screenshots / Recordings / Logs

See the log excerpts and event-count tables under Actual behavior above.

Independent verification

I had a second, independent automated reviewer (read-only) try to refute this diagnosis against the raw log, the bundle and both databases on the machine. It confirmed the affected database is the ZCode session store, the bundle anchors above, and the log counts. The memory plugin I run alongside ZCode (zmem) keeps its own 51 MB SQLite store, had no lock errors of its own in the same window, and its only read of db.sqlite (a Stop-hook select count(*) from tool_usage where session_id = ?) had zero same-session hits within 5 seconds of any lock. I am separately changing that plugin to open the file with a read-only URI and a 1-second busy budget so its footprint on your store is as small as possible; that does not prove it can never contribute, only that the observed correlation was zero.

Proposed fixes, in priority order

1. Never let a usage or bookkeeping write fail a turn or a subagent result. Keep the fail-open wrappers on the three usage writers and apply the same policy to the retention prune and to any other non-essential persistence on the turn path. The subagent's report must reach the parent even if bookkeeping did not persist.
2. Take the retention prune off the hot path. Run AK(e) once per session start or on a timer per process, not after every usage upsert.
3. Add bounded retry with jitter on SQLITE_BUSY for required writes (message/part persistence, session_input, todo, fork commit). isSqliteLockError already exists; a small retry helper around the begin immediate sites would reuse it.
4. Serialize or batch usage-fact writes through one writer per process (a queue with group commit), so N parallel tool completions produce one transaction rather than N upserts plus N prunes.
5. Measure and control checkpointing. The -wal file is 120 MB with wal_autocheckpoint at the default 1000 pages. That is consistent with checkpoints being starved by concurrent readers and writers, but I have not proven it; logging pragma wal_checkpoint(PASSIVE) results from one owner would confirm or rule it out.
6. Keep the store from growing without bound. 1.45 million part rows and 357 thousand message rows make every lock wait longer. An archive or prune policy for old sessions' message/part rows (with vacuum only while ZCode is stopped) would shrink the window in which writers collide.
7. Instrument which statement returns SQLITE_BUSY and how long it waited. Today the log shows the symptom at the usage-write and turn level only.

Workaround in use

Re-dispatch the failed lane as a fresh agent; it usually succeeds. Reducing parallelism to 2 or 3 subagents reduces the frequency but has not eliminated it.

Start by inspecting resources/glm/zcode.cjs, especially SqliteSessionStore, AK, bNt, the usage-write catch sites, and the existing m4n/isSqliteLockError migration retry path. Reproduce parallel subagent writes against a large WAL database and instrument the required write to confirm which statement returns SQLITE_BUSY. Done means transient lock contention no longer surfaces as a failed subagent result, retention pruning is not performed after every usage write, and the behavior is covered by an appropriate regression test.