はじめに
こんにちは、クラスター株式会社でソフトウェアエンジニアをやっている
id:shiba_yu36です。
クラスターではGoの自動テストをCircleCIで実行しています。入社して以降、この自動テストの実行時間が少し長いと感じたため、調査と改善を進めてきました。結果として速度を改善できたので、この記事でGoの自動テスト高速化のための調査と改善手法について共有したいと思います。
- はじめに
- Goの自動テストで課題だったこと
- 最終的な結果
- 自動テスト高速化の流れ
- テスト実行時間のボトルネックを調査する
- 高速化でやるべきことを決定する
- 1つずつ改善し結果を計測する
- 最終的な結果のまとめ
- おわりに
Goの自動テストで課題だったこと
クラスターではGoの自動テストは全てのPullRequestで実行し、自動テストが通らないとマージしてはいけないというルールになっています。その時の自動テストの実行時間がそろそろ10分を超えそうになっていました。
これまでの自分の経験上、10分を超え始めると「テストの実行が遅いな」と感じることが多かったです。またテスト実行時間の長さは、PullRequestマージまでの時間やリリース実行時間に大きく影響を与え、結果として開発生産性の重要な指標である変更のリードタイムとサービス復元時間に悪影響を与えてしまいます。
さらにサービス拡大/組織拡大に伴って、自動テストの数もかなりの勢いで増えていました。そのため今後もテスト実行時間が伸び続けると予想していました。
以上の理由から、開発生産性を維持するためにもテスト実行を高速に保ちたいと考えました。しかし自分は、テスト実行時間を速めるためにテストの書き方を工夫したり必要最低限のテストのみに制限したりといった対策はやりたくありませんでした。なぜならテスト自体を工夫しなければならないと開発に余計な時間がかかりますし、また必要最低限のテストに留めると品質水準を損なう危険があるためです。
そこでできる限りテストの実行の仕方の工夫だけで、自動テストの実行時間を減らしたいと考えました。
最終的な結果
調査手法や改善手法を書く前に最終的な結果をまとめておきます。
- PullRequestごとのテスト実行時間が、9〜10分ほどから、5〜6分ほどに改善した
- テスト並列化により、テストが増えても実行時間が伸びにくくなった
- 今回の改善による影響だけではないが、リリース開始〜終了までの時間を15分ほど短縮した
自動テスト高速化の流れ
テスト実行を高速にするためにはボトルネックの明確化と、効果を計測した上での改善が必要です。そのためにボトルネックを調査する -> 高速化でやるべきことを決定する -> 1つずつ改善し結果を計測するという手順を踏むとスムーズに行くことが多いです。そこでまずはボトルネックの調査を始めました。
テスト実行時間のボトルネックを調査する
最初は大まかなボトルネックを探し、その次に気になった部分だけ詳細に調べるという流れでボトルネックを調査します。
CircleCIのTIMINGタブで大まかなボトルネックを調査する
CircleCIにはジョブの実行結果の画面にTIMINGタブというものがあり、そこを見ることで大まかなボトルネックをすぐに知ることができます。
これを見ると実行時間が多いステップは次の3つでした。
- Spin up environment: 30秒
- go generate: 2分
- make test: 6分15秒
まずSpin up environmentはCircleCIの実行コンテナが立ち上がるまでの時間なため、ある程度どうしようもありません。
次にgo generateについてです。クラスターではgo generateの結果が何らかの理由でランダムに変わってしまう問題に対処できておらず、レポジトリにgo generateの成果物をcommitできていませんでした。そのため自動テストの実行時に毎回go generateをする必要があり、コード量が多くなるにつれ、この実行時間も伸びていました。もしランダムに変わる部分を無くしてcommitできれば、最低でも2分は実行時間を短縮できそうです。
最後にmake testです。make testは実際のテストの実行で、今のところ並列化せずに実行していました。そのため並列化をすれば実行時間が短縮できそうです。一方手元開発環境での自動テストの実行時間を見ているとここまで時間はかかっておらず、実行時間に違和感がありました。
この違和感を解消するため、さらにmake testのボトルネックについて調査を続けました。
make testのボトルネックを調査する
まずCircleCIのRESOURCESタブで見たところ、make test開始から2分程度CPUが100%に張り付いていた後、その後は70%程度の推移で実行されていることが分かりました。
TIMINGタブとRESOURCESタブの2つの結果から、最初のCPUが100%に張り付いている部分はテストの実行はしておらず、後半のCPU利用率が70%程度の部分でだけテストが実行されているのではないかという仮説を立てました。さらに前半部でやっていることとしてGoでのコンパイルが思ったより時間がかかっているのではないかと思い当たりました。
そこでテストのコンパイルだけにどの程度時間がかかっているかを調査しました。go test -list . ./... をするとコンパイルだけを行うことができるので、これを自動テストのジョブ上で実行し時間を計測しました。結果、この実行時間が2分ほどかかっており、やはりコンパイル時間に思ったより時間がかかっていることが分かりました。
さらに調査を進めるとクラスターのCircleCIの設定では自動テスト上ではGoのビルドキャッシュをまったく使っていないことが分かりました。そのためビルドキャッシュを使えばより高速に実行できそうです。
高速化でやるべきことを決定する
さてここまででボトルネックが調査できました。9〜10分ほどの自動テスト実行時間の中のボトルネックの大まかな割合と改善できるポイントをまとめると次のとおりです。
- go generate: 2分
- 改善策: go generateの成果物をレポジトリにcommitし自動テスト上では実行しない
- make testの中のコンパイル時間: 2分
- 改善策: ビルドキャッシュを用いて高速化する
- make testの中のテストの実行時間: 4分半
- 改善策: テストの並列化によって高速化する
1つずつ改善し結果を計測する
ここまでで改善策をいくつか作れました。これらを1つずつ実施し、その結果を計測し、実際に適用するかを決定します。
go generateの成果物をレポジトリにcommitし自動テスト上では実行しない: 2分短縮
まずはgo generateの成果物をレポジトリにcommitし、自動テスト上ではgo generateを実行しないような改善を加えました。そのためにランダムに変わる部分を直す必要があります。
ランダムに直す部分は正直地道に原因を探って1つずつ問題を解決するというやり方しかなく、かつ他社に参考になるような情報は無さそうだったため、今回の記事では割愛します。クラスターで使っているフレームワークのgeneratorの使い方によってはランダムに変わるケースがあったというのが原因でした。
1つだけTipsがあるとすれば、go generateの成果物に環境依存でdiffが出ないかをCI上でチェックすることです。go generateの結果を各開発者にcommitしてもらうことになるため、環境差で成果物にdiffが出ると困ります。そのため以下のようなジョブを作り、PullRequestごとにチェックするようにしています。
jobs: # go generateの結果にdiffが出ないか検証する check_gen: steps: # 事前にcheckoutや依存モジュールのインストールをしておく ... # Makefileにgo generateしているディレクトリを全て消すタスクを作り実行する - run: make clean_gen # go generateする - run: go generate ./... # new fileに対応するためにgit add -Nをしてからdiffがないか確認する - run: git add -N . && git diff --exit-code
この改善により、自動テスト中にgo generateをする必要がまったく無くなり、テスト実行時間が2分短縮できました。
ビルドキャッシュを用いて高速化する: 改善ならず
続いてビルドキャッシュを用いてコンパイルの高速化を試みます。CircleCIの場合save_cache/restore_cacheを用いることでビルドキャッシュを保持できます。たとえば次のようなジョブを作り、ビルドキャッシュを使った場合の時間短縮効果を計測しました。
jobs: test_compile: steps: ... # ビルドキャッシュをrestoreしてから - restore_cache: keys: - build-cache-{{ .Branch }}- paths: /root/.cache/go-build # このコマンドを入れておくことで、何が再コンパイルされる予定かを出力できる - run: go list -f '{{if .Stale}}{{.ImportPath}}:{{.StaleReason}}{{end}}' ./... # テストのコンパイルを行う。-xオプションを付けることで実行したコマンドをSTDERRに出力でき、実際にコンパイルが行われたpackage名を調査可能になる - run: go test -x -list . ./... 2> command-log.txt # コンパイル後のビルドキャッシュを再度保持する - save_cache: key: build-cache-{{ .Branch }}-{{ .Revision }} paths: /root/.cache/go-build # コマンド実行ログを保持しておく - store_artifacts: path: ./testlog
この時go test -x -list . ./...の部分の実行時間を計測し、コンパイル時間の変化を観察すると
- ビルドキャッシュをまったく使わないケース: 2分半
- 変更を全く行わずビルドキャッシュを完全に使えたケース: 15秒
- controller部分など、他からの依存がほとんどない表面部分だけ変更したケース: 50秒
- 依存関係が少なめなドメインロジックを変更したケース: 1分半
- 依存関係が多めなドメインロジックを変更したケース: 2分
またビルドキャッシュを使うためにはCircleCIのsave_cache/restore_cacheを使う必要があるのですが、save_cacheに30秒程度、restore_cacheに10秒程度かかる事が分かりました。Goのビルドキャッシュは容量が大きくなる傾向にある（今回のレポジトリでは1GBを超えていました）ので、思った以上に時間がかかるようです。
以上からビルドキャッシュを使うと高速になるケースはありましたが、想定よりは速くならなかったことやその仕組みを入れることによる複雑さの向上と釣り合わないと判断し、仕組みを入れないことに決めました。
テストの並列化によって高速化する: 2分〜2分半短縮
最後にテスト並列化による改善です。Goはデフォルトでpackageレベルの並列化が行われていますが、さらに高速にするには2つの手法が考えられます。
- CircleCIの並列実行を用いる
- 参考: https://circleci.com/docs/parallelism-faster-jobs/
- 便利なツールとしてgotesplitが存在する
- メリット: テストの書き方を変更することなく実行時間を短縮できる。CPUコア数よりコンテナ数の方が増やしやすいのでスケールしやすい
- デメリット: コンパイル時間などテスト実行の前に必要な作業が無駄なオーバーヘッドとなる
- Goのt.Parallelを用いる
- 参考: https://engineering.mercari.com/blog/entry/how_to_use_t_parallel/
- メリット: コンパイル時間などの無駄なオーバーヘッドが起こりにくい
- デメリット: テストの書き方自体に工夫が必要
今回はテストの書き方を変えずに実行時間を短縮しやすい前者の手法を取ることにしました。変更点としてはCircleCIの設定ファイルのjobのparallelismの値を変更した上で、gotesplitを使ったテスト実行にするだけです。下記設定では4並列でテストコンテナを動かし、gotesplitによって自動でテスト分割されて実行されています。
jobs: test: parallelism: 4 steps: # 事前にcheckoutや依存モジュールのインストールをしておく ... - run: go install github.com/Songmu/gotesplit/cmd/gotesplit@latest - run: gotesplit -junit-dir=build/test-results ./... - store_test_results: path: build/test-results
この設定により、make testの中のテストの実行時間が4分半だったところを2分〜2分半程度と2分強程度短縮できました。またテスト実行を並列化したため、今後テストが増えたとしても実行時間が伸びにくい状況を作れました。
もちろんCircleCIレベルでの並列化と同時にt.Parallelによる高速化も行えるため、必要に応じてt.Parallelによる高速化を検討すると良いでしょう。
最終的な結果のまとめ
以上の改善で、PullRequestごとの実行時間が9〜10分ほどだったのが5〜6分ほどに改善しました。さらにテスト並列化により今後テストが増えていっても実行時間が伸びにくい状況を作り出せました。
また現在のクラスターでは、リリース時のテストでは-race付きでテストをしていること、リリース時に自動テストが2回走ってしまっている1ことも影響し、今回の自動テスト実行時間改善の効果が大きかったです。今回の改善だけの結果ではないですが、リリース開始〜終了までの時間を15分ほど短縮しました。
最初に述べたとおり、自動テストの実行時間は変更のリードタイムとサービス復元時間に大きな影響を与えます。サービス復元時間についてはリリース実行時間の短縮分がそのまま減るため、15分ほど短縮できました。変更のリードタイムについてはまだ正確には計測できていませんが、今回の変更によって改善されると良いなと考えています。
おわりに
今回は、Goの自動テスト高速化のため、どのような調査をしどのような改善を加えたかについてまとめました。Goの自動テストの速度改善に悩んでいる人の参考になれば幸いです。
クラスター社では、機能開発だけでなく、このような開発改善も盛んに行われています。この記事を読んで興味が湧いた方は、ぜひ下記リンクからご応募ください。
- これは別途改善を予定しています↩
