GitHub Actionsのcronで組んだ定時実行が、予約した時刻に動きませんでした。遅れた幅は43分から103分。設定は同じままで、日によってばらつきます。
最初は自分の書き方を疑って何度も見直したんですが、原因はこっち側にありませんでした。しかも厄介なのは、遅れるだけやなくそのまま来ん日もあることです。この記事は、その2つをどう見分けて、どう組み直したかの記録です。
先に結論だけ書いておきます。
- 出したい時刻ちょうどに予約せず、発火する時刻より前に置く
- 1本のcronに賭けず、時間差で複数回発火させる
- 多重化するなら二重実行のガードは必須(これが無いと同じものが何回も出る)
予約は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です。進行中の障害と、いつ発生していつ緩和されたかがここに出ます。
対策1|出したい時刻より前に置く
21時に出したいなら、21時に予約せんことにしました。定時実行そのものが遅れてくるので、ぴったりに出すのを諦めて、前倒しで置くほうが結果として近い時刻に着きます。
これが成り立つのは、まだ来てへん時刻のぶんは処理せずに待つようにしてあるからです。早い便が拾っても、予約時刻が未来ならそのまま置いて帰る。だから前倒しで置いても早く出てまうことはありません。
具体的には、初便が20時53分に発火する設定なので、予約はその8分前の20時45分に置いてます。ここを何分にするかは、自分のcronの発火時刻から逆算するだけです。
ひとつ注意点があって、前倒しで置いたぶんには賞味期限があるようにしてます。自分の場合は予約時刻から6時間で期限切れ扱いにして、処理済みへ退避させる。これが無いと、何日も前の予約が残っとって忘れた頃に出てまいます。
あわせて、毎時ちょうどの時刻は避けました。混む時間に自分から並びに行く理由が無いからです。
対策2|発火を多重化する

もうひとつは、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回だけ見に行っといたほうがええです。
よくある質問
どれくらい遅れるものですか?
自分の実測では43分から103分でした。設定は変えてへんのに日によって違います。目安は決めてええですが、上限があるものとして組まんほうがええです。
遅延を無くす方法はありますか?
定時実行に任せず、外から叩いて起こす形にすると精度は上がります。ただし叩く側を別に用意することになるので、そこを何が動かすのかという話に戻ります。自分は前倒しと多重化で足りたので、そこまではやってません。
失敗したのか遅れとるのか、どう見ますか?
実行の履歴に何も出てへんなら、まだ発火してへんということです。緑で終わっとるのに結果が出てへんなら、中の処理のほうを見ます。この2つは原因が別なので、先に切り分けたほうが早いです。
あわせて読みたい
- Windows自動化で黙って壊れる罠3つ|エラーが出ない|これもエラーにならんまま壊れる系統の話
- テストが通っても本番で落ちる|緑を信じて1日分飛ばした|緑は動いた証明やない、という話
- 未経験10日目、AIで作業を自動化するツールを自作した話|そもそも何を自動で出しとるかはこちら