メモリ99.8%の障害を調べたら、犯人が証拠に写っていなかった —— Zabbix + LLMの障害調査を実際にやってみた記録
深夜1時16分、Zabbixからメールが届きました。
ホスト: Japan-RTX3090-2a
障害: Linux: High memory utilization (>90% for 5m)
重要度: Average
朝、復旧を確認したうえで調査に入りました。結論から言うと、障害の直接原因は特定できませんでした。理由は、自分で作った証拠収集の仕組みに欠陥があり、肝心の犯人プロセスが記録に残っていなかったからです。
この記事は、その調査と対処、そして「原因が分からなかったこと」から得た考察の記録です。
何が起きていたか
Zabbix APIからメモリ使用率の履歴を引くと、状況は明快でした。
00:40〜01:05 70〜73% (平常)
01:06〜01:10 73% → 96% (10分で約19GB増加)
01:16:26 99.8% ★発報
01:24:47 98.2% → 56.4%(約27GBが一括で解放)
以降 56〜61% (事前より約8.5GB低い)
同時刻の状態はこうでした。
- Load Average 248(CPU 20コアの機体)
- CPU時間の87%がシステム時間(ユーザー処理は1.2%)
- PSI(Pressure Stall Information)の memory full avg10 = 88.7%
- スワップ 0
CPUが計算に使われていない。システム時間ばかり。これは典型的なスラッシングです。物理メモリが尽きたとき、Linuxはページキャッシュを捨てて凌ごうとしますが、スワップが無いと逃げ場がありません。捨てては読み直し、を延々と繰り返し、その管理コストでCPUが埋まる。
面白い(そして厄介な)のは、監視エージェント自身も窒息していたことです。Zabbix Agent 2 のログにこう残っていました。
plugin 'Cpu': time spent in collector task 18.892164 s exceeds collecting interval 1 s
cannot connect to [192.168.0.2:18200]: i/o timeout
1秒間隔で集めるはずの処理に18.9秒かかっている。障害を観測すべき側が、障害に巻き込まれて観測できなくなる。さらに snapd が同じ01:16:26にSIGABRT(systemdのウォッチドッグによる強制終了)を食らっていました。応答できなかったからです。
証拠が無かった
kzabbixには、障害検知時に対象ホストの状態スナップショットを撮る仕組みを入れてありました。今回もちゃんと3枚撮れていました。中身を開いて、愕然としました。
2804636 795562 ollama Ss postgres 0.0 0.0
2806248 795562 ollama Ss postgres 0.0 0.0
2806249 795562 ollama Ss postgres 0.0 0.0
(以下、kworkerとpostgresが延々)
メモリを食っているプロセスが1つも写っていません。原因は2つありました。
欠陥1:CPU順でしか取っていなかった
run(["ps", "-eo", "pid,ppid,user,stat,comm,%cpu,%mem", "--sort=-%cpu"], limit=6000)
--sort=-%cpu。メモリ障害なのにCPU順です。メモリを大量に確保して静かに座っているプロセスは、この一覧の上位に来ません。
欠陥2:切り詰めが逆向きだった
こちらの方が悪質でした。共通のヘルパー関数がこうなっていました。
return redact(output[-limit:])
output[-limit:] ——末尾を残す切り詰めです。ログの尻尾を見るには正しい実装ですが、ps の出力に適用するとソートして並べた上位が丸ごと消えます。さらに保存直前にもう一度 [:3000] で切っており、こちらは先頭を残す向き。方向が食い違ったまま二重に切っていました。
結果として残ったのは「末尾3000文字の、さらに先頭」——つまりリストの真ん中あたりにいるkworkerの群れでした。
証拠を撮っているつもりで、撮れていなかった。しかもそれに気づけるのは、実際に障害が起きて中身を開いたときだけです。
対処したこと
1. 証拠収集を作り直した(本命)
CPU順とメモリ順を別々に上位20件ずつ。psの側で head を通してから受け取り、切り詰めの向きに依存しないようにしました。
raw = run([
"bash", "-lc",
"ps -eo pid,ppid,user,stat,rss,%cpu,%mem,comm,args "
f"--sort={sort_key} | head -n {rows + 1}",
], limit=40000)
文字列ではなく dictの配列にして、サイズ削減が必要なときは文字数ではなく件数で削るようにしました。文字数で削ると、また同じ事故が起きます。
comm も見直しました。コマンド名は15文字までしか出ないので、python3 が3つ並んだら区別できません。args(コマンドライン全体)も採取し、秘密情報のマスクを通したうえで160文字まで保持するようにしました。
配布して即座に効果が出ました。
rss=21.04GB mem=32.0% uvicorn /home/kojima/venv311/bin/python3.11 ... --port 8091
rss= 8.39GB mem=12.7% llama-server /usr/local/lib/ollama/llama-server --model /usr/share/o
21GBを常時占有しているプロセスが即座に見えました。改善前は、これが一切写っていませんでした。
2. スワップを入れた
このホストはスワップがゼロでした。「メモリは潤沢だから不要」という判断だったのでしょうが、スワップ0は「性能が落ちない」ではなく「逃げ場がない」という意味です。実際、ページキャッシュを削り切った先で即スラッシングに入りました。
8GB、vm.swappiness=10(普段は使わず、逼迫時だけ退避)で設定しました。これは性能のためではなく、同じことが起きたときに「遅くなる」で済ませ、「固まる」まで行かせないための保険です。
3. 常駐していた無駄を削った
新しい証拠収集が見せてくれた顔ぶれを、片端から確認しました。
| 対象 | 状態 | 対処 |
|---|---|---|
| 動画生成API(21GB常駐) | 36日間稼働・27日間ジョブ実行なし | 停止(約20GB回収) |
| 未使用の26Bモデル(18GB) | 4か月更新なし・参照元なし | 削除 |
| あるマイナーの常駐サービス | 実体削除済みなのに10秒ごとに再起動を繰り返す残骸 | 停止(30分で202回のループが消滅) |
結果、メモリ使用率61% → 29%、Load Average は 248 → 0.6 になりました。
4. ついでに見つかった地雷
調査中、別のコードにこんな行を見つけました。
ollama_model = os.environ.get('OLLAMA_MODEL', 'gemma4:26b')
環境変数が読めなかったときの既定値が18GBのモデル。.env の読み込みに失敗した起動が一度でもあれば、18GBのロードが走ります。スワップ無しの機体では、それだけで今回と同じ状態になります。既定値を常用の12Bモデルに下げました。
障害を調べに行って、まだ発火していない同種の地雷を見つける。これは調査の副産物として、かなり価値がありました。
考察:AIに調べさせる前に、証拠を撮れているか
kzabbixは、障害イベントをLLM(ローカルのGemma 4)に投げて調査レポートを書かせる仕組みです。今回もレポートは生成され、内容自体は妥当でした。
原因候補と確度
- メモリリークまたは急激なメモリ消費を伴うプロセス実行 (確度: 高)
- I/O待ちによるシステムハング (確度: 中)
読める日本語で、筋も通っています。でも、犯人の名前はどこにも書かれていません。書けるはずがない。証拠に写っていないのだから。
ここが今回いちばんの学びでした。LLMは、渡された証拠以上のことは言えません。そして厄介なのは、証拠が欠けていてもそれらしいレポートが出てしまうことです。「メモリを大量消費するプロセスがあった可能性が高い」——正しいけれど、何も特定していない。読み手が注意深くないと、「調査済み」と錯覚します。
AIを監視や運用に組み込むとき、投資すべきは推論の側ではなく証拠収集の側だと痛感しました。プロンプトをどれだけ工夫しても、--sort=-%cpu は直りません。
同じことは、以前 x402決済の入金検証を作ったときにも考えました。ブラウザの「支払いました」という自己申告を信じず、決済事業者に問い合わせて突き合わせる。自己申告ではなく観測を根拠にするという点で、構造は同じです。先日読んだ trycompai/crm が「確信度スコアを一切受け取らず、観測した事実だけを報告させる」設計にしていたのも、同じ問題意識でしょう。
考察:直らなかったものについて正直に書く
障害の直接原因は、いまも分かっていません。
分かったのは「犯人でないもの」までです。
- Ollama:違う — 該当時間帯にモデルの再ロードは無く、12〜14秒の定常応答を続けていた
- snapd:被害者 — SIGABRTはシステム硬直によるウォッチドッグ強制終了
- 動画生成API:違う — 27日間ジョブ実行なし
- 周期性なし — 30時間の履歴で90%超はこの1回だけ(平均72.6%)
証拠が失われている以上、これ以上は遡れません。ここで「たぶんこれが原因だった」と書いてしまうのは簡単ですが、それは調査ではなく作文です。
代わりにできるのは、次に起きたときに分かるようにしておくことです。今回の対処は、そのほとんどが「再発防止」ではなく「再発したときに特定できるようにする」ためのものでした。
- 証拠収集の改善 → 次は犯人がargs付きで記録される
- スワップ → 固まらず、調査する余裕が残る
- 常駐の削減 → 平常時の余裕が28GB増え、同じ増加量では発報に至らない
原因不明のまま終わった障害でも、「次は分かる」状態にできれば前進です。むしろ、証拠収集の欠陥を見つけられたことの方が、単発の原因を特定するより長期的な価値があったと思っています。
おまけ:調査経路そのものが資産になる
今回、調査の入口で15分ほど無駄にしました。Zabbixのホスト名(Japan-RTX3090-2a)が実機のIPと結びついておらず、どのマシンの話なのか分からなかったからです。
最終的に、Zabbixサーバーから各エージェントに system.hostname を直接聞いて対応表を作りました。
s = socket.create_connection((ip, 10050), timeout=3)
p = b"system.hostname"
s.sendall(b"ZBXD\x01" + struct.pack("<Q", len(p)) + p)
こういう「調べ方」は、障害のたびに再発明しがちです。ホスト名とIPの対応、APIの場所、認証情報のありか、SSHの鍵と踏み台の経路——次に3分で入れるように書き留めておくだけで、障害対応の速度が変わります。
ちなみに今回、SSHで小さな回り道もしました。鍵を登録したのに Server accepts key の直後に拒否される。権限を疑って調べたら全て正常で、auth.log の Connection closed by authenticating user ... [preauth] が答えでした。サーバーは鍵を受理し署名を要求したが、クライアントが応答できなかった——つまり秘密鍵にパスフレーズが掛かっていて、自動実行では署名できなかったのです。権限問題(bad ownership or modes)とはログの出方が違う。この見分け方も、書き留めておく価値のある知識でした。
まとめ
- 監視は「検知」だけでは足りない。検知した瞬間に正しい証拠を撮れているかが本番
- 証拠収集のコードは、実際に障害が起きるまで壊れていても気づけない。定期的に中身を開いて確認する
- LLMは渡された証拠以上のことを言えない。それでも、それらしいレポートは出てしまう
- 原因不明で終わることはある。そのときは「次は分かる」状態にすることを成果とする
深夜のメール1通から、20GBの無駄と、まだ発火していない地雷1つと、証拠収集の重大な欠陥が見つかりました。障害は、システムの健康診断としては優秀です。