STORES Product Blog

こだわりを持ったお商売を支える「STORES」のテクノロジー部門のメンバーによるブログです。

CircleCIのslowest tests大改善

こんにちは! STORES でWebエンジニアをしている hsm_hx です。

6月に STORES に中途入社し、ネットショップやレジを中心に機能追加や改善・運用をするチームでバックエンドやフロントエンドの開発を担当しています。


STORES ネットショップの開発チームでは、隔週〜毎月のペースで「大改善デー」という催しを行っています。

この記事では大改善デーについてと、実際にわたしが11月の大改善デーで行ったトライをご紹介したいと思います。



大改善デーとは

STORES ネットショップの開発チームでは、月に1回、開発ラインごとにプロダクト開発から離れて自由な技術課題に取り組む日を設けています。


各自が業務開発をする中で気になっている技術負債や細かいプロダクトの改善など、お題を1人1人自由に設定して朝から夕方まで改善に取り組みます。

1日の終わりには振り返りがあり、各自の行った大改善についてお互いに共有することで普段の開発とはまた違った技術トークで盛り上がったり、日常的なプロダクト開発の合間のリフレッシュとしての役割も果たしています。


例えば、わたしは大改善デーを利用してよく STORES ネットショップのパフォーマンスチューニングに取り組んでいます。

このような大きな課題は日常の業務の隙間時間では取り組みにくく、かつ普段の開発でがっつり使わない筋肉を使い頭がほぐれる感覚があるので個人的にはお気に入りです。

今回の大改善デーでは、遅いテストの速度改善に取り組んでみました。



CircleCIのtest insightsを見てみよう

STORES では自動テストにCircle CIを利用しています。

Circle CIでは、OrganizationやProject、WorkflowごとのInsightsを見ることができます。


以下は STORES ネットショップのサーバーリポジトリで自動テストを行っているWorkflow Insightsページの実例です。

Workflow Insights


さらに、Insightsではテストケースを実行に時間が掛かっている順に確認することができます。

Slowest tests


これらのテストを高速化できれば作業効率向上に繋がりそうです。


TestProfを使ったテストコードの解析

Circle CIのInsightsを見ていると、ブラウザ上の動作をシミュレートして挙動を検証する feature spec が軒並み重そうである当たりがついたので(統合テストだし、それはそうとも言えますね)、

とりあえず手早くできることがないか feature spec で factory.create イベントが呼ばれている数と所要時間を TestProf で解析してみることにしました。


TestProf はRubyのテストを解析するために作られたgemです。

このgemを使うと、遅いテストを炙り出したり、遅いテストが一体何にそこまで時間を使っているのかを明らかにすることができます。

github.com


実際にテストコードを解析していきます。

$ EVENT_PROF='factory.create' bundle exec rspec spec/features

[TEST PROF INFO] EventProf results for factory.create

Total time: 00:30.276 of 05:06.972 (9.86%)
Total events: 1252

Top 5 slowest suites (by time):

elementの表示確認 (./spec/features/path_to_spec.rb:3) – 00:06.649 (312 / 3) of 00:12.821 (51.86%)
...


一番時間の掛かっているテストケースでは、52%の時間を factory.create に使用していました。

このテストケースではある一覧ページの表示を確かめており、ページング時の挙動を確認するために大量のデータを作っていることがわかりました。

当該ページでは1ページあたり32件までのアイテムが表示されますが、このspecでは100件のアイテムデータを作っており、明らかに必要なさそうであることがわかります。


また、実際にプロダクトを確認すると、アイテムが十分数なくても2ページ目としてアイテムが0件のページを表示することはできるので、テストケースの要件を満たすためにアイテムデータを生成する必要はなかったことがわかりました。


さらに、ページの装飾などの不要なデータを削ってみた結果、改善前は312回呼ばれていた factory.create イベントをわずか6回まで減らすことができました 🎉


これが↓

[TEST PROF INFO] EventProf results for factory.create

Total time: 00:07.303 of 00:32.404 (22.54%)
Total events: 312

こう↓

[TEST PROF INFO] EventProf results for factory.create

Total time: 00:00.259 of 00:06.280 (4.13%)
Total events: 6


所要時間も 32.4 [sec] → 6.28[sec] と爆速になっています 🎉


TestProfでは他にも flamegraph 形式でテストから呼び出されているメソッドを解析するなど、様々な使用法で我々にとってイライラの原因ともなるCIの待ち時間を短縮するお手伝いをしてくれます。

残り時間でなにかできないかと唸っていたところ発見したすごいflamegraph


最後に

STORES ネットショップのバックエンドではMongoDBを採用しており、一般に知られている TestProf recipe のようなテストパフォーマンスチューニングに関する知見をそのまま活用できない場合も多くあります。

このような技術的な難しさもありつつ、その上でプロダクトをもりもり開発したり、日頃の開発中に浮かんだ改善案を大改善デーで検討・実装する中には、エンジニアとしてわくわくする種がたくさんあります!


STORES では、これからも継続的にエンジニアがのびのびと開発できる環境で様々な機能追加や改善を進めていきます。

STORES Beer Bash など様々なエンジニア向けイベントも実施しているので、興味を持ってくださった方はぜひ、 STORES のエンジニアとお話に来ていただけるとうれしいです!