⏳
GitHub Actions でワークフローの実行時間≒ジョブ実行時間の合計にならなかった話
「GitHub Actions のスケジュール実行による待機時間を Google Data Portal で可視化した」で実行しているワークフローは 30 分毎にスケジュール実行しています。そのためサービスの障害の影響を受けることが時々あります。その中で少し興味深い現象があったのでメモなど。
ジョブは 1 つでタイムアウトは 10 分
上記で実行している各ワークフローのジョブは 1 つだけで、ジョブには 10 分のタイムアウトを設定しています。
jobs:
append:
environment: append
permissions:
contents: 'read'
id-token: 'write'
runs-on: ubuntu-latest
timeout-minutes: 10
しかし、ワークフローの実行時間は 20 分を超えることも
GitHub で障害発生していた近辺の出来事になりますが、ワークフロー開始から終了までの時間が 20 分を超えることがありました。
調べてみると、「ジョブは数秒で完了しているがワークフローの実行時間が長い」ということがわかりました。
▼ 図 2-1 ワークフローとジョブの実行時間
さらにログを確認してみると「runner がジョブをピックアップするのを待っている時間」が長いという状況です。
▼ 図 2-2 runner がオンラインになるのを待っている時間
2022-03-18T01:50:37.2662072Z Requested labels: ubuntu-latest
2022-03-18T01:50:37.2662156Z Job defined at: hankei6km/gha-now-to-sheet/.github/workflows/append-00-13.yaml@refs/heads/main
2022-03-18T01:50:37.2662198Z Waiting for a runner to pick up this job...
2022-03-18T01:50:37.5434531Z Job is waiting for a hosted runner to come online.
2022-03-18T02:11:48.4331373Z Job is about to start running on the hosted runner: Hosted Agent (hosted)
2022-03-18T02:11:50.8795737Z Current runner version: '2.288.1'
オーバーヘッドがあるので「ジョブの実行時間 = ワークフローの実行時間ではない」ということは頭では理解していましたが、ここまで違うことがあるのは少し意外でした。
おわりに
上記のことはイレギュラーなこととは思われますが、普段まったく発生しないとも言い切れません。障害が発生していないときでも 5 分近くピックアップ待ちになることもありました[1]。
「ジョブにタイムアウトを設定しているからワークフローの実行時間は一定の範囲に収まる」という前提でフローを組んでいると思わぬ落とし穴があるやもしれません。
-
実際の状況はわかりませんが、GitHub Status - Incident History には記録がない状態です。 ↩︎
Discussion