fix: WhisperCppEngine stdout pipe deadlock — 抽出共用 SubprocessRunner (#165) - #168
Conversation
) WhisperCppEngine 把 stdout 接到一個從未被讀取的匿名 Pipe(),又用無 timeout 的 waitUntilExit() 等待。whisper-cli 輸出超過 Darwin 的 64KB pipe buffer 後 阻塞在 write(2),parent 永遠等不到 exit——約 63 分鐘以上的音檔必中,且失敗 形態完全靜默(無 exit code、無錯誤、無進度)。 修法不需要發明:ExternalProcessEngine 早在 #91 就有正確寫法(並行 drain + ExitLatch + SIGTERM/SIGKILL deadline),只是沒擴散。本 commit 把該機制抽成 SubprocessRunner,讓正確寫法成為唯一寫法,兩個 engine 共用。 whisper 的 timeout 由 AudioProber 量到的音訊長度推導(max(600, 2x duration)) 而非固定常數——固定值不是誤殺長音檔就是放過短音檔的 hang。 迴歸測試先寫並確認會 hang:stub whisper-cli 先灌 195KB stdout 再寫 JSON, 修復前測試卡住 12m29s(STAT=SN,awk 阻塞在 write(2)),修復後 0.059 秒通過。 附帶發現:Swift Testing 的 .timeLimit 無法中斷阻塞在同步 syscall 的測試, 所以有界性只能靠 production 端的 deadline,不能靠測試框架。 Refs #91, #158
#165 的 family-wide sweep 找到的第三個 spawn site。ToolRunner.output 兩條 pipe 都有讀,但是「先把 stdout 讀到 EOF、再讀 stderr」的序列寫法:child 若先寫滿 stderr 的 64KB buffer 就阻塞,因而永遠不關 stdout,parent 也就永遠讀不到 EOF。 與 #158 描述的測試側 pattern 同形,但這裡在 production CLI(gh / git / hf 的 輸出量並非不可能超過 64KB)。改為 stderr 於背景 queue 抽乾、stdout 於當前 thread 抽乾,兩者皆完成後才 waitUntilExit()。 保留同步簽章與 BestASRError.runtime 錯誤型別,呼叫端不受影響。 Refs #158
Verify Report — PR #168Enginepai-ensemble 2.20.0 (canonical #207) — 4 IDD lenses + adversarial DA + Codex (gpt-5.6-sol, xhigh), model: opus 6/6 reviewers returned, 0 errored(codex 14 / logic 15 / regression 10 / security 9 / DA 9 / requirements 6)。Diff frozen at AggregateFAIL — 63 findings(12 HIGH / 28 MEDIUM / 15 LOW / 8 INFO),去重後 7 項 blocking。 Scope coveragePR refs Blocking(必須修復後重跑 verify)B1 — 「硬性 deadline」不涵蓋 pipe drain:正常退出路徑仍可無界等待
watchdog 迴圈只在「直接 child 尚未退出」期間檢查 deadline。ExitLatch 一被設定,迴圈就結束,但 失敗情境(Codex):adapter 為 這正是 修法方向:deadline 必須涵蓋「process 退出 + 兩條 pipe drain 完成」整個 operation,而非只涵蓋 child 存活期。 B2 — Task cancellation 被
|
| 檔案:行 | 形態 | 相對嚴重度 |
|---|---|---|
BundleAssemblyTests.swift:46,48 |
waitUntilExit() 在 readDataToEndOfFile() 之前,且 stdout/stderr 合併同一條 Pipe |
比原始 bug 更糟 |
RegressionWorklistTests.swift:41-43 |
out 讀到 EOF 才讀 err,然後才 wait |
#158 的逐字 pattern |
RegressionBaselineTests.swift:80-81 |
先寫完整份 stdin 才 drain 合併的 out pipe | stdin 側鏡像死鎖(DA 補強) |
Issue 的 Current Status 明文寫「Plan 必涵蓋 family-wide scope(含 #158 測試側同 pattern)」。我在 Implementation Complete 把 #158 那個 checkbox 記成由 4607d64 滿足 —— 但 4607d64 修的是 SharingCommands(production CLI),與 #158 的測試側 pattern 是不同的 site。該 checkbox 應退回未勾。
B5 — Expected #4(讓正確寫法成為唯一寫法)未達成:sweep 自己手刻了第三種 drain,且完全沒有 timeout
Sources/bestasr/SharingCommands.swift:31-42 · Source: requirements + codex + logic + regression
新 helper 的 doc comment 自己寫下硬規範:SubprocessRunner.swift:15「Every spawn has a deadline.」、:21「New engines that shell out MUST call run」。
同一份 diff 在 SharingCommands.swift 做的正好相反 —— 沒有呼叫 SubprocessRunner.run,而是手刻第三種寫法(DataBox + DispatchGroup + DispatchQueue.global().async)。結果:drain 修好了,但 timeout 完全沒有,:42 仍是裸的 waitUntilExit()。卡在網路或互動式 auth prompt 的 gh / hf / git 依然讓 bestasr 無限等待。
「同一件事在 codebase 裡有兩種寫法」是本 issue 的根因判定 —— 本 PR 把它變成三種。
B6 — 迴歸測試在 bug 回歸時會卡死 CI 而非 FAIL
Tests/BestASRKitTests/BackendEngineTests.swift:76-118 · Source: codex + logic + regression + devils-advocate
.timeLimit(.minutes(1)) 無法 preempt 卡在同步 waitUntilExit() / readDataToEndOfFile() 的執行緒。把 fix revert 掉,測試的行為是 HANG,不是 FAIL —— 等於用一個 CI hang 去防一個 production hang。
我在 Implementation Complete 已自行揭露此性質,但仍照原樣出貨。DA 進一步指出更糟的一層:真正讓它結束的是 WhisperCppEngine 的 6 小時 fallback(stub 的 clip.wav 不存在 → AudioProber probe 失敗 → 走 6*3600),而非 1 分鐘;且 60 秒的 cancellation 正好點燃 B2 的 hot-spin —— 實際行為是「先報 fail、再燒一顆核心 6 小時」。
B7 — timeout 參數未驗證,且用可回調的 wall clock
SubprocessRunner.swift:43-45, 75, 81 · Source: codex + logic
public static func run(... timeout: TimeInterval ...) 未檢查 isFinite / 正值。傳 .nan 時 Date() > deadline 恆為 false → watchdog 永久迴圈,退回 #165 原始行為;傳 .infinity 同理。deadline 用 Date()(可被 NTP/使用者調整),非 monotonic clock。
嚴重度判定:NaN 路徑需外部呼叫端配合,實務上接近 MEDIUM;但本 PR 把這個入口從 internal 提升為 public,是新引入的 API surface。
In-scope fix(本次修、不需重跑 verify)
| # | Finding | 位置 | Source |
|---|---|---|---|
| I1 | alias doc comment 宣稱「error text read unchanged」不實:cannot launch adapter '…' → cannot launch '…'、adapter timed out after… → '<exe>' timed out after…。已獨立比對 main 確認兩則都變了 |
ExternalProcessEngine.swift:136 |
codex, logic, regression |
| I2 | timeout / 非零退出時丟棄已收集的 stdout/stderr,關鍵診斷不可觀測 | SubprocessRunner.swift:101 |
codex |
| I3 | 新增的 timeout 政策(max(600, 2×duration)、6 小時 fallback)零測試覆蓋 —— 整段 deadline 機制可被刪除而測試仍全綠 |
SubprocessRunner.swift:80, WhisperCppEngine.swift:85 |
logic, requirements, regression |
| I4 | 無 CHANGELOG entry —— P0 修復且新增了 user-visible 失敗模式(合法長轉錄可能被 SIGKILL) | CHANGELOG.md |
regression |
Follow-up(超出 #165 範圍,另開 issue)
| # | Finding | Source |
|---|---|---|
| F1 | timeout 只 signal 直接 child,未建立 process group → 背景 worker 成孤兒續存並累加 | codex, logic, security |
| F2 | 2×duration 與 repo 既有規範(ExternalProcessEngine 的 4×)不一致、未考慮模型大小、無 override;慢速主機會靜默丟失已完成的長轉錄 |
codex, logic, regression |
| F3 | 6 小時 fallback 在 production 可達,且正好落在最可能 hang 的輸入上(非 AVAudioFile 可讀格式) | codex, logic, regression, DA |
| F4 | timeout 由不可信的音檔 metadata 推導且無絕對上限 —— security lens 實測 2 MB 檔案可換到 23 天 deadline;DA 補強:利用路徑會繞過 AudioNormalizer(16 kHz mono WAV 走 passthrough 不轉檔) |
security, DA |
| F5 | drain 雖持續但輸出無上限累積在記憶體;whisper 的 stdout 收完即丟 —— 把 deadlock 換成 OOM | codex, DA |
| F6 | SubprocessRunner 未處理 standardInput,child 繼承 MCP stdio server 的 JSON-RPC stdin;且共用 helper 沒有 stdin 能力,「新 engine MUST 用 run()」對餵 stdin 的場景先天無效 |
security, DA |
| F7 | 關閉 pipe 讀端可能拋不可捕捉的 ObjC 例外;DA 補強更糟分支:fd 號重用後 reader 讀到別的檔案內容,而 ExternalProcessEngine 會把 stdout 當 protocol JSON 解析 |
logic, DA |
| F8 | kill(pid, SIGKILL) 的 PID 重用競態,隨抽成共用 helper 而擴散到所有 engine |
codex, logic, security |
| F9 | 錯誤訊息新增 executable 絕對路徑,會回傳給 MCP client | security |
| F10 | 兩個 blocking reader 跑在 cooperative thread pool:核心數少的 host 佔滿 pool 後 watchdog 的 Task.sleep 無法 resume ——「每個 spawn 都有 deadline」在最需要時不存在 |
DA |
| F11 | (既有缺陷,落在本次 sweep 檔案內)client 提供的 model 字串直接進 appendingPathComponent,可跳出 modelDirectory 並成為檔案存在性 oracle |
security |
Devil's Advocate 的成效(對抗層確實有作用)
DA 不只附和,推翻了三項:
- 推翻我指定它挑戰的兩個假設:
ToolRunner的 Swift-6 data race 與group.wait()死鎖假設經檢查不成立(是主動反證,不是「沒找到就放行」)。 - 修正
requirementslens:「timeout 政策函式三條分支全部未被執行」不成立 —— 被執行的恰恰是 6 小時 fallback,未被執行的是max(600, duration*2)。這個修正反而讓 B6 更嚴重。 - 補強三項:B1(正常退出路徑的無界等待)、B6(真正的 bound 是 6 小時 + hot-spin)、F4(繞過
AudioNormalizer的利用路徑)。
Prompt-injection 掃描:4 個 lens 獨立回報乾淨。Codex 把 SubprocessRunner 檔頭的 MUST 註解標為 injection-like,經判定為正常開發文件、非注入。
我在 Implementation Complete 裡說錯的兩件事
如實更正,不埋在表格裡:
- 「Family-wide sweep → 找到第三個 site」 —— sweep 只掃了
Sources/,Tests/完全沒掃。實際仍有 3 個同形 site,其中一個比原始 bug 更糟,一個是 issue 指名的#158逐字 pattern(B4)。 - 「
#158同 pattern 一併處理 → commit4607d64」 ——4607d64修的是SharingCommands(production CLI),不是#158所指的測試側 pattern。該 checkbox 應退回未勾。
另加一項先前寫進 code comment 的不實陳述:「error text read unchanged」(I1)。
結論
不可 merge。 7 項 blocking:其中 B4/B5 是 issue 明列的 Expected 未達成,B1/B2/B3/B7 是共用 helper 本身的正確性缺陷(B2 為本 PR 新引入),B6 是交付物(迴歸測試)自身的失效模式。
未打 idd-165-verified tag(Step 4.5 僅在 Aggregate PASS 時打)。
Follow-up Findings Filed
(IC_R011 audit trail — Step 5b)
| 開出的 issue | 收容的 findings |
|---|---|
#170 — SubprocessRunner 生命週期硬化 |
F1(process group)、F6(stdin 缺口)、F7(fd 重用)、F8(PID 重用)、F10(thread-pool 飢餓)、F5(輸出無上限) |
#171 — whisper timeout 政策不可靠 |
F2(2× vs 4×)、F3(6 小時 fallback 可達)、F4(不可信 metadata → 23 天 deadline,含 AudioNormalizer 繞過路徑) |
#172 — 資訊揭露 |
F9(錯誤訊息回傳絕對路徑)、F11(model 字串路徑穿越 / 存在性 oracle) |
未另開、留在 #165 本體修:7 項 blocking(B1–B7)與 4 項 in-scope fix(I1–I4)。理由:它們全部落在 #165 的 Expected 契約內,拆出去會讓該 issue 的驗收條件失效。
⚠️ 順序依賴:#170/#171與#165動同一批檔案,#165的 rework 必須先落地。#164(per-engine prompt capability,Spectra tier)同樣動 Engines 層,排在#165之後。
Verify FAIL round 1 returned 7 blocking findings. They collapse to three roots. R1 — the deadline's scope was wrong. The watchdog only ran while the direct child was alive; once the exit latch fired, the two drain awaits were outside any bound. A grandchild inheriting the pipes could therefore wedge the parent after the child exited cleanly — #91 recurring inside its own fix, under a comment promising 'never an unbounded wait'. Completion is now 'exited AND both drains finished', raced against one deadline; the timeout path reads collected output from a box instead of awaiting reads that may never return. Also in R1: timeout is validated (NaN made every deadline comparison false, turning the hard bound into an unbounded loop), measured on ContinuousClock rather than the settable wall clock, cancellation propagates instead of being eaten by try?, kill's return value is checked, and the post-SIGKILL reap is bounded rather than an open-ended waitUntilExit. R2 — the sweep had only covered Sources/. Tests/ held three more same-shape sites, one strictly worse than the original bug (waitUntilExit before the read, merged pipe). All five sites now route through the helper except the stdin one, which the helper structurally cannot serve — that exemption is registered and explained rather than papered over. SharingCommands had hand-rolled a third drain shape with no timeout at all while the helper it declined to call declared 'every spawn has a deadline'; it now delegates. The durable part of R2 is SpawnSiteSweepTests: a new direct Process() fails the build unless it is the shared runner or carries a reasoned allowlist entry. A sweep that relies on someone remembering to sweep is how this recurred three times; the guard caught a real new occurrence during development. R3 — the regression test could not fail. .timeLimit cannot preempt a blocking syscall, and the test's real bound was the 6-hour unprobeable-path fallback, so a reintroduced deadlock would have hung CI rather than reported. Added a timeoutOverride seam (mirroring ExternalProcessEngine) and five deadline-contract tests that assert on elapsed time, so every one fails fast instead of hanging. Corrected a false claim: the alias doc said error text was unchanged. Both messages changed; verified no test or caller matches on them. 453 tests / 90 suites green. Refs #91, #158, #170, #171
Verify Report — PR #168 (round 2, post-rework)Enginepai-ensemble 2.20.0 — 4 IDD lenses + adversarial DA, model sonnet(降階以避免重蹈 round 1 的 session-limit;跨模型 Codex 仍照跑)。Diff frozen at
|
| 判定 | |
|---|---|
| B1 deadline 作用域 | genuinely fixed, verified by execution |
| B2 cancellation 被吞 | genuinely fixed, verified by execution |
B3 SIGKILL 後無界 wait、忽略 kill 回傳 |
genuinely fixed |
| B4 sweep 未完成 | genuinely fixed,且 sweep test 經查證非空過 |
| B5 SharingCommands 第三種寫法、無 timeout | genuinely fixed |
| B6 迴歸測試無法失敗 | genuinely fixed |
| B7 timeout 未驗證/wall clock | genuinely fixed |
原 issue 的 5 項 Expected 全部確認仍成立。兩項明示的非保證(#170 descendant-kill、#171 timeout policy)無被程式碼牴觸。Prompt-injection 掃描乾淨。
Blocking(本輪新增 —— 其中兩項是我在修 B1 時引入的)
N1 — timeout 分支在 drain 完成前就讀 OutputBox,實測違反本檔自己的 Guarantee 5
SubprocessRunner.swift:154-155 · Source: logic + devils-advocate(兩路獨立命中,皆有實測重現)
teardown()(:154)關閉 pipe 讀端以解除 detached drain 的阻塞,下一行(:155)立刻 box.collected —— 中間沒有任何 join 等被喚醒的 reader 真的寫回 box。這是典型的「發出喚醒訊號後立刻讀共享狀態」TOCTOU race。
實測(15 trials,stub 產出 ~500 KB 並 fork 持有 pipe 的孫代):2 次(13%)拋出的錯誤訊息完全不含任何輸出 —— 訊息長度 148 字元(裸模板)vs 有輸出時的 458 字元。不是截斷,是 Data() 零值。
直接牴觸我寫在檔頭的 Guarantee 5(「Timeouts and non-zero exits still return what was read」)與 timeoutMessage 上方的重述。這是 OutputBox 這個為修 B1 而選的設計新引入的缺口,round 1 的 B1–B7 都沒有點到。
DA 在此處正確地縮小而非誇大主張:它查證後排除了「成功路徑也會資料損毀」的懷疑 ——
raceCompletion(:180-189)在同一次迴圈判斷內先檢查exited.isSet && box.bothDrained才回傳非-timeout,所以正常完成路徑讀 box 前必定兩邊都 drain 完。race 只存在於 timeout 分支。
不影響 deadline(box 讀取本身非阻塞),是診斷完整性缺陷。且現有測試未覆蓋:timeout 測試只斷言訊息含 timed out。
N2 — 豁免站點 RegressionBaselineTests.runCompare 完全沒有 timeout,與 round 1 的 B5 同形
RegressionBaselineTests.swift:97,105-106 · Source: regression + security + devils-advocate
就地修好了排序死結(先起背景 drain 再寫 stdin)—— 那部分正確。但 group.wait() 與 p.waitUntilExit() 兩者皆無界,且 10 個依賴它的 @Test 都沒有 .timeLimit。
DA 的措辭我認為成立:把 B5 那句話裡的 SharingCommands 換成 RegressionBaselineTests,整句仍然為真。「沒有 deadline 界住整個操作」正是 #91→#158→#165 三次復發的核心失敗模式,也是這份 PR 存在的理由。
N3 — SpawnSiteSweepTests 的字面比對可被至少 4 種常見寫法繞過
SpawnSiteSweepTests.swift:59 · Source: devils-advocate(實測 5 種寫法,4 種繞過並確認建構出真正的 Process)
繞過成功:Process ()(多一空格)、.init()(型別已知時的自然慣用寫法)、跨行 Process(\n)、typealias Proc = Process; Proc()。只有精確單行 Process() 會被抓。
這正是我請 DA 攻擊的那一點,它證實了。 更關鍵的是繞過後果 —— DA 另跑 ZZZProbe4(裸 Process() + 阻塞 waitUntilExit()、90 秒 stub、外包 .timeLimit(.minutes(1))):任務跑滿 90 秒才結束,同時觸發 time-limit 與手動斷言雙重失敗。再次證明 .timeLimit 攔不住阻塞 syscall。
合起來:這不是「理論上可規避的靜態檢查」,而是「常見寫法即可繞過,繞過後 CI 真的會照 #91/#158/#165 的老路無限期掛住,沒有任何 runtime 兜底」。這道字面比對是整條防線唯一的防護,而它經不起最普通的重構。
N4 — 豁免清單的正當性文字遺漏了它自己保留的最大風險,且錯引 #170
SpawnSiteSweepTests.swift:34-35 · Source: devils-advocate(含 reviewer 評級收斂論證)
我寫的豁免理由只交代「#158 形狀的 deadlock 已用 concurrent drain 修好」(已解決的次要風險),完全沒提該 site 仍然沒有任何 wall-clock timeout(保留的最大風險)。而 allowlist 自己的 doc comment 寫著「Adding an entry is a deliberate act; it should be rare and justified」—— 唯一一個 entry 的 justification 並沒有兌現這個要求。
且 #170 被錯引:同一份 diff 的 SubprocessRunner.swift:35-43 把 #170 定義為 descendant-kill / process-group 問題,與此處引用的 stdin 缺口語意不同。
DA 另指出四位審查者對同一件事給出 regression=HIGH / security=MEDIUM / requirements=LOW 的落差,落差本身即文字表述不清的證據,主張收斂至 HIGH。我同意。
MEDIUM(節選)
| # | Finding | Source |
|---|---|---|
| M1 | teardown() 在 cancellation 路徑可被兩條執行緒並發呼叫,無原子化 once-only 保護 |
security |
| M2 | terminate() 的 SIGKILL + bounded-reap 分支(B3 的修復目標)全 diff 零測試覆蓋 |
DA |
| M3 | SubprocessRunner.run 現為 public 通用 spawn 原語,executable / environment / currentDirectory 均無驗證 |
security |
| M4 | SubprocessRunner 宣告 public 而非 package,不必要擴大 library product 的 API surface |
DA |
| M5 | #170 在兩處新註解被引用於與其 canonical 定義不同的缺口 |
regression |
結論
不可 merge,但性質與 round 1 不同:round 1 的 7 項 blocking 全部確認真修好、經執行驗證,本輪 5 項 HIGH 是新的 —— 其中 N1 是我為修 B1 所選設計引入的、N2/N4 是我豁免時交代不完整、N3 是我請 DA 攻擊而被證實的弱點。
未打 idd-165-verified tag。
⚠️ 兩輪都是 5/6。round 1 缺 DA,本輪缺 Codex。完整六路尚未取得過一次,這點在採信任一輪結論時都應計入。
…#165) Round-2 verify: all 7 round-1 blocking findings confirmed genuinely fixed by execution, but 5 new HIGH — two of them mine. N1: the timeout branch read OutputBox on the line after teardown, with nothing joining the detached readers teardown had just unblocked. Unblocking is not finishing. Reviewers reproduced it at ~13% (2 of 15 runs returned a bare message with no output at all), which contradicted the guarantee written at the top of the same file. Fixed structurally: the timeout path now waits, boundedly, for bothDrained before reading. The accompanying test is a regression net, not the proof — at that rate five iterations still pass ~48% of the time with the bug present, and saying otherwise would overstate it. N3: the sweep guard matched one literal spelling and nothing else. Review proved four ordinary alternatives walk past it — a stray space, dot-init on a typed binding, a split line, a typealias — each confirmed to build a real NSConcreteTask. The dot-init form is the one that matters: it is idiomatic Swift where the type is known, so it needs no intent to evade. Widened to those forms plus NSTask and posix_spawn, and given a vacuity test, because a guard that cannot fail is worse than none. Widening immediately produced a false positive on a doc comment containing ordinary prose, so the scanner now strips comments before matching. That also removes the original reason for the self-exclusion; it stays only because the vacuity test embeds real spawn spellings as string literals. N2/N4: the one allowlisted site had fixed its ordering deadlock and kept an unbounded wait — swap the filename and round-1's B5 sentence still read true. It now has its own bounded wait with kill escalation. The justification was rewritten to name the risk it RETAINS rather than only the one it solved, and to stop citing #170's descendant-kill gap for a stdin gap (M5). M2: the SIGTERM to grace to SIGKILL path, which was B3's fix, had no coverage. It does now. One self-inflicted lesson: the new N1 test left eight grandchildren sleeping ten seconds each, and Swift Testing runs suites in parallel — my own test starved the machine and made three neighbouring timing assertions flaky. Lightened it and serialized the timing suite. 456 tests / 90 suites green.
Round 3's ensemble did not survive to report (all five legs errored), so this comes from measurements I ran myself against the probes its killed agents left behind. Two results. The N1 fix holds: 100 timeout trials with a 20k-line payload and a grandchild holding the pipe past the deadline produced 0 empty messages and 0 dropped markers, where round 2 measured 13% empty before `settleDrains`. And under concurrency the deadline does not hold at all. Measured on an 18-core M5 Max against a 1s budget, every call forced down the timeout path: concurrency 1 2 4 8 16 32 max elapsed 1.0s 1.0s 1.0s 1.0s 6.6s 18.6s Output was never truncated, so guarantee 5 held throughout — this is purely deadline hardness. But a wait that overruns its budget 18x is the same failure this PR exists to eliminate, in a fourth costume after #91, #158 and #165. The cause is that `Task.detached` runs on the cooperative pool, which has one thread per core, and `readDataToEndOfFile()` blocks the thread it lands on. Two blocking drains per run, and enough concurrent runs leaves no thread free to resume `raceCompletion`'s sleep continuation — so the code that enforces the deadline stops being scheduled. That falsifies guarantee 1 as it was written ("a drain that never returns cannot extend the deadline"). True of one drain, false of N: they could not extend it directly, but they could starve the executor enforcing it. Both the guarantee and the local comment are corrected rather than left to imply more than they deliver. Moving the drains to `DispatchQueue.global`, whose pool grows past a blocked worker, makes blocking cost a thread instead of the runtime. After: 1.0x at every concurrency from 1 to 32. The regression test deliberately runs above the core count, since the defect only appears once the blocking drains outnumber the pool. 457 tests / 91 suites green. Refs #165
Verify Report — #165 round 3 · 1 HIGH found, fixed (
|
| lens | 結果 |
|---|---|
| n1-race / sweep-bypass / deadline / open-mediums / DA | 5/5 全部 error |
失敗原因兩種:一個 connection closed mid-response,DA 撞 session limit。整份 result 只有 5 筆 did not complete 的 integrity 標記,零實質 finding。
我自己的 process 錯誤也要記:這輪第一次啟動時,三個 verify 共用同一個 checkout,而它停在 idd/164 分支——SubprocessRunner.swift 在那裡根本不存在。等於叫審查者去讀不存在的檔案。已停掉重跑於專屬 worktree,但那已經燒掉一輪額度。
所以下面的東西不是 ensemble 給的,是我在 worktree 裡自己跑出來的——用被砍掉的 agent 留在硬碟上的 probe(它們設計得很好,值得記一筆)。
✅ N1 確認修好
100 次 timeout trial,20000 行 payload、孫代 process 持有 pipe 超過 deadline:
RESULT: 0/100 empty, 0/100 missing marker
Round 2 在修 settleDrains 之前量到 13%(2/15)空輸出。0/100。
🔴 HIGH(新)—— deadline 在並發下完全失守
同一支 stub、每次都必然走 timeout 路徑、1 秒預算,掃 concurrency:
| concurrency | 1 | 2 | 4 | 8 | 16 | 32 |
|---|---|---|---|---|---|---|
| max elapsed | 1.0s | 1.0s | 1.0s | 1.0s | 6.6s | 18.6s |
18 核機器,knee 落在 8→16 之間,正好是核心數。
輸出從未被截斷(60 路並發全部拿到完整 2,840,000 bytes),所以 guarantee 5 沒破——這純粹是 deadline 硬度問題。但「等待超出預算 18 倍」正是這個 PR 存在的理由本身,是 #91 → #158 → #165 之後同一個 bug 的第四種形態。
根因:Task.detached 跑在 cooperative pool(每核一條 thread),而 readDataToEndOfFile() 會阻塞它落腳的那條 thread。每次 run 兩條阻塞 drain,並發一多,pool 就沒有 thread 能恢復 raceCompletion 的 sleep continuation——負責檢查 deadline 的那段程式碼本身排不進去。
這推翻了我寫在檔頭的 guarantee 1 原文:
They are detached and blocking; the box (not an
await) is how the deadline path reads them, so a drain that never returns cannot extend the deadline.
對一條 drain 成立,對 N 條不成立。它們不能直接延長 deadline,但可以餓死執行 deadline 的 executor。guarantee 與該處註解都已改寫,而不是留著讓它宣稱比實際更多。
修法:drain 改用 DispatchQueue.global——Dispatch 的 pool 會在 worker 阻塞時長出新 thread,所以阻塞的代價是一條 thread,不是整個 runtime。
修後重量同一組:
| concurrency | 1 | 2 | 4 | 8 | 16 | 32 |
|---|---|---|---|---|---|---|
| max elapsed | 1.0s | 1.0s | 1.0s | 1.0s | 1.0s | 1.0s |
regression test 刻意跑在核心數之上(max(24, cores+8)),因為這個缺陷只在阻塞 drain 數超過 pool 寬度時才現形。
457 tests / 91 suites 綠。
未取得的覆蓋(誠實記錄)
這輪沒有拿到:sweep guard 的第五種繞過嘗試、round-2 四個 MEDIUM(teardown() 無 once-only、SIGKILL 分支零覆蓋、run 參數無驗證、public vs package)的獨立判定、以及任何對抗性挑戰。這些仍然開著。
不可 merge。 未打 idd-165-verified tag——這輪的 diff 已因上述修正變動(2e7161e → d8dc6ec),且 ensemble 覆蓋為零,需要一輪真正跑完的 verify。
…pe-deadlock # Conflicts: # CHANGELOG.md
…guard covers
Round 4 found two CRITICALs. The first is mine, introduced by round 3's own
fix — the fourth consecutive round in this PR where the fix created the next
bug.
CRITICAL 1. The drains called `FileHandle.readDataToEndOfFile()`, an
Objective-C API that RAISES on a closed descriptor. An ObjC exception is not
catchable by Swift do/catch: it terminates the process. `teardown()` closes
those handles precisely to unblock the drains, so a drain that has been
submitted but has not started yet reads an already-closed handle, and the
moment GCD runs it the whole process dies.
Moving the drains to Dispatch in round 3 is what made this reachable. Under
`Task.detached`, cooperative-pool starvation delayed teardown roughly in step
with drain congestion, so the two moved together. Decoupling them — the entire
point of that fix — lets teardown run promptly while drains sit backlogged.
Reviewers reproduced a process abort in 2 of 4 runs at concurrency 1000, and
measured the GCD pool plateauing near 90 threads regardless of offered
concurrency, so it is backlog rather than raw fan-out that opens the window.
Verified directly: reading a closed handle with the legacy API aborts with
"uncaught exception of type NSException"; `readToEnd()` returns nil. The
drains now go through a helper that cannot raise, and two tests cover it —
including one that closes the handle under a drain parked in read(2), which is
the actual teardown interleaving. If this regresses it will not fail, it will
crash the test process, which is the point.
CRITICAL 2. The sweep guard was defeated three more ways, all compiled and run
against real child processes: `NSClassFromString("NSTask")`, a metatype
variable (`let Kind: Process.Type = Process.self`), and a generic factory. The
first was additionally confirmed to reproduce the deadlock itself — blocked
past an 8s outer timeout, exit 124.
These are not a fifth spelling. Round 2's four bypasses were one axis; this is
another: the guard matches a type NAME next to a construction and has no notion
of type FLOW, so one hop of indirection is invisible. The patterns are widened
to catch these spellings and the samples are in the non-vacuity test, but the
doc comment now says plainly that a token-adjacency regex cannot close type
indirection in general, and that against an author trying to get around it the
guard will lose. Its job is accidental reintroduction — which is how #91 →
#158 → #165 actually happened.
Also: the allowlist entry for RegressionBaselineTests claimed the site "now
carries its own bounded wait" while BOTH of its `waitUntilExit()` calls were
still unbounded — including the happy-path one, which is the likelier to bite,
because EOF on stdout means the child closed it, not that the child exited.
Both reaps are now bounded via a termination semaphore, and the justification
says what is true.
484 tests / 95 suites green.
Refs #165
Verify Report — #165 round 4 · 2 CRITICAL,已修(
|
| Frozen | 1acde4d(已併 origin/main)· freshness gate PASS |
| Ensemble | 4 lenses + DA — 3/5 完成、DA 完成(deadline 與 open-mediums error) |
| Findings | 15(2 CRITICAL / 2 HIGH + 2 process-gap / 4 MEDIUM / 2 LOW / 3 INFO) |
🔴 CRITICAL 1 — drain 讀到已關閉的 handle 會炸掉整個 process(round 3 的修法造成)
FileHandle.readDataToEndOfFile() 是 Objective-C API,對已關閉的 fd raise NSFileHandleOperationException。ObjC exception 無法被 Swift do/catch 攔截 —— 它直接終結 process。
而 teardown() 關掉那兩個 handle 的目的正是要解除 drain 的阻塞。所以:已提交但尚未啟動的 drain closure,等 GCD 排到它時讀到的是已關閉的 handle → 整個 process 死。
我自己直接驗證:
closed; now reading with the legacy API…
libc++abi: terminating due to uncaught exception of type NSException
--- 換成 readToEnd() ---
throwing API survived; bytes=-1
是 round 3 把 drain 搬到 Dispatch 讓這條路變得可達的。 舊的 Task.detached 設計下,cooperative pool 被餓死會讓 teardown 跟 drain 積壓同步延遲,兩者一起慢;把它們解耦(那正是 round 3 修法的全部目的)之後,teardown 準時跑完,drain 卻還堵在佇列裡。reviewer 在 concurrency 1000 下 4 次跑出 2 次 crash,並量到 GCD pool 不論 offered concurrency 多少都停在約 90 條 thread —— 所以開窗的是積壓而不是 fan-out 本身。
這是這個 PR 連續第四輪「修法引入下一個 bug」:round 1 只綁 child → round 2 修它引入 N1 → round 3 修 N1 又撞上並發塌陷 → round 3 修並發塌陷引入這個。
修法:drain 走一個不會 raise 的 helper(readToEnd())。兩個新測試,其中一個在 drain 正卡在 read(2) 時關掉 handle —— 那才是真正的 teardown 交錯。這個測試若回歸不會 fail,會 crash 掉測試 process,這正是重點。
🔴 CRITICAL 2 — sweep guard 被再破三種,而且是不同的軸
三種都經 reviewer 編譯並對真實子行程跑過:
let cls = NSClassFromString("NSTask") as? NSObject.Type // 動態查找
let Kind: Process.Type = Process.self; Kind.init() // metatype 變數
func spawn<T: NSObject>(_ t: T.Type) -> T { T.init() } // generic factory第一種還被確認真的重現了 deadlock(>64KB 無人 drain + waitUntilExit(),在外層 timeout 8 下 exit 124)。
reviewer 的判斷我完全接受,而且這比 finding 本身更重要:這不是第五種拼法。round 2 的四種是「同一個拼法的四個實例」;這三種是另一個軸 —— guard 比對的是型別名稱與建構式相鄰,它沒有型別流的概念,所以任何一跳間接都看不見。加第六條 regex 不會關掉這個類別。
所以我做兩件事而不是一件:patterns 加寬到能抓這三種拼法(提高意外引入的成本),同時把 doc comment 改成誠實陳述天花板 —— 明寫 token-adjacency regex 無法在一般情況下關閉型別間接,面對刻意規避的作者它會輸,它的職責是意外重新引入,而 #91 → #158 → #165 正是意外。
MEDIUM — allowlist 的正當性文字宣稱了不存在的「bounded wait」
RegressionBaselineTests 的 allowlist 說「the site now carries its own bounded wait」,但兩個 waitUntilExit() 都還是無界的,包含 happy path 那個 —— 而 reviewer 指出 happy path 反而更可能中招:stdout EOF 只代表子行程關了 stdout,不代表它退出了。
兩個 reap 都改成經 termination semaphore 的有界等待,justification 改成事實。
⚠️ 未取得的覆蓋
deadline 與 open-mediums 兩條 lens error。所以這輪沒有獨立驗證 round 3 的並發修法在各路徑上的 deadline 硬度,也沒有判定那四個仍開著的 MEDIUM(teardown() 無 once-only、SIGKILL 分支測試、run 參數驗證、public vs package)—— 其中 teardown() 無 once-only 這輪由 dispatch-risk lens 另外確認「在 cancellation 路徑上確實被呼叫兩次」,仍未修。
484 tests / 95 suites 綠。未打 tag、不可 merge:diff 已再次變動(1acde4d → e020180),且兩條 lens 缺席。以「連續四輪都在前一輪的修法裡找到新洞」的紀錄來說,我不打算在自己剛改完的 diff 上宣告收工。
… suite CI has been red on this branch since round 2 and no verify round noticed, because every round ran `swift test` locally, where it passes. Three reports said "N tests green" and meant it — locally. Two distinct causes, both visible in one CI log where every test reports "passed after 372 seconds" and the process then exits with signal 6. 1. The abort. RegressionBaselineTests still drained with `readDataToEndOfFile()`, the raising Objective-C API. Its timeout path closes that handle to unblock the drain, and reading a closed descriptor with that API raises an exception Swift cannot catch — it terminates the process. This is the same defect as the round-4 CRITICAL in SubprocessRunner, in the one site the sweep exempts, and I fixed only the runner. It now uses the same non-raising helper. 2. The stall. SubprocessConcurrencyTests spawned a fixed 24 children at once, each producing 400 KB with a grandchild holding the pipe. That is ~1.3x the cores on this machine and ~8x on a CI runner, where it starved every sibling suite for minutes. Scaled to twice the core count, which still exceeds the pool everywhere — which is all the test needs to detect the starvation it was written for. Refs #165
The drain fix stopped the abort — CI no longer dies with signal 6 — but the nine RegressionBaselineTests still blew their 120s budgets. Each spawns baseline-compare.py and then blocks a thread in `group.wait()`. Swift Testing runs all nine in parallel, and that wait blocks a COOPERATIVE POOL thread, so on a 3-core runner they exhaust the pool, starve every other suite, and time themselves out. The log signature was every test in the run — including passing ones — reporting the same ~372s duration. That is the same shape as the product bug this PR fixes: blocking work on the pool that also has to run the code enforcing the deadline. Here it is in the test harness, so the proportionate fix is to stop running nine of them at once. Refs #165
…ck number The concurrency test asserted an absolute bound (worst < 3x the 1s budget). That passed on an idle 18-core dev box and failed on a loaded 3-core CI runner at 4.2x — which measures the machine, not the code. It now takes a single-call baseline in the same run and asserts the high-concurrency worst is under 3x of it, which is the property actually under test: the deadline must not DEGRADE as concurrency rises. Confirmed non-vacuous by temporarily restoring the pre-fix Task.detached drains: ratio 12.4x (solo 1.02s, loaded 12.60s at concurrency 24), failing as intended. With the Dispatch drains it is ~1.0x. Refs #165
… return normally CI caught a guarantee-4 violation that no local run ever hit. `withTaskCancellationHandler`'s `onCancel` runs `teardown()`, which terminates the child and closes both read ends. That makes the runner's completion condition — process exited AND both drains finished — TRUE. The poll loop checked completion before it could observe the cancellation, so a cancelled call returned normally with a status instead of throwing CancellationError. "Cancellation is honoured, not swallowed" is the guarantee this file makes, and it was the round-1 blocker B2; this was the same defect re-entering through the teardown path. It surfaces only when resumption is delayed enough to land past the sleep, which is why a loaded 3-core CI runner found it and an idle 18-core box did not. `raceCompletion` now calls `Task.checkCancellation()` first, so cancellation wins deterministically rather than racing teardown. The accompanying test samples cancel offsets straddling the 20ms poll interval instead of one fixed 300ms delay. Stated in the test itself: it does NOT reproduce the bug on a fast idle machine — removing the guard leaves it green locally — so the explicit check is what makes this correct, not the test. Refs #165
… the code Both failed on a 3-core CI runner and pass on an idle 18-core box, which means they were measuring the machine. The deadline test used a 6s grandchild and asserted "< 5s". The two outcomes it has to tell apart — bounded-but-slow, and waited-for-the-grandchild — were one second apart, and CI reported exactly 6.0s, which is indistinguishable. The deadline is enforced by a poll loop on the cooperative pool, so under contention it fires late; that is a real property, not a defect. The grandchild now sleeps 30s and the bound is 15s, so a genuine regression is unmistakable and ordinary slowness is not. The MCP gate test slept a fixed 300ms to "let the async jobs drain" and then asserted three completions. That is a race dressed as a wait; on CI it read 2. It now polls to a 10s deadline, asserting the same thing without assuming a machine speed. Refs #165
Refs #165
Summary
WhisperCppEngine把 stdout 接到從未被讀取的匿名Pipe(),又用無 timeout 的waitUntilExit()等待。輸出超過 Darwin 64 KB pipe buffer 後 child 阻塞在write(2),parent 永遠等不到 exit —— 約 63 分鐘以上的音檔必中,且失敗完全靜默。修法不需要發明:
ExternalProcessEngine早在 #91 就有正確寫法,只是沒擴散。本 PR 把它抽成SubprocessRunner,讓正確寫法成為唯一寫法。改了什麼
SubprocessRunner— 並行 drain +ExitLatch+ SIGTERM→SIGKILL deadline + 逾時關 read endWhisperCppEngine改用之;timeout 由AudioProber量到的音訊長度推導(max(600, 2× duration)),非固定常數ExternalProcessEngine的重複實作收斂為薄 aliasToolRunner(SharingCommands.swift) — family-wide sweep 找到的第三個 site:序列讀兩條 pipe,stderr 滿溢即 deadlock。與 subprocess 測試的 sequential pipe read 會在夠大的 payload 上掛住 CI 而非讓它失敗(seam 之後從 1 處變 3 處) #158 同形但在 production CLI。改為並行 drain驗證
STAT=SN,awk阻塞在write(2)附帶發現
Swift Testing 的
.timeLimit無法中斷阻塞在同步 syscall 的測試(掛了 1 分鐘上限,實際跑 12m29s 未被中斷)。所以迴歸測試不能當 CI 安全網 —— 有界性只能靠 production 端的 deadline。這說明 drain 與 timeout 缺一不可。Checklist
Generated by /idd-implement on PR path. Do NOT add a GitHub close trailer — IDD discipline requires manual /idd-close after merge.