このプロジェクトについて
EDINET(有価証券報告書等)の開示データをもとに、日本株の財務指標・投資判断スコアを日次で算出・公開しているサービスです。ニュース記事の要約と、意味の近い記事を探すための数値化(ベクトル化)にはローカルLLM(Ollama)を使っており、その処理はワークフロー管理ツールAirflowが1日4回動かしています。Airflowでは一連の処理をまとめた実行単位をDAGと呼び、今回の主役は llm_processing という名前のDAGです。
公開サイトはこちら →
https://stocks.happy-life-design.net
前回の記事はこちら →
https://qiita.com/rightcross-ae86/items/6c7a8e14080f5a9edf00
7月5日: リトライ待ちのまま1時間以上進まないタスクを見つけた
OSアップデートに伴うサーバー再起動のあと、全体の正常性確認をしている最中に見つけました。llm_processing DAGの run_llm_tasks タスクが up_for_retry(リトライ待ち)のまま1時間以上進んでいません。
リトライ待ちということは、Airflowはこのタスクを「あとで実行する」と認識しています。それなのに、いつまで経っても実行されませんでした。
直接の原因: 一時停止中のDAGは、リトライもキューイングされない
DAGの状態を確認すると is_paused=True、つまり一時停止(pause)されていました。
一時停止は「これから始まる分を動かさない」だけだと考えていたのですが、Airflowのスケジューラのソース(airflow/jobs/scheduler_job_runner.py)を読むと、実行待ちタスクを拾うクエリの時点で一時停止中のDAGが除外されていました。
.where(not_(DM.is_paused))
この条件があるため、一時停止中のDAGはすでに走り始めたDAG実行のリトライすらキューに載りません。タスクの状態は「リトライ待ち」のまま変わらず、外からは「予約されているのに永久に実行されない」ように見えます。
一時停止を解除したところ、3回目のリトライが直ちに流れて成功しました。復旧そのものは1コマンドです。
docker exec <コンテナ名> bash -c "airflow dags unpause llm_processing"
復旧はできたが、「なぜ止まっていたか」が分からなかった
問題はここからでした。このDAGを止めた覚えがなく、日々の作業内容を書き残している作業メモにも、止めたという記録がありません。
処理は動き出しており、実害はすでに止まっています。そのため「いつ・なぜ一時停止されたか不明」という一文だけを残課題として登録し、そのまましばらく過ぎました。
8月26日: 操作履歴はAirflowのデータベースに残っていた
残課題リストを見直していて、唯一手つかずで残っていたのがこの項目でした。
まず現状確認として airflow dags list を実行し、is_paused=False(正常)であることを確認します。そのうえで、過去に一時停止された履歴が残っていないかを調べました。
Airflowは実行状態だけでなく操作履歴もメタデータ用のデータベース(airflow_db)に持っています。その log テーブルを直接参照したところ、cli_dag_pause / cli_dag_unpause というイベントのレコードが残っていました。
| 日時(UTC) | イベント | 回数 |
|---|---|---|
| 2026-05-19 04:11:55〜04:12:24 | cli_dag_pause |
3回 |
| 2026-05-21 01:18:44〜01:18:52 | cli_dag_unpause |
2回 |
| 2026-07-04 23:09:46 | cli_dag_pause |
1回 |
| 2026-07-05 00:29:53 | cli_dag_unpause |
1回 |
最後の cli_dag_unpause の時刻は、7月5日に自分で一時停止を解除した時刻と一致します。探していた「いつ止まったか」は、このテーブルがずっと持っていました。
Airflowが自動で止めた可能性を先に消しておく
操作履歴が見つかっても、それだけでは手で打ったコマンドとは限りません。自動で止まった線を先に消しておきたかったので、3点を確認しました。
| 確認したこと | 結果 | そこから言えること |
|---|---|---|
| イベント名の接頭辞 |
cli_ が付いている |
Web UIのトグル操作ではなく、airflow dags pause というCLIコマンドの実行 |
| 他のDAGでの発生有無 |
llm_processing 以外では発生していない |
Airflow全体に影響する事象ではなく、このDAGだけが対象 |
dags_are_paused_at_creation の設定値 |
false |
DAGの新規作成時に自動で一時停止される設定でもない |
このDAGだけを狙って、誰かが手でコマンドを打った。そういうことになります。
なぜ一時停止が入ったのか
一時停止された時刻は 2026-07-04 23:09 UTC、日本時間では7月5日の8時09分です。その前後に何をしていたかを作業メモで振り返りました。
前日の7月4日は、CPU温度が91〜95℃まで上がるアラートの原因を追いかけていました。調べた結果、llm_processing のローカルLLM呼び出し(schedule_interval="30 0,15,18,21 * * *")が他プロジェクトのCron実行時刻と重なり、その時間帯に負荷が集中していたことが分かっています。
一時停止の時刻は、ちょうどこの調査を切り上げたあたりに重なります。負荷の出どころを切り分けるためにDAGを一時的に止め、作業メモに書き残すのを後回しにしたまま、元に戻すのも忘れて翌日の作業に移っていました。
5月19日〜21日の1回目も同じことをやったのだと思いますが、当時はまだ作業メモを付けておらず(付け始めたのは6月24日)、裏付けは取れませんでした。
再発していないことをどう確認したか
「原因はこれだった」で終わらせると、同じことが今も続いていた場合に気づけません。7月5日以降、DAGが予定どおり動いているかを実行履歴から確認しました。
- 2026年6月27日〜8月25日の約8週間分のDAG実行履歴を日次で集計
-
llm_processingが毎日4回実行されていること、実行が欠けた日が0件であることを確認
7月5日以降、一時停止は一度も発生していません。
経過の内訳
| 区間 | 期間 | 処理は止まっていたか |
|---|---|---|
| 一時停止されてから発見まで | 約1時間20分 | 止まっていた(リトライ待ちのまま) |
| 発見から復旧まで | 数分 | 解除して復旧 |
| 復旧から原因特定まで | 長期間 | 動いている(原因が分かっていないだけ) |
実害があったのは最初の1時間20分だけです。残りは「原因不明の課題」がリストに載り続けていた時間で、原因を特定する作業自体は、監査ログを1回参照すれば終わる内容でした。
何をしていれば長引かせずに済んだか
システム側のログには最初から残っていました。足りなかったのは手元の記録のほうです。
- 一時的に止めたものは、止めたその時点で記録する。 「あとで戻すから書かなくていい」と判断したものが、戻らずに残りました
- その日の作業を終える前に、一時的に入れた設定を元に戻す。 今回の一時停止は、調査用の応急処置がそのまま本番の設定として残ったものです
- 「原因不明」を残課題に登録するときは、まだ見ていない情報源も併せて書く。 「Airflowの監査ログは未確認」と書いてあれば、ここまで長引かなかったはずです
効き目が大きいのは3つ目です。残課題リストには「何が分からないか」は書いてありましたが、「どこを見れば分かる可能性があるか」は書いていませんでした。その結果、着手しても何から始めればいいか分からない項目になり、優先度が上がらないまま後ろへ回り続けました。
まとめ
Airflowで「タスクは残っているのに動かない」ときは、まずDAGの一時停止状態を疑うのが速い、というのが実務上の教訓です。一時停止中はリトライもキューに載らないため、リトライ待ちのまま無期限に止まります。
そして「いつ誰が止めたのか」は、Airflowのメタデータ用データベースの log テーブルに cli_dag_pause として残っています。今回は長らく「原因不明」として扱っていましたが、記録は最初からシステムの中にありました。原因不明のまま残課題に積む前に、まだ見ていないログが無いかを確認する価値があります。
気になる点・ご質問があればコメントでお知らせください。