Rails: 時間との戦い -- テストを5倍高速化するツールと手順（翻訳）
はじめに
遅いテストはどんなプロジェクトでもつらいものですが、大規模に運用されているエンタープライズレベルのプロジェクトではなおさらです。テストが遅いと、CIの遅れやデプロイの遅れにつながるのはもちろん、開発エクスペリエンスがひたすら退屈なものになってしまう可能性もあります。
Evil Martiansは、最近あるお客様のCIパイプライン最適化、コードのテストや変更の高速化を支援し、最終的に5倍の高速化を達成しました。本記事では、これを支えるいくつかのテクニックやツールについて解説します。きっと皆さんも同じことをしたくなること請け合いです！
最初に、私たちのお客様の背景情報について少し説明いたします。Power Home Remodeling（"POWER"）は全米最大の住宅外装改修企業であり、窓・サイディング・屋根・ドア・屋根裏断熱材・ソーラーパネルなどの外装改修を専門としています。社内・社外ともに同社の水準の高さは明らかでしたので、私たちは同社の見事な仕事ぶりにふさわしい支援を提供いたしました。
また同社は、「米国で最も働きがいのある職場」の意味も改革しています。Fortune誌の「働きがいのある企業トップ100」リストで第14位、People誌の「思いやりのある企業」、Computerworld誌の「IT業界で最も働きがいのある職場」にランクインしています。
技術的には、当プロジェクトはRuby on Rails上に構築されており、数十ものコンポーネントを擁するコンポーネントベースのアーキテクチャ設計（またの名をモジュラーモノリス）に沿っています。
🔗 私たちが行った最適化の概要
私たちは、RSpecのハック、これまで培ってきたプロファイリング技術（Stackprofなどを利用）、そして私たちが開発したTestProfツールキットを組み合わせることで、このパフォーマンス向上を実現しました。
最初に、Stackprofを用いてテストスイート全体の予備調査を実施しました。予備調査は、factory、ログ出力、API呼び出しなどの改善すべき一般事項を特定するうえで役立ちました。
続いて一般的な最適化を実施し、それが終わってから、ローカルテストの最適化（特定のテストファイルの分析やリファクタリングなど）を行いました。
全般的な結果としては、3件のプルリクを送信（およびマージ）し、どのプルリクもテストスイートの改善をそれぞれ異なるレベルで達成しました。本記事では、ここで行った3つの最適化マイルストーンについて解説します。
テストの最適化で重要な3つの心構え
背景については以上ですが、詳しい話に入る前にもう少しだけ補足させてください。
テストの最適化に取り組む前に、改善作業を実りあるものにするうえで欠かせない3つのマインドセットを理解しておくことが重要です。このマインドセットは以下の3つの柱に基づいています。
- 最適化する価値が最も高い場所を見極めること
たとえば、全テストで共通で用いられるユーザーfactoryを最適化する方が、めったに使われず変更もされないmonthly_report_spec.rbファイル1個を最適化するよりずっと大きな価値を得られます。 -
楽に達成できる最適化を見つけること、そして最適化をやりすぎないこと
自分の手法にこだわりすぎないよう注意してください。テストのパフォーマンスを1秒改善するのに4時間もかかるのであれば、作業の優先順位を見直す必要があります。 -
タイミングを必ず測定すること
常に最適化前と最適化後のタイミングを比較しましょう。テスト時間が驚くほど長くなるのであれば、望ましくありません。
🔗 状況を把握する
最初に、概要を明確に把握してボトルネックを特定するために、さまざまな測定結果をチェックする必要がありました。このときの測定項目はおおよそ次のとおりでした。
- テスト時間の総計
- コールスタック内で最も遅いメソッド
- 最も利用頻度の高い（および最も遅い）factory
🔗 ツールのセットアップ
最初にインストールと設定を行ったのはStackprofとTestProfでした。
StackProfはRuby用のコールスタックプロファイラで、TestProfは、テストのプロファイリングや最適化を行う高度なツールボックスです（繰り返しますが、TestProfを作ったのはEvil Martiansです）。
ここで皆さんに、測定値をしばらく覚えておいていただきたいと思います。当初のテストスイートの実行時間は53分でした。
さて、ここで問題です、この数値を私たちがどこまで短縮できたか当ててみてください。答えについてはこのままお読みください（驚くかもしれません）。
StackProfで収集したコールスタックを詳しく調べて、「なぜこんなに遅いのか」という理由を大づかみしてみましょう。なお、これは遅いテストスイートを扱うときに最初に行うべき作業です。
🔗 コールスタックの結果から学んだこと
アプリケーションのコールスタックを読むときは、コールスタックをフレームグラフとして描画するのがベストです。これは、TEST_STACK_PROF=1 SAMPLE=1000 bin/rspecの実行結果をSpeedscopeに読み込むことで行えます。Speedscopeは、Stackprofなど（Ruby以外も含む）さまざまなプロファイラをサポートしているフレームグラフビューアです。
フレームグラフをマスターするには多少時間はかかりますが、Speedscopeの「Sandwich」ビューですぐに手がかりを得られます。私たちの場合は、Active Recordの怪しいコールバックをいくつか特定できました。
History#auto_add_history
NitroSearch::Elastic::Indexing
コールスタックのフレームグラフで見た
#auto_add_history
この他に、Active Recordの低レベルな呼び出し（#exec_prepareなど）やfactory関連の呼び出し（FactoryBot#create）も多数見当たりました。
それでは、TestProfのFactoryProf profilerでfactoryをもっと詳しく見てみましょう。
🔗 factoryをFactoryProfで分析する
FactoryProfを使うことで、どのfactoryの利用頻度および消費時間が最も大きいかを調べられます。私たちの場合、テスト時間に最も影響していたのはproject factoryとestimatefactoryでした。
フレームグラフ風の非常に便利なfactory用プロファイラ（FPROF=flamegraph bin/rspec）を使えば、factoryカスケードをあぶり出すこともできます。
最適化前のFactoryFlame
上のフレームグラフでfactoryカスケードを1つ見てみると、create(:candidate_interview)を呼び出すたびに、依存するレコードが大量に作成されていることがわかります。
ここから、これらのfactoryカスケードは、project factoryとestimatefactoryが繰り返し作成されていたのが原因であることもわかります。
最初は、このプロファイリング情報を手がかりにして、最適化パッチを1つずつ適用しました。
🔗 プルリク1: 一般的な最適化
私たちは、テスト実行中にいくつものActive Recordコールバック（例: History#auto_add_history）が頻繁に呼び出されていることに気づきました。しかし、これに対応する副作用を必要とするテストは、全体の約1%しかありませんでした。つまり、テストではこれらのコールバックをデフォルトで無効にしておき、必要な場合にのみ有効にすれば、テスト時間を短縮できます。
そのために、テスト容易性（testability）パターンを適用しました。具体的には、対象となる機能に、テストでのコールバック呼び出しを制御する特殊なTestingモジュールを追加したのです。
# models/history.rb
module Testing
class << self
def fake? = @fake
def fake! = @fake = true
def real! = @fake = false
end
# ...
def auto_add_history
return if History::Testing.fake?
# ...
end
end
ここでは、多くのRuby開発者が慣れ親しんでいるSidekiq::Testingインターフェイスに沿っています。これで、rails_helper.rbファイルで以下を実行できるようになりました。
# spec/rails_helper.rb
# ...
History::Testing.fake!
RSpec.configure do |config|
config.before(:each) do |example|
if example.metadata[:auto_history] == true
History::Testing.real!
else
History::Testing.fake!
end
end
end
ここではRSpecのタグ付け機能を用いて、コールバックの振る舞いを条件に応じて切り替えています。自動履歴機能に依存する機能をテストする必要が生じたら、対応するテストのexampleにいつでも:auto_historyを追加できます。
# spec/models/history_spec.rb
describe History do
let(:fp) { create(:finance_project) }
it "automatically record history on creation", :auto_history do
h = fp.histories.last
expect(h.owner_changes["roofing_sold"]).to eq([nil, true])
expect(h.activity).to eq("Created the Finance Project")
end
# ...
end
NitroSearch::Elastic::Indexingモジュールにも同様の手法を適用した結果、テスト時間の総計は53分から33分に短縮されました。しかも、これはほんの序の口です。
🔗 プルリク2: factoryの最適化
FactoryProfのレポートから、project factoryとestimatefactoryが最も遅いことは既に判明しています。そこでソースコードを調べたところ、ある共通点が見つかったのです。つまり、どちらもデフォルトでhome関連付けとowner関連付けを作成していたのです。
factory :estimate do
# ...
home
association :owner, factory: :user
end
こういうものを見つけたらどうすればよいでしょうか？関連付けをコメントアウトして、テストがいくつ失敗するかを見てみましょう。
私たちの場合、失敗の件数はそれほど多くありませんでした（数千件のテストのうち約50件）ので、関連付けの作成を、対応するtraitに移動して、必要に応じて使うことにしました。
factory :estimate do
# ...
trait :with_home do
home
end
trait :with_owner do
association :owner, factory: :user
end
end
不要な関連付けを除去した後のfactoryのフレームグラフは次のようになりました。スタックは大幅に減少していますね（ついでに全体のテスト時間はさらに15%ほど削減されました）。
最適化後のFactoryFlame
🔗 nitro_userをfixtureに置き換える
さらに、ほぼすべてのテストで、デフォルトのユーザーが作成されている（User.current）ことも判明しました。テストでは、User.current || create(:nitro_user)という一つ覚えの書き方が多用されていることがわかりました。ユーザーを作成するたびに、ユーザーに関連するいくつかのfactoryも作成しなければならなくなるため、factoryの再作成によるオーバーヘッドがかなり目立っていました。
そこで、TestProfのAnyFixtureツールを利用して、デフォルトのユーザー作成をfixtureに移行することにしました。
# spec/nitro_user.rb
require "test_prof/recipes/rspec/any_fixture"
using TestProf::AnyFixture::DSL
RSpec.shared_context "fixture:nitro_user" do
let(:nitro_user) { fixture(:nitro_user) }
end
RSpec.configure do |config|
# テスト全体を実行するためにNitroユーザーを作成する
config.before(:suite) do
fixture(:nitro_user) { FactoryBot.create(:nitro_user) }
end
config.include_context "fixture:nitro_user"
end
fixtureを導入した後で、テストにある明示的なUser.currentの作成をすべて削除しました。パフォーマンスをさらに向上させるためです。
🔗 データベースのステートとクリーンアップ
nitro_user fixtureを導入している最中に、トランザクショナルfixtureが使われているにもかかわらず、テスト実行後のデータベースが完全な状態になっていないことに気づきました。
取り急ぎ調べてみた結果、テストでbefore(:all)がいくつか使われているのが見つかったので、TestProfのbefore_allに置き換えました。このbefore_allは、元のRSpecフックのトランザクショナル版です。
さらに、データベースのステートをリセットするのに便利な（条件付き）フックも導入しました。これにより、修正前のブランチで作業している開発者たちがグローバルステートの問題を手軽に修正できます。
RSpec.configure do |config|
config.prepend_before(:suite) do
# 全テーブルを捨ててクリーンな状態から開始できるようにする
ActiveRecord::Tasks::DatabaseTasks.truncate_all if ENV["CLEAN_DB"]
end
end
ここではサードパーティのデータベースクリーナーを使わず、Active Recordの機能だけで行っている点にご注目ください。
プルリク2で最終的にテスト実行時間を21分に短縮できました（当初は53分だったのがプルリク1で33分に短縮されていましたよね）。
しかしこれで満足する私たちではありません。さらに細かな最適化を推し進めました。
🔗 プルリク3: 特定のテストファイルを最適化する
TestProfの目玉機能のひとつであるbefore_allは既にプルリク2で紹介しましたが、真の力を秘めているのは、before_allの兄弟であるlet_it_beです。
let_it_beヘルパーの使い勝手はlet!と同じですが、パフォーマンスが段違いです。一度作成したデータは、そのファイル内（またはRSpecコンテキスト内）の全テストで再利用されます。つまり、let_it_beは一種のローカルfixtureと見なせるのです。
let_it_beへの移行作業は、必ず1ファイル単位で行わなければなりません。この移行をどのファイルから開始すべきかは、どうすれば見分けられるでしょうか？
TestProfには、そのためのRSpecDissectという特殊なプロファイラを提供しています。RSpecDissectは、let/let!宣言やbefore(:each)宣言がどのぐらいテストで時間を使っているかを表示してくれます。
Top 10 slowest suites (by `let` time):
HiringRequisition (./spec/models/hiring_requisition_spec.rb:5) -- 00:04.126 (378 / 59) of 00:05.019 (82.21%)
...
以下のサンプルレポートを見ると、spec/models/hiring_requisition_spec.rbファイルのテスト実行時間の約半分がlet式で占められています。私たちのリファクタリング方法をご覧ください。
...しかし私たちはリファクタリングの前には、必ずFactoryProfツールを実行するようにしています。それによって、factoryプロファイルをキャプチャする形でテストファイルの現在のステートを記録しています。最初にキャプチャした統計は以下のとおりです。
$ FPROF=1 rspec spec/models/hiring_requisition_spec.rb
Total time: 00:03.368 (out of 00:07.064)
name total top-level total time
user 237 109 3.8929s
office_location 86 41 2.3305s
...
この情報から得られる知見について事細かに述べる代わりに、私たちがテストをどのようにリファクタリングしたかを以下に示します。
- let(:office_location) { create(:office_location, territory: create(:territory)) }
+ let_it_be(:default_user) { create_default(:user) }
+ let_it_be(:office_location) { create(:office_location, territory: create(:territory)) }
何が変更されたかおわかりですか？
letをlet_it_beに置き換えることで、office_locationレコードがそのファイル全体で1回だけ作成されるようにしています。- さらに、
create_default最適化も適用しています。
これは、factoryで生成された全オブジェクト（これらはuser関連付けを必要とします）でユーザーレコードを再利用可能にします。
変更の効果を測定するためにFactoryProfを再実行すると、以下の結果が得られました。
FPROF=1 rspec spec/models/hiring_requisition_spec.rb
Total time: 00:01.039 (out of 00:04.341)
name total top-level total time
office_location 11 11 0.1609s
...
ご覧の通り、合計時間は3秒（約50%）も短縮され、factoryが占める時間も3秒から1秒に短縮されました。単一ファイルの変更としてはまずまずの結果です。
私たちはこの調子で、他のファイルについてもlet_it_be や create_defaultのリファクタリング適用を繰り返しました。そうして数十ファイル（数百ファイル中）に対してリファクタリングを行った結果、テスト実行時間は11分という満足のいく結果に達しました。
まとめると、私たちが3つの最適化手順に取り組んだことで、わずか2週間でテストが約5倍（53分→11分）高速化されました。
皆さんはどう思いましたか？遅いテストのサポートが必要でしたらお気軽にお問い合わせください！
概要
元サイトの許諾を得て翻訳・公開いたします。
日本語タイトルは内容に即したものにしました。