はじめに
GoプロジェクトのCIでgolangci-lintを実行していたところ、
突然Lintが完了しなくなり、CircleCIのジョブがタイムアウトする問題が発生しました。
表示されていたエラーは、次のような内容です。
Too long with no output (exceeded 10m0s): context deadline exceeded
また調査中には次のようなエラーも確認しました。
ERRO Timeout exceeded: try increasing it by passing --timeout option
Exited with code exit status 4
どちらも同じ「タイムアウト」っぽいですが、
実際にはタイムアウトを発生させている主体が異なってました。
- CircleCI側の無出力タイムアウト
-
golangci-lint側の実行タイムアウト
本記事ではCircleCI上でgolangci-lintがタイムアウトした際に確認したこと・
そして実施した対処について紹介していきます!
Zenn派の方はこちら↓
本記事は問題が発生した当時のgolangci-lint
及びCircleCIの設定をもとにしています。
golangci-lintのタイムアウト仕様はバージョンによって異なるため、
利用中のバージョンの公式ドキュメントも確認してください。
実行していた処理
CircleCIでは、次のようにgolangci-lintを実行していました。
- run:
name: Run golangci-lint
command: |
$(go env GOPATH)/bin/golangci-lint run
しかしプロジェクトの規模が大きくなったり、有効化しているLinterが増えた影響もあり、
Lintの実行に時間がかかるようになりました。
→結果、CI上で次のエラーが発生しました。
Too long with no output (exceeded 10m0s): context deadline exceeded
最初は
「golangci-lintの処理が10分を超えたかな?」
「そもそもデフォルトでタイムアウト10分だったけ?」
なんてことを考えました。
が、このエラーで注目すべきなのは、
単に実行時間が長いことではなく下記です↓
Too long with no output
CircleCIはコマンドから一定時間出力がない場合、
処理が停止している可能性があると判断してステップを終了するのです。。
つまりgolangci-lint自体が正常に動いていたとしても、
ログを出力しない状態が続けばCircleCI側から終了させられる可能性があります。
タイムアウトには2種類ある
今回の問題では、次の2種類のタイムアウトを切り分ける必要がありました。
| タイムアウト | 判定する主体 | 意味 |
|---|---|---|
no_output_timeout |
CircleCI | 一定時間コマンドから出力がない |
--timeout |
golangci-lint |
Lint全体の実行時間が設定値を超えた |
この2つは似ていますが、別の設定です。
片方だけを変更しても、もう片方の制限に引っかかります。
1. CircleCI側の無出力タイムアウト
CircleCIのrunステップには、no_output_timeoutという設定があります。
これはコマンドの実行時間そのものではなく、
コマンドから最後に出力があってからの経過時間を制限するものです。
CircleCIはデフォルトで10分間出力がないと、該当ステップが終了する場合があり
今回発生した次のエラーは、この制限に該当します。
Too long with no output (exceeded 10m0s): context deadline exceeded
対策として、no_output_timeoutを延長しました。
- run:
name: Run golangci-lint
command: |
$(go env GOPATH)/bin/golangci-lint run
no_output_timeout: 20m # timeoutの延長を試みる
golangci-lintからログが出力されない時間が10分を超えても、
とりあえず20分まではCircleCIが待機するようになります。
no_output_timeoutは実行時間の上限ではない
ここで注意したいのは、no_output_timeoutは
処理全体の実行時間を制限する設定ではないことです。
例えばLintに30分かかったとしても、途中で継続的にログが出力されていればno_output_timeout: 10mには該当しません。
逆に処理全体が12分で終わるとしても、
途中で10分以上ログが出力されなければタイムアウトする場合があります。
処理開始
↓
2分後にログ出力
↓
10分以上出力なし
↓
CircleCIがステップを終了
重要なのは、処理時間ではなく無出力の時間です。
2. golangci-lint側のタイムアウト
次に確認したのが、golangci-lint自身のタイムアウトです。
発生していたエラーは次のような内容でした。
ERRO Timeout exceeded: try increasing it by passing --timeout option
Exited with code exit status 4
こちらはCircleCIではなく、golangci-lint自身が処理を終了しています。
利用しているバージョンで実行時間の制限が設定されている場合、
--timeoutオプションを指定して延長できます。
golangci-lint run --timeout=10m
CircleCIの設定では、次のようになります。
- run:
name: Run golangci-lint
command: |
$(go env GOPATH)/bin/golangci-lint run --timeout=10m
no_output_timeout: 20m
これで、それぞれ次の設定になります。
golangci-lintの実行時間上限: 10分
CircleCIの無出力時間上限: 20分
golangci-lint側のタイムアウトを10分にするのであれば、CircleCI側のno_output_timeoutは、それより長く設定しておくと原因を切り分けやすくなります。
ただし現在のgolangci-lintでは、
設定ファイルのタイムアウトに関する仕様がバージョンによって異なります。
特にv1系とv2系では挙動が異なるため、単純に過去の設定をコピーするのではなく
次のコマンドで利用中のバージョンを確認してください。
確認コマンド
golangci-lint version
詳細なログを出力する
タイムアウトの原因を調査するときは、
-vオプションを付けて詳細なログを出力する方法もあります。
golangci-lint run -v
今回の設定に加えると、次のようになります。
- run:
name: Run golangci-lint
command: |
$(go env GOPATH)/bin/golangci-lint run \
-v \
--timeout=10m
no_output_timeout: 20m
詳細ログを出すことで、次のような点を確認しやすくなります。
- どの設定ファイルが読み込まれているか
- どのLinterが実行されているか
- どの処理に時間がかかっているか
- キャッシュが利用されているか
-
golangci-lintが動作しているのか、停止しているのか
また利用しているバージョンで対応している場合は、
リソース使用状況を確認するオプションも調査に役立ちます。
golangci-lint run -v --print-resources-usage
オプションはバージョンによって変更される可能性があるため、
実行前にヘルプを確認します。
golangci-lint run --help
killedと表示された場合は別の原因も疑う
調査中に、次のようなログが出る場合もあります。
Received "killed" signal
または、単純に次のように表示されることもありますが
この場合はタイムアウトが原因とは限りません。
Killed
CIの実行環境でメモリが不足し、OSやコンテナランタイムによって
プロセスが終了させられた可能性があります。
golangci-lintは複数のLinterを並列実行するため、プロジェクトの規模や有効化しているLinterによっては、多くのCPUやメモリを使用します。
その場合は、下記のように並列数を下げるのもアリです↓
golangci-lint run --concurrency=2
CircleCIでは、次のように指定できます。
- run:
name: Run golangci-lint
command: |
$(go env GOPATH)/bin/golangci-lint run \
-v \
--concurrency=2 \
--timeout=10m
no_output_timeout: 20m
設定ファイルで管理する場合は、
利用しているgolangci-lintのバージョンに対応した形式で設定します。
run:
concurrency: 2
ただし並列数を下げるとメモリ使用量を抑えられる一方で、
Lint全体の実行時間は長くなる可能性があります。
そのため、次の観点を合わせて確認する必要があります。
- CircleCIのリソースクラス
- コンテナに割り当てられたCPUとメモリ
- 有効化しているLinter
- Lintの対象ディレクトリ
- キャッシュの有無
- 並列実行数
- Lintにかかっている時間
最終的な設定例
今回の対応をまとめると、次のような設定になります。
- run:
name: Run golangci-lint
command: |
$(go env GOPATH)/bin/golangci-lint run \
-v \
--concurrency=2 \
--timeout=10m
no_output_timeout: 20m
それぞれの役割は次のとおりです。
-v
詳細なログを出力する
--concurrency=2
並列実行数を抑え、CPUやメモリの使用量を調整する
--timeout=10m
golangci-lint側の実行時間を設定する
no_output_timeout: 20m
CircleCI側の無出力タイムアウトを延長する
ただし必ずしもこの値が適切とは限りません。
プロジェクトの規模やCircleCIの実行環境に合わせて調整する必要はあります。
また現在使用しているgolangci-lintのバージョンによっては、--timeoutや設定ファイル上のタイムアウトの扱いが異なる場合があります。
タイムアウトを伸ばすだけで終わらせない
タイムアウト値を伸ばせば、一時的にCIを通せる可能性があります。
しかし以前は短時間で終わっていたLintが急に遅くなったのであれば、
別の問題が発生している可能性もあります。
有効化しているLinterを確認する
必要以上に多くのLinterを有効にしていると、実行時間やメモリ使用量が増加します。
まずは現在有効になっているLinterを確認します。
golangci-lint linters
すべてを有効にするのではなく、プロジェクトで必要なLinterを選択することが重要です。
ローカルとCIの実行時間を比較する
ローカルでは短時間で終わり、CIだけが遅い場合は
CI環境のCPUやメモリが不足している可能性があります。
time golangci-lint run
ローカルでも遅い場合は、設定や対象範囲・特定のLinterに原因がある可能性があります。
キャッシュを確認する
golangci-lintはキャッシュを利用します。
CIで毎回キャッシュが破棄されている場合、実行時間が長くなる可能性を疑ってみましょう!
golangci-lint cache status
必要に応じて、CircleCIのキャッシュ機能を利用することも検討します。
対象範囲を確認する
生成されたコードや、Lint対象にする必要がないディレクトリまで解析していないか確認します。
ただし問題を隠すためだけに大量のファイルを除外すると、
Lintを導入している意味が薄くなります。
除外する場合は、なぜ対象外にするのかを明確にしておく必要があります。
トラブルシューティングの流れ
同様の問題が起きた場合は、次の順番で確認すると切り分けやすくなります。
1. エラーメッセージを確認する
↓
2. CircleCIが終了させたのか確認する
↓
3. golangci-lint自身が終了したのか確認する
↓
4. -vを付けて詳細ログを確認する
↓
5. ローカルでも実行時間を計測する
↓
6. CPU・メモリ・並列数を確認する
↓
7. 有効なLinterと対象範囲を確認する
↓
8. 必要に応じてタイムアウト値を調整する
エラー別に整理すると、次のようになります。
| エラー・現象 | 最初に疑うこと |
|---|---|
Too long with no output |
CircleCIのno_output_timeout
|
Timeout exceeded |
golangci-lint側のタイムアウト |
Killed |
メモリ不足やリソース制限 |
| CIだけ極端に遅い | CIのCPU、メモリ、キャッシュ |
| ローカルでも遅い | Linter、対象範囲、設定内容 |
まとめ
CircleCI上でgolangci-lintがタイムアウトした場合、
単にタイムアウト値を増やすだけでは、適切な対処にならない可能性があります。
今回のポイントは、タイムアウトを発生させる主体が複数存在することでした。
-
no_output_timeoutはCircleCI側の無出力タイムアウト -
--timeoutはgolangci-lint側の実行時間に関する設定 -
Killedの場合はメモリ不足も疑う -
-vを付けて、処理状況や利用中の設定を確認する - 並列数やCIのリソース、キャッシュも確認する
- タイムアウトの延長だけでなく、遅くなった原因を調査する
CI上では、CircleCI・Lintツール・コンテナ・OSなど、
複数のレイヤーが処理に関わっています。
そのため「タイムアウトした」という結果だけを見るのではなく、
どのレイヤーが、どの条件で処理を終了したのかを切り分けることが重要です!