Upgrade to Pro — share decks privately, control downloads, hide ads and more …

[Paris.rb 2018] 99 problems of slow tests

[Paris.rb 2018] 99 problems of slow tests

Vladimir Dementyev

June 29, 2018
Tweet

More Decks by Vladimir Dementyev

Other Decks in Programming

Transcript

  1. TestProf
    Vladimir Dementyev
    I GOT
    99 PROBLEMS
    BUT MY TEST
    AIN’T ONE
    99 problems of slow tests

    View full-size slide

  2. palkan_tula
    palkan
    2
    @palkan
    @palkan_tula
    Vladimir Dementyev
    694
    489
    259
    359

    View full-size slide

  3. palkan_tula
    palkan
    3

    View full-size slide

  4. palkan_tula
    palkan
    https://evilmartians.com
    4

    View full-size slide

  5. palkan_tula
    palkan
    https://evilmartians.com
    5

    View full-size slide

  6. palkan_tula
    palkan
    https://evilmartians.com
    6

    View full-size slide

  7. palkan_tula
    palkan
    99 problems of
    slow tests
    8

    View full-size slide

  8. RAISE YOUR HAND
    IF YOUR TESTS ARE SLOW

    View full-size slide

  9. palkan_tula
    palkan
    fountain.com
    11
    3700 tests / 22 minutes = 170 TPM
    9800 tests / 14 minutes = 700 TPM

    View full-size slide

  10. Problem #1
    Misconfigured
    Environment
    TODO: картинко

    View full-size slide

  11. palkan_tula
    palkan
    Use general profilers to diagnose
    environment problems
    15

    View full-size slide

  12. palkan_tula
    palkan
    General Profilers
    16
    RubyProf
    StackProf
    rbspy

    View full-size slide

  13. 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

    View full-size slide

  14. palkan_tula
    palkan
    #PROTIP
    https://jtway.co/speed-up-your-rails-test-suite-by-6-in-1-line-13fedb869ec4
    config.logger = Logger.new(nil)
    config.log_level = :fatal
    “Speed Up Your Rails Test Suite By 6% In 1 Line”
    18

    View full-size slide

  15. 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 # __bc_crypt
    1.12 47489 Arel ::Visitors ::Visitor#dispatch
    1.04 205208 String#to_s
    19

    View full-size slide

  16. 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!

    View full-size slide

  17. palkan_tula
    palkan
    Encryption in Tests
    https://github.com/Sorcery/sorcery/pull/81
    21

    View full-size slide

  18. palkan_tula
    palkan
    Test environment should be
    configured differently
    22

    View full-size slide

  19. 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

    View full-size slide

  20. palkan_tula
    palkan
    TEST_STACK_PROF
    24

    View full-size slide

  21. Problem #2
    database_cleaner

    View full-size slide

  22. 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

    View full-size slide

  23. palkan_tula
    palkan
    One database connection per thread
    No way to use transactional tests with
    multiple threads
    Why database_cleaner?
    27

    View full-size slide

  24. palkan_tula
    palkan
    Rails 5.1
    https://github.com/rails/rails/pull/28083
    28

    View full-size slide

  25. palkan_tula
    palkan
    ActiveRecordSharedConnection
    29
    https://test-prof.evilmartians.io/#/active_record_shared_connection
    # Rails 5.1+
    # connection is shared out-of-the-box
    # Rails <5.1
    require 'test_prof/recipes/active_record_one_love'

    View full-size slide

  26. palkan_tula
    palkan
    Let’s measure the impact of
    removing database_cleaner
    with EventProf
    30

    View full-size slide

  27. palkan_tula
    palkan
    EventProf
    31
    rspec --profile
    +
    ActiveSupport ::Notifications

    View full-size slide

  28. palkan_tula
    palkan
    EventProf
    32
    ruby test.rb --event-prof=sql.active_record
    +
    Custom Instrumentation

    View full-size slide

  29. 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!

    View full-size slide

  30. 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!

    View full-size slide

  31. palkan_tula
    palkan
    You (likely) don’t need
    database_cleaner
    35

    View full-size slide

  32. palkan_tula
    palkan
    TEST_STACK_PROF=boot
    36

    View full-size slide

  33. Problem #3
    Boot Time

    View full-size slide

  34. palkan_tula
    palkan
    TEST_STACK_PROF=boot
    38

    View full-size slide

  35. palkan_tula
    palkan
    EventProf
    39
    “sidekiq.inline"
    Jobs executed inline
    TestProf-provided events

    View full-size slide

  36. Problem #4
    Inlined Jobs

    View full-size slide

  37. palkan_tula
    palkan
    https://gist.github.com/nateberkopec/3932fce995c9feddd411417fc9bf33bf
    Sidekiq Shame
    41

    View full-size slide

  38. 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

    View full-size slide

  39. 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

    View full-size slide

  40. palkan_tula
    palkan
    Do not inline background jobs
    by default
    44

    View full-size slide

  41. palkan_tula
    palkan
    How to migrate?
    45
    https://evilmartians.com/chronicles/testprof-a-good-doctor-for-slow-ruby-tests

    View full-size slide

  42. 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!!!

    View full-size slide

  43. Problem #5
    Testability of
    Deps

    View full-size slide

  44. 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
    )

    View full-size slide

  45. 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

    View full-size slide

  46. 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

    View full-size slide

  47. palkan_tula
    palkan
    Testability of dependencies affects
    your test suite run time
    51

    View full-size slide

  48. 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

    View full-size slide

  49. 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

    View full-size slide

  50. 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

    View full-size slide

  51. palkan_tula
    palkan
    EventProf
    55
    “sidekiq.inline"
    “factory.create”
    Top-level factory calls
    TestProf-provided events

    View full-size slide

  52. 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 ⁉

    View full-size slide

  53. Problem #7
    Factory
    Cascades

    View full-size slide

  54. 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

    View full-size slide

  55. palkan_tula
    palkan
    Factory Stack
    59
    create(:comment)
    # stack = [
    # :comment,
    # :answer,
    # :question,
    # :user,
    # :user,
    # :user
    # ]

    View full-size slide

  56. palkan_tula
    palkan
    FactoryProf
    60
    https://test-prof.evilmartians.io/#/factory_prof

    View full-size slide

  57. 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!

    View full-size slide

  58. palkan_tula
    palkan
    Factory Story
    62

    View full-size slide

  59. palkan_tula
    palkan
    Factory Story
    63
    From 54 seconds to 2 seconds!

    View full-size slide

  60. palkan_tula
    palkan
    Factory Therapy
    64
    https://evilmartians.com/chronicles/testprof-2-factory-therapy-for-your-ruby-tests-rspec-minitest

    View full-size slide

  61. 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?

    View full-size slide

  62. Problem #8
    Repetitive
    Data
    Generation

    View full-size slide

  63. 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

    View full-size slide

  64. 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

    View full-size slide

  65. 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: '[email protected]'
    }
    end
    %i[account funnel luke].each { |id| let(id) { fixture(id).refind }
    end
    http://bit.ly/any-fixture

    View full-size slide

  66. 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

    View full-size slide

  67. palkan_tula
    palkan
    Do not choose between factories
    and fixtures–use both!
    71

    View full-size slide

  68. Problem #9
    Repetitive
    Setup
    test do
    setup
    exercise
    verify
    teardown
    end

    View full-size slide

  69. 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

    View full-size slide

  70. 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

    View full-size slide

  71. 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

    View full-size slide

  72. 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

    View full-size slide

  73. palkan_tula
    palkan
    77

    View full-size slide

  74. palkan_tula
    palkan
    78
    before_all
    let_it_be

    View full-size slide

  75. 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

    View full-size slide

  76. 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

    View full-size slide

  77. palkan_tula
    palkan
    Use before_all and let_it_be to share
    setup between tests
    81

    View full-size slide

  78. 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!!!

    View full-size slide

  79. Problem #10
    One Assertion
    per Test

    View full-size slide

  80. 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(“[email protected]") }
    it { is_expected.to be_delivered_to('[email protected]') }
    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

    View full-size slide

  81. 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("[email protected]")
    is_expected.to be_delivered_to('[email protected]')
    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!

    View full-size slide

  82. 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

    View full-size slide

  83. Problems #11-99
    It’s You

    View full-size slide

  84. palkan_tula
    palkan
    github.com/palkan/test-prof
    https://test-prof.evilmartians.io
    TestProf
    88
    v0.6.0 (2018-06-28)

    View full-size slide

  85. Merci!
    Vladimir Dementyev
    evilmartians.com/blog
    @palkan
    @palkan_tula
    @evilmartians

    View full-size slide