まだそこまで遅くはないですが、将来の為にRSpecの実行時間を短くしておきます。
結果、99.93秒だったのが55.72秒となり、44%短縮されました。(想像以上)
RSpecをリファクタリングして可読性と速度を上げる
FactoryBotのcreateやbuild_stubbedを上手くまとめても、結局、SQLが走るのはit毎なので、同じクエリが複数回走る事になります。
test-prof(Ruby Tests Profiling Toolbox)のlet_it_beやbefore_allを使うと、同じクエリが走るのを抑制できます。
インストール
Gemfile
group :test do <省略> + # Use Ruby Tests Profiling Toolbox + gem 'test-prof' end
% bundle install
spec/rails_helper.rb
# Use Ruby Tests Profiling Toolbox require 'test_prof/recipes/rspec/let_it_be' require 'test_prof/recipes/rspec/before_all'
遅いテストを確認(変更前)
% rspec --profile Top 10 slowest examples (1.6 seconds, 1.6% of total time): user user:destroy 3件(削除予約1件、削除対象1件) behaves like [3件]ドライランfalse behaves like 削除件数 ユーザーが1件・お知らせが0件削除される 0.23363 seconds ./spec/lib/tasks/user_spec.rb:32 Users::Auth::Registrations POST #update APIログイン中 behaves like [APIログイン中]有効なパラメータ(変更なし) behaves like ToMsg 対象のメッセージと一致する 0.16228 seconds ./spec/requests/users/auth/registrations_spec.rb:8 Users::Auth::Registrations POST #update APIログイン中 behaves like [APIログイン中]有効なパラメータ(変更あり) behaves like OK 対象項目が変更される。対象のメールが送信される 0.15845 seconds ./spec/requests/users/auth/registrations_spec.rb:343 Users::Auth::Registrations POST #update APIログイン中 behaves like [APIログイン中]有効なパラメータ(変更あり) behaves like ToOK behaves like ToOK(json/json) HTTPステータスが200。対象項目が一致する。認証ヘッダがある 0.15602 seconds ./spec/requests/users/auth/registrations_spec.rb:377 Users::Auth::Registrations POST #update APIログイン中 behaves like [APIログイン中]有効なパラメータ(変更あり) behaves like ToMsg 対象のメッセージと一致する 0.15389 seconds ./spec/requests/users/auth/registrations_spec.rb:8 Users::Auth::Registrations GET #show APIログイン中 behaves like ToOK behaves like ToOK(json/json) HTTPステータスが200。対象項目が一致する。認証ヘッダがある 0.1485 seconds ./spec/requests/users/auth/registrations_spec.rb:233 Users::Registrations PUT #update ログイン中 behaves like [ログイン中]有効なパラメータ(変更あり) behaves like OK 対象項目が変更される。メールが送信される 0.14838 seconds ./spec/requests/users/registrations_spec.rb:168 Users::Auth::Registrations POST #update APIログイン中 behaves like [APIログイン中]有効なパラメータ(変更なし) behaves like ToOK behaves like ToOK(json/json) HTTPステータスが200。対象項目が一致する。認証ヘッダがある 0.14691 seconds ./spec/requests/users/auth/registrations_spec.rb:377 Users::Registrations PUT #update ログイン中(メールアドレス変更中) behaves like [ログイン中]有効なパラメータ(変更あり) behaves like OK 対象項目が変更される。メールが送信される 0.14578 seconds ./spec/requests/users/registrations_spec.rb:168 Users::Auth::Registrations POST #update APIログイン中(削除予約済み) behaves like [削除予約済み]URLがない behaves like ToNG behaves like To406(json/html) behaves like To406 HTTPステータスが406 0.14564 seconds ./spec/support/application_contexts.rb:36 Top 10 slowest example groups: Infomations 0.07971 seconds average (3.99 seconds / 50 examples) ./spec/requests/infomations/important_spec.rb:3 Top 0.07553 seconds average (0.9064 seconds / 12 examples) ./spec/requests/top_spec.rb:3 Users::Registrations 0.06223 seconds average (4.05 seconds / 65 examples) ./spec/requests/users/registrations_spec.rb:3 Infomations 0.05848 seconds average (8.54 seconds / 146 examples) ./spec/requests/infomations/index_spec.rb:3 user 0.05272 seconds average (0.57991 seconds / 11 examples) ./spec/lib/tasks/user_spec.rb:3 Users::Auth::Registrations 0.04691 seconds average (19.23 seconds / 410 examples) ./spec/requests/users/auth/registrations_spec.rb:3 Admin 0.0416 seconds average (0.1664 seconds / 4 examples) ./spec/requests/admin_spec.rb:3 DeviseMailer 0.03127 seconds average (0.15633 seconds / 5 examples) ./spec/mailers/admin_devise_mailer_spec.rb:3 User 0.03108 seconds average (1.18 seconds / 38 examples) ./spec/models/user_spec.rb:3 Infomations 0.02785 seconds average (9.36 seconds / 336 examples) ./spec/requests/infomations/show_spec.rb:3 Finished in 1 minute 39.93 seconds (files took 4.01 seconds to load) 3369 examples, 0 failures
変更してみる(1)
そこまで遅いのは無いですが、一番時間が掛かっているのを直してみます。
spec/lib/tasks/user_spec.rb
describe 'user:destroy' do let(:task) { Rake.application['user:destroy'] } - let!(:user1) { FactoryBot.create(:user) } + let_it_be(:user1) { FactoryBot.create(:user) } - let!(:user2) { FactoryBot.create(:user_destroy_reserved) } + let_it_be(:user2) { FactoryBot.create(:user, :destroy_reserved) } - before do + before_all do FactoryBot.create(:infomation) # :All FactoryBot.create(:infomation, target: :User, user_id: user1.id) FactoryBot.create(:infomation, target: :User, user_id: user2.id) end shared_context 'ユーザー作成3' do - let!(:user3) { FactoryBot.create(:user_destroy_targeted) } + let_it_be(:user3) { FactoryBot.create(:user, :destroy_targeted) } end shared_context 'ユーザー作成4' do - let!(:user4) { FactoryBot.create(:user_destroy_targeted) } + let_it_be(:user4) { FactoryBot.create(:user, :destroy_targeted) } - before do - FactoryBot.create(:infomation, target: :User, user_id: user4.id) - end + before_all { FactoryBot.create(:infomation, target: :User, user_id: user4.id) } end
単純にlet!をlet_it_beに、beforeをbefore_allに置換。
変更前
% rspec spec/lib/tasks/user_spec.rb
...........
Finished in 0.67378 seconds (files took 2.64 seconds to load)
11 examples, 0 failures
変更後
% rspec spec/lib/tasks/user_spec.rb
...........
Finished in 0.43816 seconds (files took 2.68 seconds to load)
11 examples, 0 failures
変更してみる(2)
% rspec spec/lib/tasks/user_spec.rb ........... Finished in 0.43816 seconds (files took 2.68 seconds to load) 11 examples, 0 failures
変更してみる(2)
よく使っているshared_contextを直してみます。
spec/support/user_contexts.rb
shared_context 'ユーザー作成' do |target, use_image| - let(:image) { use_image ? fixture_file_upload(TEST_IMAGE_FILE, TEST_IMAGE_TYPE) : nil } + let_it_be(:image) { use_image ? fixture_file_upload(TEST_IMAGE_FILE, TEST_IMAGE_TYPE) : nil } - let!(:user) { FactoryBot.create(target, image: image) } + let_it_be(:user) { FactoryBot.create(target, image: image) } - include_context '画像削除処理' if use_image end - - shared_context '画像削除処理' do - after do - user.remove_image! - user.save! - end - end
let_it_beで使用している値(image)をletで作ると怒られるので、let_it_beに変更。
afterでの処理
afterでlet_it_beの値を使うのも怒られるので、画像削除処理(remove_image!)は削除。
画像は/tmpに保存していますが、ゴミが暫く残るので、rake_helperでテスト後にディレクトリ毎削除する事にしました。(危ないので、/tmpに設定されているかも確認してから実施)
毎回削除するよりも早くなるし、途中で落ちてもその後のテストで削除できる。
但し、ファイル指定で実行した場合は消えなかった。
spec/rake_helper.rb
# ImageUploaderで作成したファイルをディレクトリごと削除 config.after(:suite) do store_dir = User.new.image.store_dir if store_dir.start_with?('/tmp/') FileUtils.rm_r(store_dir, secure: true) else p "[Skip]rm -f #{store_dir}" end end
状態が変わった時に影響を受ける
let_it_beで作成したモデルの値が先行のテスト(it)で変わった場合(モデル内でインスタンス変数持っている場合も)、次のテスト(it)では初期化されないので、落ちてしまう。
spec/requests/users/registrations_spec.rb
context 'ログイン中' do include_context 'ログイン処理' it_behaves_like 'OK' it_behaves_like 'ToLogin', nil, 'devise.registrations.destroy_reserved' end
冗長ですが、contextやshared_examples_forを分けてあげればOK。
context 'ログイン中' do include_context 'ログイン処理' it_behaves_like 'OK' end context 'ログイン中' do # Tips: 上記と一緒にすると変更の影響を受ける為(let_it_beに変更後) include_context 'ログイン処理' it_behaves_like 'ToLogin', nil, 'devise.registrations.destroy_reserved' end
変更しても意味がないケース
FactoryBotのcreateやbuild_stubbedが同じ値で複数回走るケースじゃないとそもそも意味がない。
下記はshared_contextにすれば、let_it_beに変更可能ですが、nameが毎回違う。
spec/models/user_spec.rb
describe 'validates :name' do let(:user) { FactoryBot.build_stubbed(:user, name: name) } # テストケース context 'ない' do let(:name) { nil } it_behaves_like 'InValid' end context '最小文字数よりも少ない' do let(:name) { 'a' * (Settings['user_name_minimum'] - 1) } it_behaves_like 'InValid' end
let!を根絶できるか?
できそうだけど、速度に全く貢献しないケースも存在する。
私の手元で残ったのは下記のようなTime.currentを取得しているケース。
itの中で変数にしてしまっても良いのだけれど、そのままの方が解りやすいので残しています。
複数回呼ばれるように外に置いても動くけど、短時間とは言え、betweenが広くなるのと、定義が遠くなるのと。
spec/models/user_spec.rb
context '削除依頼日時' do let!(:start_time) { Time.current.floor } it '現在日時に変更される' do is_expected.to eq(true) expect(user.destroy_requested_at).to be_between(start_time, Time.current) end end
遅いテストを確認(変更後)
% rspec --profile Top 10 slowest examples (1.07 seconds, 1.9% of total time): user user:destroy 3件(削除予約1件、削除対象1件) behaves like [3件]ドライランfalse behaves like 削除件数 ユーザーが1件・お知らせが0件削除される 0.19967 seconds ./spec/lib/tasks/user_spec.rb:30 Users::Auth::Registrations POST #image_update APIログイン中 behaves like [APIログイン中]有効なパラメータ behaves like ToMsg 対象のメッセージと一致する 0.11833 seconds ./spec/requests/users/auth/registrations_spec.rb:8 Users::Auth::Registrations POST #image_update APIログイン中 behaves like [APIログイン中]有効なパラメータ behaves like ToOK behaves like ToOK(json/json) HTTPステータスが200。対象項目が一致する。認証ヘッダがある 0.11135 seconds ./spec/requests/users/auth/registrations_spec.rb:628 Users::Registrations POST #image_update ログイン中 behaves like [ログイン中]有効なパラメータ behaves like OK 画像が変更される 0.11079 seconds ./spec/requests/users/registrations_spec.rb:282 Users::Auth::Registrations POST #image_update APIログイン中 behaves like [APIログイン中]有効なパラメータ behaves like OK 画像が変更される 0.1105 seconds ./spec/requests/users/auth/registrations_spec.rb:611 Users::Registrations POST #image_update ログイン中 behaves like [ログイン中]有効なパラメータ behaves like ToEdit 登録情報変更にリダイレクトする 0.10967 seconds ./spec/requests/users/registrations_spec.rb:31 Admin GET rails_admin ログイン中(管理者) behaves like ToOK HTTPステータスが200 0.09601 seconds ./spec/requests/admin_spec.rb:14 Infomations GET #show ログイン中 behaves like [*]対象が他人 behaves like [*][他人]開始日時が過去 behaves like [*][他人][過去]終了日時が過去 behaves like ToNot behaves like To404(html/html) behaves like To404 HTTPステータスが404 0.07841 seconds ./spec/support/application_contexts.rb:19 Users::Auth::Passwords POST #update ログイン中 behaves like [未ログイン/ログイン中]トークンが期限内(未ロック) behaves like [未ログイン/ログイン中][期限内]有効なパラメータ behaves like ToOK behaves like To406(html/json) behaves like To406 HTTPステータスが406 0.07677 seconds ./spec/support/application_contexts.rb:36 AdminUsers::Passwords POST #create ログイン中 behaves like [ログイン中]有効なパラメータ(未ロック) behaves like ToAdmin RailsAdminにリダイレクトする 0.05382 seconds ./spec/requests/admin_users/passwords_spec.rb:17 Top 10 slowest example groups: Admin 0.04478 seconds average (0.17911 seconds / 4 examples) ./spec/requests/admin_spec.rb:3 Top 0.03936 seconds average (0.47227 seconds / 12 examples) ./spec/requests/top_spec.rb:3 user 0.03533 seconds average (0.38867 seconds / 11 examples) ./spec/lib/tasks/user_spec.rb:3 Users::Registrations 0.03177 seconds average (2.06 seconds / 65 examples) ./spec/requests/users/registrations_spec.rb:3 Infomations 0.03164 seconds average (1.58 seconds / 50 examples) ./spec/requests/infomations/important_spec.rb:3 DeviseMailer 0.02619 seconds average (0.13093 seconds / 5 examples) ./spec/mailers/admin_devise_mailer_spec.rb:3 Infomations 0.02596 seconds average (3.79 seconds / 146 examples) ./spec/requests/infomations/index_spec.rb:3 AdminUsers::Sessions 0.01997 seconds average (0.63914 seconds / 32 examples) ./spec/requests/admin_users/sessions_spec.rb:3 AdminUsers::Passwords 0.01969 seconds average (1.1 seconds / 56 examples) ./spec/requests/admin_users/passwords_spec.rb:3 Users::Passwords 0.01944 seconds average (1.63 seconds / 84 examples) ./spec/requests/users/passwords_spec.rb:3 Finished in 55.72 seconds (files took 4.14 seconds to load) 3369 examples, 0 failures
99.93秒だったのが55.72秒となり、44%短縮されました。
まとめ
変更検討対象は、FactoryBotのcreateやbuild_stubbed、または時間が掛かるけど結果が変わらないものだけで良さそう。
let!をlet_it_beに、beforeをbefore_allに置換すれば大体の所は動く。
但し、使っている値もlet_it_beに変更してあげる必要がある。
全部を置き換えるよりも、挙動の違いを把握して、必要な所だけ使うのが良さそう。
今回のコミット内容
※序でにtraitに変更。複数組み合わせて使えるので良いですね!
https://dev.azure.com/nightonly/rails-app-origin/_git/rails-app-origin/commit/6ea9b4f2773fedbd7aefb58c09bda4e3ec16efc9