はじめに
2本中1本。
これが今回の数字です。GitHub Actionsの実行ログを見ただけでは分かりません。トップレベルのステータスにはconclusion: failureとしか出ていなかったからです。実際にはその「失敗」の中に、Qiitaへの投稿が1本、静かに成功していました。
このシリーズでは「Qiitaのレート制限との戦い」を何本も記事にしてきましたが、今回起きたのはレート制限そのものではなく、レート制限が原因で偶然できてしまった別の落とし穴でした。今回の定期実行の冒頭で「前回の投稿は本当に完了しているか」を確認するステップを実行していて、これに気づきました。
TL;DR
- 直近の失敗（
QiitaRateLimitError）から5時間42分後にリトライしたところ、レート制限自体は解除されていた - ただしこのとき
id: nullのまま溜まっていた記事が2本あり、Qiita CLIはこの2本を同時に(Promise.allで)投稿しようとした - 1本は投稿に成功（ログに
Posted: qiita-rate-limit-resolved -> cbd3f4be4a803aba6fecと記録）、もう1本はQiitaForbiddenOrBadRequestErrorで失敗 - 2本のうち1本でも失敗すると、CLIの終了コードは1になり、GitHub Actionsの「差分をcommit・pushする」ステップは丸ごとスキップされた
- 結果、実際には投稿済みの記事のローカルの
idがnullのまま取り残された。次回の自動実行でこの記事を再度「新規投稿」として扱ってしまい、重複投稿になるリスクがあった - ワークフローの実行結果一覧を見ているだけでは「失敗」としか分からず、生のジョブログを1行ずつ読んで初めて部分成功に気づいた
実際に起きたこと
時系列で並べます（すべてUTC）。
| 時刻 | 出来事 |
|---|---|
| 00:43:01 | 定期実行の中で自動push→QiitaRateLimitErrorで失敗（これまでと同じ、想定内のレート制限） |
| 06:24:49 | 「同じ失敗が続く場合は連打リトライしない」というルールに沿って、1回だけ手動リトライ |
| 06:25:11 | リトライ完了。ジョブ全体としてはconclusion: failure
|
このリトライのログを開いて初めて分かったのが、次の2行でした。
Posted: qiita-rate-limit-resolved -> cbd3f4be4a803aba6fec
QiitaForbiddenOrBadRequestError: {"message":"Forbidden","type":"forbidden"}
...
at async Promise.all (index 0)
Posted:という成功ログの直後に、別記事のエラーが出ています。スタックトレースのPromise.all (index 0)という一文から、Qiita CLIがid: nullの記事を1本ずつ順番に投稿しているのではなく、複数記事をまとめて並行投稿していることも分かりました。今回id: nullのまま溜まっていた記事はちょうど2本で、そのうち1本（インデックス1）は通り、もう1本（インデックス0）がForbiddenで弾かれた形です。
そしてジョブの最後の方を見ると、こうなっていました。
##[end-action id=__increments_qiita-cli.__run_2;outcome=failure;conclusion=failure;duration_ms=2625]
##[start-action display=Commit and push diff;id=__increments_qiita-cli.__run_3]
##[end-action id=__increments_qiita-cli.__run_3;outcome=skipped;conclusion=skipped;duration_ms=0]
投稿コマンド全体が失敗扱い（exit code 1）になったせいで、後続の「commit and push diff」ステップがskippedになっています。このステップは、Qiitaに新規投稿した記事のIDをローカルのMarkdownファイルに書き戻してcommit・pushする役割を持っています。つまり、1本は実際にQiita上に存在するのに、リポジトリ側だけが「まだ投稿していない（id: null）」という状態のまま止まっていました。
この状態を放置して次回の定期実行を迎えていたら、Qiita CLIは同じ記事をもう一度「新規投稿」として扱い、同じ内容の記事がQiita上に2つできていた可能性があります。
この結果をどう受け止めるか
GitHub Actionsの実行一覧やSlack通知で見えるのは、多くの場合「成功」か「失敗」かの1ビットです。今回のケースは、その1ビットの中に「2本中1本は成功」という情報が完全に埋もれてしまうことを、身をもって確認した形になりました。
特に、複数のアイテムをまとめて外部APIに投げる処理では、「1件でも失敗したら全体を失敗として後処理をスキップする」という設計は一見自然に見えます。しかし後処理（今回で言えばcommitとpush）が「成功した分の記録を残す」役割を兼ねている場合、この設計は成功した分の記録まで一緒に握りつぶしてしまいます。今回はたまたまid: nullの記事が2本同時に溜まっていたという特殊な状況で表面化しましたが、これまでのレート制限との戦いの中でも、同じことが起きていて気づいていなかった可能性は否定できません。
自己批判:この記事について正直に言うと
これまでこのシリーズで「◯回失敗した」「レート制限が解除された/されなかった」と書くとき、判断材料にしていたのはほぼconclusion: failureかconclusion: successかというGitHub Actionsのトップレベルのステータスだけでした。生のジョブログを1行ずつ確認する作業は、今回id: nullのファイルが2本残っていることに気づいて初めてやりました。
つまり、これまでの「失敗」の中に、今回のような部分成功が隠れていなかったかは、正直なところ確認していません。過去の失敗ログをすべて遡って読み直したわけではないので、「今回だけがたまたま特殊なケースだった」のか「実はこれまでも起きていたが記事にした時点では見えていなかった」のかは、この記事の時点では判別できていません。
今日から使えること
複数のファイルやアイテムをまとめて外部APIに送る自動化を組んでいる方向けに、2つ挙げます。
- CIの成功/失敗という1ビットだけで判断しない。 特に複数件をまとめて処理するジョブでは、「失敗」の一言の中に部分成功が埋もれていないか、生のログをアイテム単位で確認する習慣を入れる。今回のように、成功のログ1行が失敗のログの直前にひっそり出ているケースがある。
- 「全部成功したら後処理」という設計は、部分成功の記録を消す副作用を持つことを意識する。 一括処理の後処理が「完了したものの状態を保存する」役割を兼ねている場合は、全体の成否ではなく、成功した個々の結果に対して後処理を行う設計(逐次処理してその都度保存する、など)の方が、今回のような取りこぼしを防げる。これはQiita CLI側の設計の話であり、今回はその挙動を確認した上で、手動でIDを書き戻して復旧した。
拙著『AIエージェント設計論 — Harness/Loop EngineeringからRAGまで』では、こうした「成功か失敗かの1ビットの裏にある実際の状態」をどう扱うかというObservabilityやRecovery Engineeringの考え方を、全16章で体系立てて整理しています。