[Paris.rb 2018] 99 problems of slow tests

[Paris.rb 2018] 99 problems of slow tests

52cc8a838bf44a589d2572833b2dd1b9?s=128

Vlad Dem

June 29, 2018
Tweet

Transcript

  1. 1.

    TestProf Vladimir Dementyev I GOT 99 PROBLEMS BUT MY TEST

    AIN’T ONE 99 problems of slow tests
  2. 10.
  3. 11.

    palkan_tula palkan fountain.com 11 3700 tests / 22 minutes =

    170 TPM 9800 tests / 14 minutes = 700 TPM
  4. 12.
  5. 13.
  6. 17.

    palkan_tula palkan $ TEST_STACK_PROF=1 rspec spec/models/user_spec.rb $ stackprof tmp/test_prof/stackprof-cpu.dump TOTAL(pct)

    SAMPLES (pct) FRAME 2409 (25.5%) 988 (10.4%) AR…#exec_no_cache 2235 (23.6%) 935 (9.9%) AR…#execute 1287 (13.6%) 641 (6.8%) Logger ::LogDevice#write 130 (1.4%) 65 (0.7%) Mongo ::Socket#write https://medium.com/appaloosa-store-engineering/tips-to-improve-speed-of-your-test-suite-8418b485205c 17 TEST_STACK_PROF
  7. 19.

    palkan_tula palkan TEST_RUBY_PROF $ SAMPLE=10 TEST_RUBY_PROF=1 rspec Finished in 1

    minute 12 seconds 90 examples, 0 failures $ more tmp/test_prof/ruby-prof—report-flat-total.log %self calls name 20.85 721 <Class ::BCrypt ::Engine># __bc_crypt 1.12 47489 Arel ::Visitors ::Visitor#dispatch 1.04 205208 String#to_s 19
  8. 20.

    palkan_tula palkan Encryption in Tests # config/initializers/sorcery.rb config.user_config do |user|

    # default was 10 for bcrypt! user.stretches = 1 if Rails.env.test? end 20 $ SAMPLE=10 rspec Finished in 17 seconds 90 examples, 0 failures ~3.5x faster!
  9. 23.

    palkan_tula palkan TEST_STACK_PROF 23 scenario "visit home page", :sprof do

    # … end $ bundle exec rspec StackProf report generated: tmp/stack-prof-visit-home-page.dump Run the following command to generate a flame graph report: stackprof --flamegraph tmp/stack-prof-visit-home-page.dump > \ tmp/stack-prof-visit-home-page.html && \ stackprof —flamegraph-viewer=tmp/stack-prof-visit-home-page.html
  10. 26.

    palkan_tula palkan Why database_cleaner? 26 One database connection per thread

    No way to use transactional tests with multiple threads* *e.g. Capybara browser tests
  11. 27.

    palkan_tula palkan One database connection per thread No way to

    use transactional tests with multiple threads Why database_cleaner? 27
  12. 33.

    palkan_tula palkan With DatabaseCleaner 33 $ EVENT_PROF=sql.active_record rspec [TEST PROF

    INFO] EventProf for sql.active_record Total time: 00:04.146 Total events: 259 Top 5 slowest suites (by time): … Finished in 12.32 seconds 8 examples, 0 failures ~30% in database!
  13. 34.

    palkan_tula palkan With Shared Connection 34 $ EVENT_PROF=sql.active_record rspec [TEST

    PROF INFO] EventProf for sql.active_record Total time: 00:00.152 Total events: 216 Top 5 slowest suites (by time): … Finished in 7.99 seconds 8 examples, 0 failures ~0% in database => 30% faster!
  14. 42.

    palkan_tula palkan Sidekiq Inline 42 $ EVENT_PROF=sidekiq.inline rspec [TEST PROF

    INFO] EventProf for sidekiq.inline Total time: 04:28.175 Total events: 15596 Finished in 20 minutes 26 seconds Using Sidekiq ::Testing.inline! by default ~25% executing inlined jobs
  15. 43.

    palkan_tula palkan Sidekiq Inline 43 $ EVENT_PROF=sidekiq.inline rspec [TEST PROF

    INFO] EventProf for sidekiq.inline Total time: 01:31.605 Total events: 3884 Finished in 17 minutes 19 seconds Using Sidekiq ::Testing.fake! by default (and inline in-place) ~8% executing inlined jobs, ~15% faster
  16. 46.

    palkan_tula palkan EventProf 46 User-provided events # lib/work.rb class Work

    def do(*args) # do something end end # spec_helper.rb TestProf ::EventProf.monitor(Work, 'my.work', :do) NEW!!!
  17. 48.

    palkan_tula palkan EventProf 48 # Profiling paper_trail functionality TestProf ::EventProf.monitor(

    PaperTrail ::RecordTrail, 'paper.trail', :record_create, :record_destroy, :record_update, :record_update_columns, :reset_timestamp_attrs_for_update_if_needed )
  18. 49.

    palkan_tula palkan paper.trail 49 $ EVENT_PROF=paper.trail rspec [TEST PROF INFO]

    EventProf for paper.trail Total time: 00:45.307 Total events: 24244 Finished in 4 minutes 52.3 seconds ~15% versioning model changes
  19. 50.

    palkan_tula palkan paper.trail 50 $ EVENT_PROF=paper.trail rspec [TEST PROF INFO]

    EventProf for paper.trail Total time: 00:00.339 Total events: 24290 Finished in 3 minutes 54.6 seconds # spec_helper.rb require 'paper_trail/frameworks/rspec ~0.1% versioning model changes
  20. 52.

    Problem #6 create vs. build_stubbed it "validates name" do user

    = create(:user) expect(user).not_to be_valid end it "validates name" do user = build_stubbed(:user) expect(user).not_to be_valid end
  21. 53.

    palkan_tula palkan Factory Doctor 53 $ FDOC=1 rspec [TEST PROF

    INFO] FactoryDoctor report Total (potentially) bad examples: 103 Total wasted time: 00:16.803 User (./spec/models/user_spec.rb:3) ./spec/user_spec.rb:8 – 1 record created, 00:00.114 https://test-prof.evilmartians.io/#/factory_doctor
  22. 54.

    palkan_tula palkan Factory All Stub 54 require "test_prof/recipes/rspec/factory_all_stub" describe User

    do let(:user) { create(:user) } it "is valid", factory: :stub do # no database interactions here expect(user).to be_valid end end https://test-prof.evilmartians.io/#/factory_all_stub
  23. 56.

    palkan_tula palkan factory.create 56 $ EVENT_PROF=factory.create rspec [TEST PROF INFO]

    EventProf for factory.create Total time: 00:58.043 Total events: 1483 Top 5 slowest suites (by time): … Finished in 1 minute 13.15 seconds ⁉
  24. 58.

    palkan_tula palkan Factory Cascade 58 factory :comment do answer author

    end factory :answer do question author end factory :question do author end create(:comment) # => creates 5 records
  25. 59.

    palkan_tula palkan Factory Stack 59 create(:comment) # stack = [

    # :comment, # :answer, # :question, # :user, # :user, # :user # ]
  26. 61.

    palkan_tula palkan Factory Story 61 [TEST PROF INFO] EventProf for

    factory.create Total time: 01:02.279 Total events: 88022 Top 5 slowest suites (by time): EmbeddedSignatureRequestsSet – 00:31.630 (121 / 11) EmbeddedSignatureRequest – 00:22.479 (52 / 13) 24 examples – 54 seconds in factories!
  27. 65.

    palkan_tula palkan FactoryProf 65 $ FPROF=1 rspec [TEST PROF INFO]

    Factories usage total top-level name 372 348 account 366 363 funnel 261 261 interview_stage 167 151 user 156 156 applicant 76 76 available_slot 372 examples, 0 failures What about fixtures?
  28. 67.

    palkan_tula palkan –@dgilperez “Using a combination of FactoryDefault, AnyFixture and

    let_it_be we just reduced times … from 25 minutes to 16 seconds.” 67 https://github.com/palkan/test-prof/issues/73
  29. 68.

    palkan_tula palkan AnyFixture 68 Accepts any block of code as

    data generator Cleanups affected tables at the end of the whole suite run https://test-prof.evilmartians.io/#/any_fixture
  30. 69.

    palkan_tula palkan AnyFixture 69 using TestProf ::AnyFixture ::DSL using TestProf

    ::Ext ::ActiveRecordRefind shared_context "shared account", account: true do prepend_before(:all) do account = fixture(:account) { create :account, name: 'Star Wars' } funnel = fixture(:funnel) { create :funnel, account: account, name: 'Tatooine' } luke = fixture(:luke) { create :applicant, funnel: funnel, name: 'Luke Skywalker', email: 'luke@sw.spec' } end %i[account funnel luke].each { |id| let(id) { fixture(id).refind } end http://bit.ly/any-fixture
  31. 70.

    palkan_tula palkan AnyFixture 70 [TEST PROF INFO] AnyFixture stats: key

    build time hit count saved time account 00:00.143 2422 05:47.871 another_account 00:00.424 380 02:41.365 funnel 00:00.018 103 00:01.864 Total time spent: 00:00.794 Total time saved: 08:47.952 Finished in 7 minutes 52 seconds 3158 examples, 0 failures ~50% faster with AnyFixture
  32. 73.

    palkan_tula palkan before 73 describe BeatleSearchQuery do before do @paul

    = create(:beatle, name: 'Paul') @ringo = create(:beatle, name: 'Ringo') @george = create(:beatle, name: 'George') @john = create(:beatle, name: 'John') end # and about 15 examples here end
  33. 74.

    palkan_tula palkan let 74 describe BeatleSearchQuery do let!(:paul) { create(:beatle,

    :paul) } let!(:ringo) { create(:beatle, :ringo) } let!(:george) { create(:beatle, :george) } let!(:john) { create(:beatle, :john) } # and more examples here end
  34. 75.

    palkan_tula palkan RSpec Dissection 75 $ RD_PROF=1 rspec [TEST PROF

    INFO] RSpecDissect report Total time: 16:11.661 Total `before(:each)` time: 09:28.678 Total `let` time: 12:26.199 Top 10 slowest suites (by `before(:each)` time): … Top 10 slowest suites (by `let` time):… https://test-prof.evilmartians.io/#/rspec_dissect
  35. 76.

    palkan_tula palkan RSpec Dissection 76 $ RD_PROF=let rspec [TEST PROF

    INFO] RSpecDissect report Top 10 slowest suites (by `let` time): booking_spec.rb:3 – 00:05.843 of 00:06.832 (33) ↳ booking – 94 ↳ occupancy – 64 ↳ error – 21 https://test-prof.evilmartians.io/#/rspec_dissect
  36. 79.

    palkan_tula palkan before_all 79 describe BeatleSearchQuery do before_all do @paul

    = create(:beatle, name: 'Paul') @ringo = create(:beatle, name: 'Ringo') @george = create(:beatle, name: 'George') @john = create(:beatle, name: 'John') end # and about 15 examples here end https://test-prof.evilmartians.io/#/before_all
  37. 80.

    palkan_tula palkan let_it_be 80 https://test-prof.evilmartians.io/#/let_it_be describe BeatleSearchQuery do let_it_be(:paul) {

    create(:beatle, :paul) } let_it_be(:ringo) { create(:beatle, :ringo) } let_it_be(:george) { create(:beatle, :george) } let_it_be(:john) { create(:beatle, :john) } # and more examples here end
  38. 82.

    palkan_tula palkan before_all 82 class MyBeatlesTest < Minitest ::Test include

    TestProf ::BeforeAll ::Minitest before_all do @paul = create(:beatle, name: 'Paul') @ringo = create(:beatle, name: 'Ringo') @george = create(:beatle, name: 'George') @john = create(:beatle, name: 'John') end # define tests which could access the object defined within `before_all` end https://test-prof.evilmartians.io/#/before_all NEW!!!
  39. 84.

    palkan_tula palkan 84 # some_mailer_spec.rb subject { described_class.request_email(request) } it

    { is_expected.to have_subject(“Welcome") } it { is_expected.to be_delivered_from(“test@examle.com") } it { is_expected.to be_delivered_to('tester@foo.com') } it { is_expected.to have_body_text(request_link) } $ rspec spec/mailers/some_mailer_spec.rb Finished in 14.43 seconds 59 examples, 0 failures
  40. 85.

    palkan_tula palkan 85 # some_mailer_spec.rb subject { described_class.request_email(request) } it

    "works", :aggregate_failures do is_expected.to have_subject("Welcome") is_expected.to be_delivered_from("test@examle.com") is_expected.to be_delivered_to('tester@foo.com') is_expected.to have_body_text(request_link) end $ rspec spec/mailers/some_mailer_spec.rb Finished in 3.39 seconds 17 examples, 0 failures ~3.5x faster!
  41. 86.

    palkan_tula palkan RSpec/AggregateFailures 86 rubocop --only RSpec/AggregateFailures -a Offenses: create_spec.rb:277:7:

    C: RSpec/AggregateFailures: Use :aggregate_failures instead of one-liners. context 'not valid secure fields' do ... ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 1 offense detected, 1 offense corrected https://test-prof.evilmartians.io/#/rubocop