[趣味競賽 進階 #10] 0xc0000409:當我的 AI 服務靜默暴斃,而 log 把死因吃掉了

白話導讀:會自我重啟的服務,最會掩埋自己的死因

這篇講的是一個很反直覺、但你只要跑過任何「會自動重啟」的常駐服務遲早會踩到的坑:服務自己把自己的死因掩埋了。

症狀很無辜:我家那台常駐 AI 腦偶爾會「咦,剛剛卡了一下」——client 那頭吃到一次 503,幾秒後又正常。我去翻服務自己的 log 想看它為什麼死,結果一片空白,只有乾乾淨淨的啟動訊息,彷彿什麼都沒發生過。

問題就出在「彷彿什麼都沒發生過」這件事上。服務設定成 crash 後自動重啟,而且它把錯誤輸出寫進一個固定的檔案——重啟那一瞬間,這個檔案被截斷覆寫,crash 當下印出的最後幾行(也就是死因)就跟著被洗掉了。等我去看,看到的永遠是「重啟後的乾淨開頭」,而不是「死前的最後遺言」。

所以這篇的兩個重點:一、死因要先往 OS 層找,別只盯著應用程式自己的 log;二、log 保留策略比 log 本身重要——一個會吃掉自己死因的 log,等於沒有 log。

---

設定:一台 headless 老桌機上的常駐腦

接續這個系列前面幾篇:一張二手改裝的 22G RTX 2080 Ti當 agent 腦,裝在一台只有 16GB RAM、六核 CPU 的廉價老桌機上(沒有螢幕,純 headless,我都是從別台機器遠端進去看)。上面用 llama.cpp serve 一顆 abliterated 的 Qwen3.6-27B Q4_K 當常駐腦,context 開 128K(這個 128K 是有故事的,見上一個硬核篇),由一個 Windows 開機自動啟動的常駐服務看著,死了就自己重啟。

關鍵字是 headless + 自動重啟。這兩件事合起來,就是這篇 bug 的溫床:沒有螢幕,所以不會有人當場看到崩潰對話框;自動重啟,所以崩潰後幾秒它又活著,你甚至不會注意到它死過——除非你剛好在那一瞬間打了一句話,吃到那個 503。

第一個錯:我盯著被截斷的 stderr 找了半天

事情是這樣開始的:某次我重新載入這顆腦、餵進去一段比較長的真實對話(input 大約 54K tokens)之後,client 吃到 503。我心想「喔,大概又是 context 相關的東西爆了」(這個系列前面講過 256K 開太滿會 OOM),於是直覺地去翻服務的 stderr log,想找那行該死的錯誤。

結果——什麼都沒有。

log 裡只有服務重新啟動的訊息,乾乾淨淨,沒有 CUDA OOM、沒有 ggml 的 alloc 失敗、沒有 stack trace,什麼都沒有。我一度懷疑「是不是根本沒 crash,只是某次請求 timeout 而已?」(這個系列也講過,這顆腦在過載時更常見的失敗模式是 timeout 排隊飢餓、不是真崩潰)。

但 503 是真的、服務重啟也是真的。一個明明重啟過的服務,log 卻顯示它從沒死過——這本身就是線索。 它在告訴我:不是「沒有死因」,是「死因被吃掉了」。

揪出真兇(之一):log 被自己的重啟截斷

回頭看服務的設定,我才意識到問題:它把 stderr 重導到一個固定的 log 檔(-RedirectStandardError)。Windows 上這個重導的預設行為,是每次(重)啟動時截斷那個檔案——也就是用空檔案覆寫掉舊內容。

把時間軸攤開就清楚了:

T+0.0s   腦在處理一段 ~54K 的重新載入
T+0.1s   內部某條 fail-fast 路徑觸發 → abort → 行程死掉
         (若此刻 stderr 印出了死因那幾行 —— 它的壽命只有 0.1 秒)
T+0.2s   常駐服務偵測到行程沒了 → 啟動新行程
T+0.2s   新行程開 stderr log → 截斷舊檔 → 上一刻的內容被空檔案覆寫
T+...    我打開 log → 只看得到「乾淨的重新啟動」

就算死因有被印出來,它的壽命也只有 0.1 秒,然後就被它自己的重啟覆寫掉了。(誠實標:我沒能保住那行,所以「它一定有被印出來」這件事我無法證實——但這套設定本身就讓 stderr 不可靠,這才是要修的。)我盯著的那個「空白 log」,不是因為沒有死因,是因為我永遠晚一步——我看到的永遠是重啟後的版本。

這就是「會自我重啟的服務最會掩埋自己的死因」的具體機制。重啟讓服務有韌性(client 只吃到一次 503 就恢復),但同一個重啟也把每一次崩潰的證物銷毀了。韌性與可觀測性在這裡是對立的,而預設設定選了韌性、犧牲了可觀測性。

揪出真兇(之二):轉去 OS 層,Event Log 才是第一現場

既然應用程式自己的 log 靠不住,我換個樓層找:OS 層的崩潰回報。

Windows 的事件檢視器(Event Viewer)→ Windows 紀錄 → 應用程式,有一組你在這種「行程靜默暴斃」的情境下一定要先看的事件:

• Event ID 1000(Application Error):OS 偵測到某個行程崩潰時記的。會列出 faulting application(哪個 exe 死了)、faulting module(死在哪個模組裡)、以及 exception code。
• Event ID 1001(Windows Error Reporting):WER 的對應紀錄。

關鍵差別:OS 層的崩潰回報不歸你的應用程式管,所以它不會被你那個會自我截斷的 log 影響。 你的 stderr 可以被覆寫一千次,Event Viewer 裡那筆 1000 還是好端端地躺在那裡。當應用 log 一片空白時,它是最可靠的第一現場。

而我在那裡看到的東西是:

• exception code = 0xc0000409
• faulting module = ucrtbase(Universal C Runtime)

兩條合起來,案情指向「不是顯示卡跳 OOM,是程式自己在 C runtime 層 abort 了」。

0xc0000409 到底是什麼:一個 fail-fast abort,不是 OOM

這串碼值得單獨解釋一下,因為它很容易誤導人。

0xc0000409 的官方名稱是 STATUS_STACK_BUFFER_OVERRUN。光看名字你會以為是「堆疊緩衝區溢位」這種記憶體安全攻擊,但實務上,現代 C runtime(ucrtbase)把它當成一個通用的 fail-fast abort code 在用——當程式內部偵測到某個「不該發生、發生了就不能繼續」的狀態時,它會走 fail-fast 路徑,主動 abort 自己,丟出這串碼。

所以在 llama.cpp 這種原生 C++ 程式上,0xc0000409 + ucrtbase 這個組合,常見的候選對應有:

• 一個 GGML_ASSERT / assert 失敗(程式自己檢查到不變式被破壞,走 abort()),或
• 一個沒被 try/catch 接住的例外,一路冒到 runtime 頂層,觸發 fail-fast。

(哪一條才是我這次的死因,在我搶救到那行訊息之前都還只是候選,不是定論。)

這串碼本身證明的是 fail-fast,不是 CUDA OOM——顯示卡記憶體不夠時,你會看到 CUDA 自己的錯誤訊息或 ggml 的 alloc 失敗,0xc0000409 不是 CUDA 的 OOM code。但要講精確:這只排除了「Windows 直接把它記成 OOM」,沒排除「VRAM/記憶體壓力是上游觸發點、最後在 C runtime 層 abort」這條可能——而那行能分辨兩者的 stderr,正是被吃掉的證物。所以我前面那個「大概是 context 爆了」的直覺其實沒被推翻,只是降成「待證的上游假設」:我預期看到 OOM,結果看到的是 abort,兩者是不同層的訊號。

⚠️ 講清楚我確定什麼、不確定什麼:我能 100% 確定的,是「fail-fast abort(0xc0000409 via ucrtbase)+ 服務自動重啟」這個外在事實。 「它對應的是 GGML_ASSERT 還是未捕捉例外」——這一層是我的推測,因為我還沒在重啟前搶救到那行真正的 ggml/assert 訊息。下面的緩解措施,正是為了下次能搶到它。

雙重緩解:先讓 log 別吃掉死因,再壓掉疑似觸發點

知道「死因被自己的重啟覆寫」之後,修法分兩半。

第一半:讓 log 別再吃掉死因。 改掉那個「重啟即截斷」的行為——在每次(重)啟動之前,先把舊的 stderr 檔改名保存(加一個帶時間戳的後綴),而不是讓新行程直接覆寫它。再保留最近若干份(我留了 15 份),這樣下次崩潰時,死前那幾行就會凍結在改名後的檔案裡,不會被下一次重啟洗掉。另外讓常駐服務本身把「我在 X 時間重啟了 Y」這種事件寫進一個獨立的事件 log,跟應用程式的 stderr 分開——這樣即使應用那邊真的什麼都沒留下,我至少有一條重啟的時間軸可以對。

這一半是真正的修——它不修崩潰,但它修「我看不見崩潰」。對一個間歇性、難重現的 bug,『能不能在它發生時抓到證據』比『現在就猜出原因』重要得多。

第二半:壓掉最可能的觸發點(緩解,非根治)。 既然假設指向「hybrid 模型的 recurrent checkpoint / 某條長 context 的 runtime 壓力路徑」,我順手把 context checkpoint 的數量上限調低(--ctx-checkpoints,從預設值降下來),減少 checkpoint 池的整體壓力。這跟上一個硬核篇講 256K OOM 是同一條長 context 壓力家族的問題——checkpoint 會隨對話長大,而這顆 hybrid 腦的 checkpoint 又特別大又特別愛失效。把上限壓低,等於替 runtime 多留一點餘裕。

⚠️ 一個我得當場修正的細節:我之前(包括 256K 那篇)把 context checkpoint 講成「VRAM-resident」,但去翻目前 llama.cpp server 的原始碼後,這個講法太武斷、而且跟版本/路徑有關——目前 mainline server 的 checkpoint/prompt-cache 位元組是存在 host 端的記憶體(std::vector<uint8_t>,用 --cache-ram 控預算,save 走 PARTIAL_ONLY 而非 ON_DEVICE)。所以「降 --ctx-checkpoints 會直接壓掉一個 VRAM 尖峰」這句話,我沒有在這張卡上確認。比較誠實的說法是:它降的是 checkpoint 快取的整體壓力,而「壓力最後是怎麼變成那次 abort 的」——VRAM 還是 host 記憶體還是別的——仍是待證假設。

但我必須誠實標清楚:第二半是「照假設先做的緩解」,不是「已驗證的根治」。 我不能宣稱「降了 checkpoint 上限之後就不 crash 了」——因為這個 bug 偶發、難重現,我也還沒等到「降了之後跑夠久、確認真的不再犯」的那個時間點。它只是把一個合理嫌犯的活動空間壓小。

還在查:128K 把它壓成「偶發一次」,但沒治好

把這篇接回上一個硬核篇的誠實轉折:當初開 256K 是每隔幾輪必爆;退回 128K + 上面這套緩解之後,它變成偶發一次、且自動恢復。差別很大——對一個常駐 agent 來說,「偶發一次 + 自動重啟 + client retry 就回來」是可以接受的營運狀態;「每隔幾輪必爆」不是。

但「壓成偶發一次」≠「治好」。我在 128K 下仍觀察到那次真實負載(input ~54K)的 0xc0000409,而緩解上線後抓到的,還是只有兩條乾淨的重啟時間戳——還沒等到「下一次崩潰、且這次 log 成功保住死因」的那一刻。換句話說:緩解措施已經架好了陷阱,但獵物還沒再出現。

所以這篇老老實實是一篇還在查的紀錄:

• ✅ 已確認:fail-fast abort(0xc0000409 via ucrtbase)、服務自動重啟、應用 log 因截斷而空白、OS Event Log 才是第一現場。
• ✅ 已上線的緩解:crash-log 保留(改名而非覆寫)、獨立事件 log、壓低 --ctx-checkpoints 上限。
• 🔎 待最終確認:那行真正的 ggml/assert 訊息;checkpoint 壓力到底是在哪一層(VRAM / host 記憶體)變成 abort;以及「降 checkpoint 上限」到底是不是有效的根治。等下次重現、且這次 log 把死因留住,我會回來更新這篇。

我寧可把這篇寫成「我架好了抓死因的陷阱,但還沒抓到」,也不想把一個沒確認的根因講得像結案。誠實是這個系列的底線。

可轉移的判斷法則

把這篇濃縮成幾條可以帶走、套到任何「會自動重啟的常駐服務」的法則:

• 行程靜默暴斃 + 應用 log 空白 → 先看 OS 層。 Windows 看 Event Viewer 應用程式 Event 1000/1001(拿 faulting module + exception code);Linux 看 dmesg / journalctl / coredump。OS 層的崩潰回報不被你的應用 log 策略影響,是最可靠的第一現場。
• 會自我重啟的服務最會掩埋自己的死因。 重啟給你韌性,卻同時銷毀證物。重啟前先保存(改名)舊的錯誤輸出,別讓它被截斷覆寫——log 保留策略比 log 本身重要。
• 0xc0000409 + ucrtbase = fail-fast abort,不是 OOM。 別被 STATUS_STACK_BUFFER_OVERRUN 這名字騙去查記憶體攻擊,現代 C runtime 拿它當通用 abort code;在原生程式上多半是 assert 失敗或未捕捉例外。記憶體不夠你會看到的是 CUDA/ggml 自己的訊息。
• 間歇 bug:先修『看不見』,再修『原因』。 對難重現的崩潰,「能在它發生時抓到證據」的價值,遠高於「現在就猜一個原因」。先架好觀測陷阱,讓下一次崩潰替你說話。

接下來

這篇是這個系列的 infra 副線——同一台 headless 老桌機上的維運真相。它跟256K OOM 那篇是同一條長 context 壓力家族的兩個切面:那篇問「為什麼開滿 256K 會死」(那邊量到的 free VRAM 一路掉到 170 MiB 是真的),這篇問「死了之後,死因為什麼找不到」。而「為什麼這顆 hybrid 腦一 miss checkpoint 就整段重算、TTFT 飆到分鐘級」,則在那篇 TTFT 硬核篇裡。

如果這篇有一句話想留給你:自己會重啟的服務,最會掩埋自己的死因——所以 log 保留策略,比 log 本身重要。

---

同系列其他篇:

• 256K crash 偵探:free-VRAM 對 context 非線性、為什麼 128K 才是甜蜜點(同一條長 context 壓力家族;那篇也提到這次的 0xc0000409)
• 為什麼 30 tok/s 體感比 14 還慢:checkpoint miss、full reprocess 與 TTFT(同一顆 hybrid 腦的另一個切面)
• 系列開篇:NT$11k 改裝卡養一顆 27B agent(這顆腦怎麼來的)

---