1
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

CircleCIでgolangci-lintがタイムアウトして動かなくなった話

1
Posted at

はじめに

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側の無出力タイムアウト
  • --timeoutgolangci-lint側の実行時間に関する設定
  • Killedの場合はメモリ不足も疑う
  • -vを付けて、処理状況や利用中の設定を確認する
  • 並列数やCIのリソース、キャッシュも確認する
  • タイムアウトの延長だけでなく、遅くなった原因を調査する

CI上では、CircleCI・Lintツール・コンテナ・OSなど、
複数のレイヤーが処理に関わっています。

そのため「タイムアウトした」という結果だけを見るのではなく、
どのレイヤーが、どの条件で処理を終了したのかを切り分けることが重要です!

参考資料

1
1
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
1
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?