見出し画像

CircleCIの時間を「さらに」半分にした話

Seiji

こんにちはnote株式会社stabilityチームの小見です。
この記事はnote株式会社 Advent Calendar 2024の2日目の記事です。以前noteでは、CircleCIを14分から6分まで短縮する施策が打たれました。詳細はこちらのGENDOSUさんの記事をご確認ください。

しかし月日は流れ、依存関係の増加・テストの増加により再び11分30秒まで実行時間が伸びておりました。今回は11分30秒から4分30秒まで短縮した、実施内容をまとめて行きます。

※ CircleCIで記載しておりますが、Github Actionsなど他のCIサービスでも同じ事が出来る部分があるため、高速化にお悩みの方にお読みいただけると嬉しいです。


前談

前提条件や調査などを記載しております。実際にやったことが気になる方は実施内容まで飛ばしてお読みください。

前提

実行時間：11分30秒前後（ばらつきが大きい。）
テスト数：23,000ケース前後
環境：CircleCIのDocker実行環境
テストフレームワーク：RSpec
並列方法：CircleCIによる並列コンテナテスト実行および各コンテナ内でparallel_testsによる並列実行
コンテナサイズ：4CPU/8GB RAM

調査

初めに、CI(RSpec)に時間が掛かっており、リリースなどの待ち時間に影響が出ており、これを改善したいというモチベーションがありました。実際に何に時間が掛かっているのか調査を開始しました。

ここで役に立つのがCircleCIのTIMING機能で以下画像の様にどのステップに時間が掛かっているのか一覧表示をしてくれます。

青い棒がRSpecの実行部分です。それ以外がSetupであり、この時間が長いことによってテストコンテナ数を増やしても増やしてもテストの実行時間が短くなりにくくなります。そして現状Setupが4割程度掛かっているため、ここの調査を始めました。赤枠で括ったSpin up environmentが2分近く掛かっておりここの詳細を確認して行きました。

Spin up environment

Spin up environmentのログを眺めていくと以下のように時間のかかる箇所を発見しました。

詳細を確認していくと、1GB近いDockerイメージをSetupしておりこれがダウンロードの速度が安定しないなどで、Setup時間のブレが大きくなっています。

Restoring cache

テスト対象のリポジトリをクローンする時にnoteは10年の歴史が詰め込まれたリポジトリ故に.gitフォルダが肥大化しております。これを単純にダウンロードしてしまうと3.1GB近くの容量を都度都度ダウンロードすることになるため、回避するために今までCircleCIのキャッシュ機能を利用していました。

しかし、3.1GB近くの容量となるとそのリストアだけでも37秒程度掛かってしまい、この方法でも速度に悪影響を及ぼしている状況になっておりました。

RSpec

本丸であるRSpec本体の問題を調査して行きます。

CircleCIのコンテナ並列は実行時間によるテスト内容を分散しています。コンテナ内では、parallel_testsを利用してコンテナ内でCPUの数だけ並列実行をしています。前提知識として頭に入れた後TIMINGやRESOURCEなどを眺めて行きます。

まずは、CPU使用率です。赤枠部分でCPU使用率が下がりダラダラと実行完了まで長引いています。

TIMINGを見ていくとRSpecの実行時間がコンテナごとにバラバラです。

CPU使用率が落ちているところから、コンテナ内のテスト分散が正常に行えず、コンテナ間の実行時間にバラツキが出て全体の実行時間を伸ばしていると予想を立てました。

まとめ

ここまでのまとめとして以下が改善ポイントとして挙げられます。

  • Spin up environmentを改善するために実行コンテナを軽量化する。

  • Restoring cacheを改善するために.gitディレクトリを軽量化する。

  • コンテナ内の並列設定の見直し、全体の実行タイミングを短くする。

実施内容

実行コンテナを軽量化

noteのCI環境は、Docker実行環境を利用しており、これのSetup時間に30〜60秒程度掛かっておりまして、これを8秒前後に改善しました。

※前述の2分近い表示は、MySQLなどのコンテナを含めた時の時間です。

主なポイントとしましては、gemファイルがコンテナ内にインストールされていたり、テストに不要なライブラリが入っていたりと大きいものになっておりました。

実施したこととしては非常に簡単で、CI環境で利用しているコンテナが、開発者向けにキャッシュしていたコンテナでgemファイルや諸々のライブラリが入っていたたため、これらをインストールする前のbaseのDocker Imageに指定することでこの問題は大幅に改善しました。

.gitディレクトリを軽量化

GithubActionsの場合actions/checkoutは直前のコミットだけクローンするため、過去のコミットを取得せず軽量なリポジトリクローンが行われます。

しかしながら、CircleCIのデフォルトコマンドでは、全ての過去コミットも取得するため、クローンの時間が非常に時間がかかります。そのため、クローンをカスタマイズして以下のような設定を行います。内容は以下の記事を参考にさせていただきました。

shallow_checkout:
  steps:
    - run:
      name: Checkout repository
      command: |
        git init
        git remote add origin ${CIRCLE_REPOSITORY_URL}
        GIT_SSH_COMMAND="ssh -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no" git fetch --depth=1 origin ${CIRCLE_SHA1}
        git checkout ${CIRCLE_SHA1}

この設定を行うことで、40秒近く掛かっていたクローンの時間を2秒まで短縮されました。

RSpec並列設定見直し

コンテナ内の並列化は、parallel_testsを利用しているためドキュメントを眺めて行きます。 --runtime-log を設定することで実行時間による並列分散を行なってくれる様です。

しかし、CircleCIの設定を確認すると既に--runtime-logが存在しました。
では何故CPU使用率が途中で低下し実行時間が伸びていたのでしょうか。
さらに詳細を確認にするために--runtime-logで設定されているファイルを確認して行きました。すると以下の様なファイル内容ですが、明らかにテスト数に対してファイル数が足りていませんでした。

Randomized with seed 58637
spec/controllers/hogehuga_controller_spec.rb:39.50255643000037
...

Randomized with seed 58637

全体の設定を見ていくと一つの実行コンテナ内のテスト結果しか格納されていなかったため、全体の1/7(実行台数7台)しか実行結果が存在せず、多くのテストケースにおいて実行時間を取得できていなく並列テストの最適化が行われていないことが推測できました。

解決方法として、全てのテストが完了した後に各コンテナから実行タイミングのファイルを吸い上げてマージしました。
以下例は若干改変しているので動かないかもしれません雰囲気を感じ取ってください。🙇

  rspec:
    ...
      - restore_cache:
          keys:
            - rspec_parallel_runtime-{{ .Branch }}
      - run:
            # restore_cacheで取得した実行タイミングをruntime-logに指定
            bundle exec parallel_rspec -n 4 --verbose --runtime-log test_results/parallel_tests/total_runtime.txt" --verbose --split-by=timings
      # この設定により、post_rspecで実行結果を取得できる様になる。
      - persist_to_workspace:
          root: /home/circleci/hogehuga
          paths:
            # このディレクトリに実行結果が格納されています。
            - test_results/parallel_tests
  post_rspec:
      # rspecで生成された実行結果へattach
      # この設定により、並列実行されていた各コンテナの実行結果を取得できます。
      - attach_workspace:
          at: /home/circleci/hogehuga
      - run:
          name: Merge test results
          command: |
            ls test_results/parallel_tests/*.log 1> /dev/null 2>&1 && cat test_results/parallel_tests/*.log | grep -v "Randomized" | grep -v "All examples" | grep -v "Run options:" | grep -v "^$" | sort -n -t ":" -k 2 > test_results/parallel_tests/total_runtime.txt
      - save_cache:
          key: rspec_parallel_runtime-{{ .Branch }}-{{ checksum "test_results/parallel_tests/total_runtime.txt" }}
          paths:
            # rspecでtest_results/parallel_tests/total_runtime.txtを読み込むことで、実行時間ごとの並列が行われます。
            - test_results/parallel_tests

注意点としては、runtime logをtest_results/parallel_tests/total_runtime.txtとは別で、コンテナ番号をファイル名に入れないとマージする時に名前被りしてしまうためその点はご調整ください。
https://github.com/grosser/parallel_tests?tab=readme-ov-file#rspec

最後に

以上のこと＋細かい対応をして最終的に以下の結果となりました。

実行時間

11分30秒前後
↓
4分30秒前後

補足情報

各コンテナCPUを高い割合で終了できている

Setupの時間が短縮されたことにより、コンテナ台数を増やしても今までよりも実行料金が掛からなくなりました。

▼noteエンジニアアドベントカレンダーはこちら

▼さらにnoteの技術記事が読みたい方はこちら

いいなと思ったら応援しよう！