この記事は、前の記録の「回答編」です
前の記録（毎朝動いているはずのAI自動化41本を5.3日ぶん数えたら、最大91%が発火すらしていなかった）で、当社は一つ宿題を残しました。「メディア系ジョブは15分（900秒）で強制終了する設定のはずなのに、51分完走した記録がある。機序は未解明」——分かった気になって書くより、分からないと書いたところです。
その謎の一つの答えが、履歴の中から出てきました。結論から言います。タイムアウトは、記録の上では効いていました。しかし、実際のプロセスは死んでいませんでした。 エラー名が「timeout 900s」なのに、実測では139分間ぶら下がっていた記録が残っています。15分で止めたことになっているだけで、止まっていなかったのです。
用語を3つだけ
- タイムアウト … 処理に制限時間を掛け、超えたら強制終了させる仕組みです。当社の自動化基盤は、各ジョブを子プロセスとして起動し、Pythonのsubprocessにtimeout=900秒（15分）を掛けています。超えたら記録上は status=error・error="timeout 900s" と残る設計です。
- 子プロセスと孫プロセス … ジョブとして起動したプログラムが「子」。その子がさらに起動する重い処理（AIのCLIやブラウザ等）が「孫」です。今回の主役です。
- ゾンビ的プロセス … 親を止めたのに死なずに居座り続けるプロセスを、この記事ではこう呼びます。次の起動をブロックしたり、同じ処理を重複させたりします。
見つかった矛盾の実データ
対象は、5分ごとに動くメール意思決定ジョブ（decide_mail）です。実測5.3日で468回起動し、うち27回がタイムアウトのerrorで終わっていました。その27回の中に、おかしな記録が2件ありました。2026年7月21日の実データです。
| run_id | 開始 | 終了 | 実時間 | 記録上のエラー |
|---|---|---|---|---|
| decide_mail-33beef9c39 | 01:20:03 | 03:24:02 | 124.0分 | timeout 900s |
| decide_mail-9412483576 | 04:21:33 | 06:41:02 | 139.5分 | timeout 900s |
「900秒＝15分で切った」という名前のエラーなのに、記録上の開始から終了まで2時間以上空いています。15分でタイムアウトを検知したはずの処理が、終了の記録を書くまでに、さらに2時間近くかかっていたことになります。
なぜこうなるのか
Pythonのsubprocessにtimeoutを掛けたとき、それが直接殺すのは起動した子プロセスだけです。その子がさらに孫プロセス——AIのCLIやブラウザといった重い処理——を産んでいると、親を止めても孫が生き残ることがあります。そして親側は、終了処理（後始末やハンドルのクローズ等）でブロックし、記録上の「終了」がずっと後ろにずれこみます。
つまり今回の記録は、こう読めます。15分の時点でタイムアウトの判定自体は下りた。しかし、産まれた孫までは殺しきれず、親の終了処理が2時間以上ブロックされ、終了の記録が139分後になった。 その間、実際のプロセスは生きていました。
同種の障害は、当社の別のアプリでも実際に起きています。「終了処理でハングし、exitイベントが来ず、親が永久にawaitし続ける」「（Node.jsは）オープンハンドルが残っていると、main関数がreturnした後もプロセスが終了しない」——言語もアプリも違いますが、構造は同じです。上位に掛けたタイムアウトは、子孫のプロセスまで確実に殺せるとは限らない。
何が困るのか
居座ったゾンビ的プロセスは、放っておくと2つの害を出します。次の起動をブロックすること、そして同じ処理を重複して走らせることです。前の記事で見た「発火したはずのジョブが抜ける」「実行が異常に長時間化する」という現象の、一因がこれです。5分ごとに動くはずのジョブの前に、2時間居座る先客がいたわけです。
正直に書く点
- これは「タイムアウトが効いていない」バグです。そして、まだ完全には直せていません。 プロセスグループごと確実に殺す等の対策を検討している段階です。
- 原因の全部を解明したとも言いません。 decide_mailがそもそも何に時間を食っていたのか——AIの応答待ちなのか、メール取得待ちなのか——の切り分けは、まだ途中です。分かったのは「記録上のタイムアウトと、実際のプロセスの生死は別物だった」というところまでです。
関連する記録
- 毎朝動いているはずのAI自動化41本を5.3日ぶん数えたら、最大91%が発火すらしていなかった — この謎を宿題として残した全数調査。
- 止まったメディア更新を、見張り役が自動で叩き起こしていた話 — 原因を直す前に入れた対症療法の側。
まとめ
- 自動化基盤には15分（900秒）で強制終了するタイムアウトを掛けている。記録上も「timeout 900s」のエラーが残る。
- しかし実データ2件で、開始から終了まで124分・139.5分という記録が見つかった。タイムアウトは"効いたことになっていた"だけだった。
- 機序は、subprocessのtimeoutが殺すのは子プロセスだけで、孫プロセスが生き残り、親の終了処理がブロックされるため。当社の別アプリでも同じ構造の障害が起きている。
- 居座ったプロセスは次の起動をブロックし、処理を重複させうる。前記事の「抜け・長時間化」の一因。
- まだ直っていない。 プロセスグループごと殺す対策は検討中。何に時間を食っていたかの切り分けも途中。分かったところまでを、そのまま書いた。