Slide 1
Slide 1 text
TestProf
Vladimir Dementyev
I GOT
99 PROBLEMS
BUT MY TEST
AIN’T ONE
99 problems of slow tests
Slide 2
Slide 2 text
palkan_tula
palkan
2
@palkan
@palkan_tula
Vladimir Dementyev
694
489
259
359
Slide 3
Slide 3 text
palkan_tula
palkan
3
Slide 4
Slide 4 text
palkan_tula
palkan
https://evilmartians.com
4
Slide 5
Slide 5 text
palkan_tula
palkan
https://evilmartians.com
5
Slide 6
Slide 6 text
palkan_tula
palkan
https://evilmartians.com
6
Slide 7
Slide 7 text
This Talk
Slide 8
Slide 8 text
palkan_tula
palkan
99 problems of
slow tests
8
Slide 9
Slide 9 text
RAISE YOUR HAND
IF YOUR TESTS ARE SLOW
Slide 10
Slide 10 text
No content
Slide 11
Slide 11 text
palkan_tula
palkan
fountain.com
11
3700 tests / 22 minutes = 170 TPM
9800 tests / 14 minutes = 700 TPM
Slide 12
Slide 12 text
TestProf
Slide 13
Slide 13 text
No content
Slide 14
Slide 14 text
Problem #1
Misconfigured
Environment
TODO: картинко
Slide 15
Slide 15 text
palkan_tula
palkan
Use general profilers to diagnose
environment problems
15
Slide 16
Slide 16 text
palkan_tula
palkan
General Profilers
16
RubyProf
StackProf
rbspy
Slide 17
Slide 17 text
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
Slide 18
Slide 18 text
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
Slide 19
Slide 19 text
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
Slide 20
Slide 20 text
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!
Slide 21
Slide 21 text
palkan_tula
palkan
Encryption in Tests
https://github.com/Sorcery/sorcery/pull/81
21
Slide 22
Slide 22 text
palkan_tula
palkan
Test environment should be
configured differently
22
Slide 23
Slide 23 text
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
Slide 24
Slide 24 text
palkan_tula
palkan
TEST_STACK_PROF
24
Slide 25
Slide 25 text
Problem #2
database_cleaner
Slide 26
Slide 26 text
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
Slide 27
Slide 27 text
palkan_tula
palkan
One database connection per thread
No way to use transactional tests with
multiple threads
Why database_cleaner?
27
Slide 28
Slide 28 text
palkan_tula
palkan
Rails 5.1
https://github.com/rails/rails/pull/28083
28
Slide 29
Slide 29 text
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'
Slide 30
Slide 30 text
palkan_tula
palkan
Let’s measure the impact of
removing database_cleaner
with EventProf
30
Slide 31
Slide 31 text
palkan_tula
palkan
EventProf
31
rspec --profile
+
ActiveSupport ::Notifications
Slide 32
Slide 32 text
palkan_tula
palkan
EventProf
32
ruby test.rb --event-prof=sql.active_record
+
Custom Instrumentation
Slide 33
Slide 33 text
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!
Slide 34
Slide 34 text
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!
Slide 35
Slide 35 text
palkan_tula
palkan
You (likely) don’t need
database_cleaner
35
Slide 36
Slide 36 text
palkan_tula
palkan
TEST_STACK_PROF=boot
36
Slide 37
Slide 37 text
Problem #3
Boot Time
Slide 38
Slide 38 text
palkan_tula
palkan
TEST_STACK_PROF=boot
38
Slide 39
Slide 39 text
palkan_tula
palkan
EventProf
39
“sidekiq.inline"
Jobs executed inline
TestProf-provided events
Slide 40
Slide 40 text
Problem #4
Inlined Jobs
Slide 41
Slide 41 text
palkan_tula
palkan
https://gist.github.com/nateberkopec/3932fce995c9feddd411417fc9bf33bf
Sidekiq Shame
41
Slide 42
Slide 42 text
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
Slide 43
Slide 43 text
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
Slide 44
Slide 44 text
palkan_tula
palkan
Do not inline background jobs
by default
44
Slide 45
Slide 45 text
palkan_tula
palkan
How to migrate?
45
https://evilmartians.com/chronicles/testprof-a-good-doctor-for-slow-ruby-tests
Slide 46
Slide 46 text
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!!!
Slide 47
Slide 47 text
Problem #5
Testability of
Deps
Slide 48
Slide 48 text
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
)
Slide 49
Slide 49 text
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
Slide 50
Slide 50 text
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
Slide 51
Slide 51 text
palkan_tula
palkan
Testability of dependencies affects
your test suite run time
51
Slide 52
Slide 52 text
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
Slide 53
Slide 53 text
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
Slide 54
Slide 54 text
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
Slide 55
Slide 55 text
palkan_tula
palkan
EventProf
55
“sidekiq.inline"
“factory.create”
Top-level factory calls
TestProf-provided events
Slide 56
Slide 56 text
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 ⁉
Slide 57
Slide 57 text
Problem #7
Factory
Cascades
Slide 58
Slide 58 text
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
Slide 59
Slide 59 text
palkan_tula
palkan
Factory Stack
59
create(:comment)
# stack = [
# :comment,
# :answer,
# :question,
# :user,
# :user,
# :user
# ]
Slide 60
Slide 60 text
palkan_tula
palkan
FactoryProf
60
https://test-prof.evilmartians.io/#/factory_prof
Slide 61
Slide 61 text
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!
Slide 62
Slide 62 text
palkan_tula
palkan
Factory Story
62
Slide 63
Slide 63 text
palkan_tula
palkan
Factory Story
63
From 54 seconds to 2 seconds!
Slide 64
Slide 64 text
palkan_tula
palkan
Factory Therapy
64
https://evilmartians.com/chronicles/testprof-2-factory-therapy-for-your-ruby-tests-rspec-minitest
Slide 65
Slide 65 text
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?
Slide 66
Slide 66 text
Problem #8
Repetitive
Data
Generation
Slide 67
Slide 67 text
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
Slide 68
Slide 68 text
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
Slide 69
Slide 69 text
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
Slide 70
Slide 70 text
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
Slide 71
Slide 71 text
palkan_tula
palkan
Do not choose between factories
and fixtures–use both!
71
Slide 72
Slide 72 text
Problem #9
Repetitive
Setup
test do
setup
exercise
verify
teardown
end
Slide 73
Slide 73 text
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
Slide 74
Slide 74 text
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
Slide 75
Slide 75 text
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
Slide 76
Slide 76 text
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
Slide 77
Slide 77 text
palkan_tula
palkan
77
Slide 78
Slide 78 text
palkan_tula
palkan
78
before_all
let_it_be
Slide 79
Slide 79 text
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
Slide 80
Slide 80 text
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
Slide 81
Slide 81 text
palkan_tula
palkan
Use before_all and let_it_be to share
setup between tests
81
Slide 82
Slide 82 text
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!!!
Slide 83
Slide 83 text
Problem #10
One Assertion
per Test
Slide 84
Slide 84 text
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
Slide 85
Slide 85 text
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!
Slide 86
Slide 86 text
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
Slide 87
Slide 87 text
Problems #11-99
It’s You
Slide 88
Slide 88 text
palkan_tula
palkan
github.com/palkan/test-prof
https://test-prof.evilmartians.io
TestProf
88
v0.6.0 (2018-06-28)
Slide 89
Slide 89 text
Merci!
Vladimir Dementyev
evilmartians.com/blog
@palkan
@palkan_tula
@evilmartians