GitHub Actionsのcron遅延|落ちたと決める前に

GitHub Actionsのcronで組んだ定時実行が、予約した時刻に動きませんでした。遅れた幅は43分から103分。設定は同じままで、日によってばらつきます。

最初は自分の書き方を疑って何度も見直したんですが、原因はこっち側にありませんでした。しかも厄介なのは、遅れるだけやなくそのまま来ん日もあることです。この記事は、その2つをどう見分けて、どう組み直したかの記録です。

先に結論だけ書いておきます。

  1. 出したい時刻ちょうどに予約せず、発火する時刻より前に置く
  2. 1本のcronに賭けず、時間差で複数回発火させる
  3. 多重化するなら二重実行のガードは必須(これが無いと同じものが何回も出る)

予約は20時45分、届いたのは21時31分

やっとることは単純です。ブログの記事とSNSの投稿を、決めた時刻に自動で出す。出したい中身をファイルにして置いておくと、定時に走るワークフローがそれを拾って処理する、という形にしてます。

実際に届いた時刻はこうでした。

  • 20時45分に予約 → 21時31分に着弾(46分遅れ)
  • 6時50分に予約 → 7時33分に着弾(43分遅れ)
  • 別の日は20時45分 → 21時35分(50分遅れ)/6時50分 → 7時55分(65分遅れ)
  • いちばんひどい日で103分(1時間43分)

ここで押さえておきたいのは、どれも成功しとることです。失敗の通知は来ません。実行のログも緑。ただ時刻がズレとるだけ。だから「動いてへん」と気づくのは、たいてい人間が見に行った時です。

「遅れとる」と「落ちた」は、見た目が同じ

21時に見に行って、まだ出てへん。この時点で分かることは何も無いんです。遅れとるだけかもしれんし、もう来んのかもしれん。

ここで慌てて手で撃ち直すと、あとから遅れて届いた分と合わせて二重に出ます。かというて待っとったら、そのまま何も来ん日がありました。

朝の便が3つとも来んかった日があります。自分の設定を疑って小一時間ほど探し回ったんですが、その日はGitHub側で障害が起きとりました。深夜0時22分に発生して、午前9時5分に緩和されるまで続いとった。つまり待っても来ん形です。

この日の学びははっきりしてます。動かんかった時に最初に見るべきは、自分のコードやなくてサービス側の状態でした。

落ちたと決める前に見る2つ

1つめ、落ちた判定の基準を先に決めておく。基準が無いと、その場の気分で撃ち直してまうからです。

ここは一回間違えました。最初は「予約時刻から2時間」で区切っとったんですが、記録を数え直したら自然に遅れた分の最大は103分=1時間43分。2時間には収まっとります。ただ、それで安心できるわけやありませんでした。障害が出た日は、2時間待っても来んかったからです。時間で区切っても、遅れとるだけなのか、もう来んのかは分けられません。

今は時計やなくて最後の便が走り終わったかどうかで見てます。自分の設定なら夜の最終便は22時53分なので、そこを過ぎて何も来てへんかったら落ちた、という判定です。実測の最大値をそのまま目安にすると、更新されるたびに毎回ズレます。

2つめ、自分を疑う前に障害情報を見る。GitHubは稼働状況を公開しとって、進行中の障害が機械で読める形でも取れます。ワークフローの中身を読み直すのは、そこを見てからで遅ないです。

見に行く先はGitHub Statusです。進行中の障害と、いつ発生していつ緩和されたかがここに出ます。

何日待ってもcronが動かない時

ここまでは「遅れて届く」と「障害の日は来ん」の話でした。止まり方はもう1種類あって、何日たっても一度も動かん形です(動いとるのに気づいてへんだけ、も含む)。これは遅れとは別物で、原因は公式のドキュメントにはっきり書いてあります。

  • ファイルが既定のブランチに入っとるか。定時実行は、既定のブランチ(たいてい main)にあるワークフローでしか動きません。作業用のブランチに置いたままやと、何日待っても来ん
  • 自動で止められてへんか。公開リポジトリで60日間なにも動きが無いと、定時実行は自動で無効になります。Actionsタブでそのワークフローを選んで「Enable workflow」を押せば戻る。公開リポジトリをフォークしたものも、最初は止まった状態です
  • 日本時間のつもりで書いてへんか。cronの時刻は、何も指定せんとUTCで読まれます。動いとるのに9時間ずれた時刻に走っとるだけ、ということがある

どれに当たるかは、実行の履歴で分かります。遅れとる時は、遅れた時刻で実行が残っとる。知らん時刻に並んどったら、たぶん3つめ。定時実行で起きた実行が1本も無いなら、1つめか2つめです。

出所はGitHub Docs の schedule の説明です。毎時ちょうどは混んで遅れやすいこと、負荷が高すぎると並んだ実行が捨てられることがある、というのもここに書いてあります。

対策1|出したい時刻より前に置く

21時に出したいなら、21時に予約せんことにしました。定時実行そのものが遅れてくるので、ぴったりに出すのを諦めて、前倒しで置くほうが結果として近い時刻に着きます。

これが成り立つのは、まだ来てへん時刻のぶんは処理せずに待つようにしてあるからです。早い便が拾っても、予約時刻が未来ならそのまま置いて帰る。だから前倒しで置いても早く出てまうことはありません。

具体的には、初便が20時53分に発火する設定なので、予約はその8分前の20時45分に置いてます。ここを何分にするかは、自分のcronの発火時刻から逆算するだけです。

ひとつ注意点があって、前倒しで置いたぶんには賞味期限があるようにしてます。自分の場合は予約時刻から6時間で期限切れ扱いにして、処理済みへ退避させる。これが無いと、何日も前の予約が残っとって忘れた頃に出てまいます。

あわせて、毎時ちょうどの時刻は避けました。混む時間に自分から並びに行く理由が無いからです。

対策2|発火を多重化する

複数の矢印が一点に集まる様子を表した図。cronの発火を多重化して確実に動かすイメージ
複数の合図をひとつにまとめる考え方

もうひとつは、1本の定時実行に賭けるのをやめたことです。夜は4回、朝は3回、時間差で発火させてます。それぞれ独立にキューへ並ぶので、1便がハマっても別の便が先に着地する。

書き方はこうです。cronの行を足していくだけの話です。

on:
  schedule:
    - cron: '53 11 * * *'   # UTC 11:53 = JST 20:53
    - cron: '23 12 * * *'   # UTC 12:23 = JST 21:23
    - cron: '53 12 * * *'   # UTC 12:53 = JST 21:53
    - cron: '53 13 * * *'   # UTC 13:53 = JST 22:53

時刻はUTCで書いとります。日本時間から9時間引いた値です(日本時間のまま書く方法は下に書きました)。分に「00・15・30・45」を使ってへんのは、世間のcronがそこに集まるからで、うちは07・23・53に寄せてます。

ただしこれは単体でやったらあかん改造です。同じ仕事を4回拾いに行く形なので、素でやると同じものを4回出します。

要るのは、何回走っても結果が変わらん作りにしておくことです。自分の場合は、出したものを処理済みの置き場へ移してから終わる形にしました。次の便が来た時にはもう対象が残ってへんので、何もせずに帰る。多重化と、この二重実行のガードはセットです。

ガードが効いとるかは、2本目以降の便のログを見れば分かります。1本目が仕事をした日に、後続の便が「対象なし・0件で終了」になっとったら成功です。ここが毎回何か処理しとるようやったら、ガードが素通りしとります。同じものが2回出てから気づくのは遅いので、入れた日に1回だけ見に行っといたほうがええです。

日本時間(timezone)でcronを書く時

9時間引くだけなら暗算で済む。そう思っとったんですが、1か所だけ落とし穴があります。日本時間の朝9時より前は、UTCでは前の日になることです。

うちの朝の初便は日本時間の7時07分で、書いとる値は 7 22 * * *。UTCの22時07分、つまり前の日の夜です。毎日動かすだけなら日付がずれても困りません。困るのは曜日や日にちを指定した時で、日本時間の「月曜7時07分」はUTCやと「日曜22時07分」。曜日の欄まで1つ前にずらさなあかん。

# 日本時間の月曜 7:07 を UTC で書く(曜日は 0=日曜)
- cron: '7 22 * * 0'

この変換が面倒なら、今は時間帯を指定する書き方があります。公式のドキュメントに timezone という項目が載っとって、時間帯の名前(日本なら Asia/Tokyo)を書くと、cronの時刻をその時間帯で読んでくれる。

on:
  schedule:
    - cron: '7 7 * * 1'   # 月曜 7:07(日本時間)
      timezone: "Asia/Tokyo"

先に白状しとくと、うちのワークフローはまだUTCで書いたままで、この書き方は自分では動かしてません。書いた内容の出所はGitHub Docs のワークフロー構文のページです。夏時間のある国を指定した時の注意書きも載っとるけど、日本は夏時間が無いのでそこは関係ない。

それと、時間帯を指定しても遅れる話は別です。日本時間で書いたから7時07分ぴったりに動く、とはならん。前倒しと多重化はそのまま要ります。

よくある質問

どれくらい遅れるものですか?

自分の実測では43分から103分でした。設定は変えてへんのに日によって違います。目安は決めてええですが、上限があるものとして組まんほうがええです。

遅延を無くす方法はありますか?

定時実行に任せず、外から叩いて起こす形にすると精度は上がります。ただし叩く側を別に用意することになるので、そこを何が動かすのかという話に戻ります。自分は前倒しと多重化で足りたので、そこまではやってません。

失敗したのか遅れとるのか、どう見ますか?

実行の履歴に何も出てへんなら、まだ発火してへんということです。緑で終わっとるのに結果が出てへんなら、中の処理のほうを見ます。この2つは原因が別なので、先に切り分けたほうが早いです。

あわせて読みたい