自作タスクキューの失敗ログ2772件を集計したら、原因の過半が同じパターンだった
① 現象
複数のワーカーが非同期にタスクを実行し、結果を result.json に書いて終わる自作のジョブキュー基盤を運用している。失敗したタスクは1行1件の JSON Lines 形式で error-ledger.jsonl に追記される仕組みだが、運用を続けるうちに「毎回何かしら失敗している気がするが、原因はバラバラだろう」という体感だけがあり、実数を見たことがなかった。
② 再現する最小の状況
error-ledger.jsonl は次のようなレコードが1行1オブジェクトで並ぶだけの単純なフォーマット。
{"ts":"2026-09-04T01:12:13.8592862+09:00","card_id":"AUTO-K4-CT-YTEN-META-D0904-20260903-mn","status":"blocked","fail_type":"blocked_by_input","origin":"system","dept":"video","lane":"youtube-en","project":"multilang"}
ワーカー側の規約は「判断材料（入力）が足りない場合は、無い事実を捏造して成果物を作らず status=blocked / fail_type=blocked_by_input として自己申告し停止する」というもの。これ自体は正しい自己防衛だが、件数が積み上がると「実際に多いのはどのタイプか」が肉眼のgrepでは追いきれなくなる。
③ 原因
実データを集計した。ファイル全体は2772行（累積）。直近の稼働区間 2026-09-02T03:57〜2026-09-04T07:04（JST、n=85件）を切り出して fail_type の内訳を数えると次の通り。
| fail_type | 件数 | 割合 |
|---|---|---|
| blocked_by_input | 49 | 57.6% |
| missing_inputs | 7 | 8.2% |
| dependency_defer_exhausted | 5 | 5.9% |
| （空文字） | 6 | 7.1% |
| tool_unavailable / login_required / dependency_not_ready / tool_access_restricted | 各2 | 各2.4% |
| その他単発（10種） | 10 | 11.8% |
blocked_by_input だけで過半（57.6%）を占めていた。中身を見ると、下流タスクが「上流タスクの成果物・承認・ログイン状態」が揃う前にスケジューリングされてしまい、ワーカーが規約通り正直に自己ブロックしているケースがほとんどだった。つまり原因は個々のワーカーの実装バグではなく、依存関係がまだ整っていないタスクを先に投入してしまうスケジューリング側の設計にある。
④ 直し方
まず「肉眼のgrep」から「再利用できる集計スクリプト」に変えた。Node.js標準ライブラリだけで書ける。
// count-fail-type.js
const fs = require("fs");
const [, , file, sinceArg] = process.argv;
const since = sinceArg ? new Date(sinceArg) : new Date(0);
const lines = fs.readFileSync(file, "utf8").split("\n").filter(Boolean);
const counts = {};
let total = 0;
for (const line of lines) {
const rec = JSON.parse(line);
if (new Date(rec.ts) < since) continue;
total++;
const key = rec.fail_type || "(empty)";
counts[key] = (counts[key] || 0) + 1;
}
Object.entries(counts)
.sort((a, b) => b[1] - a[1])
.forEach(([type, n]) => {
console.log(`${type}\t${n}\t${((n / total) * 100).toFixed(1)}%`);
});
console.log(`total\t${total}`);
$ node count-fail-type.js error-ledger.jsonl 2026-09-02T00:00:00+09:00
blocked_by_input 49 57.6%
missing_inputs 7 8.2%
dependency_defer_exhausted 5 5.9%
...
total 85
jq があれば近い集計を1行で書ける。
jq -r 'select(.ts >= "2026-09-02") | .fail_type' error-ledger.jsonl | sort | uniq -c | sort -rn
このシステムはすでに「入力未整備は dependency_defer_exhausted として再試行に回す」という区分を持っていた。つまり根本の直しは新規実装ではなく、この集計スクリプトを定点観測として組み込み、blocked_by_input の比率が閾値（例: 50%）を超えたらスケジューラ側の依存順序を疑う運用にすることだった。原因調査の入口を「なんとなく多い気がする」から「実数で57.6%」に変えただけで、次に見るべき場所が一意に決まった。
⑤ 学び
- 失敗を握りつぶさず
fail_typeのような列挙値で自己申告させておくと、後から集計するだけで原因の分布が可視化できる。 - 「体感」と「実数」はズレる。grepか50行程度のNode.jsスクリプトで済むなら、体感で判断する前に数えたほうが早い。
- 過半を占める原因が1つに絞れれば、次の一手（今回はスケジューリング側の依存順序の見直し）も自動的に絞られる。