---
title: Debugging Why Your Specs Have Slowed Down
teaser: 'Your test suite used to be lightning fast but now it''s starting to feel
a bit sluggish. Before adding CI parallelization, let''s see if there''s any clutter
to remove.
'
tags: testing,ruby,rails,factory_girl,web,factory_bot
author: Mike Wenger
published_on: 2017-09-22
---
On a recent project, a client's test suite had slowed down to a painful 15
minutes even when running with parallelization. It was great to see that
the team maintained a
[balanced testing pyramid](https://thoughtbot.com/blog/rails-test-types-and-the-testing-pyramid),
but we were surprised by the completion times of even the simplest unit specs.
```ruby
# spec/models/user_spec.rb
describe "associations" do
subject(:user) { User.new }
it { should have_many(:orders) }
# 12 additional association specs
end
```
Over 3 seconds feels like an eternity for unit specs that don't even touch the database.
## Identifying Slowdowns in the spec_helper
```ruby
# spec/spec_helper.rb`
RSpec.configure do |config|
# > 300 lines of around, before and after blocks
end
```
A very large spec_helper file offers a lot of possible culprits. Let's fast track
our experimentation by commenting out everything and rerunning our specs.
Almost 9x faster! Now we're talking. Next, we systematically uncomment code
blocks and find the worst offenders.
### Culprit 1
```ruby
# spec/spec_helper.rb
config.before(:each) do
stub_something
end
```
This before block is only needed for a few feature specs to pass, but is running
before every single spec. Let's isolate the logic to only run for feature specs.
```ruby
# spec/spec_helper.rb
config.before(:each, type: :feature) do
stub_something
end
```
This is a good start but this logic is still being used before
feature specs that don't need it. Let's further isolate the logic using
user-defined metadata.
```ruby
# spec/spec_helper.rb
config.before(:each, :stub_something) do
stub_something
end
# spec/features/user_does_something_spec.rb
scenario "user does something", :stub_something do
# spec logic
end
```
### Culprit 2
```ruby
# spec/spec_helper.rb
config.before(:each) do |example|
DatabaseCleaner.strategy = :truncation
end
```
After each spec, the test can use [different database cleaning strategies](https://github.com/DatabaseCleaner/database_cleaner#what-strategy-is-fastest)
to "reset" the database. We happen to be using a very slow strategy compared to
transaction. To accommodate the few specs that require truncation, lets use the
same fix for Culprit 1 and add user-defined metadata to the specs that need it.
```ruby
# spec/spec_helper.rb
config.before(:each, :clean_database_with_truncation) do |example|
DatabaseCleaner.strategy = :truncation
end
```
## Identifying Slowdowns in Spec Setup
Using [RSpec's profile flag](https://relishapp.com/rspec/rspec-core/docs/configuration/profile-examples),
we can identify the slowest specs in the rest of the file.
rspec spec/models/user_spec.rb --profile 5
Pulling up the slowest spec, we see:
```ruby
# spec/models/user_spec.rb
it "does something" do
user = FactoryBot.create(:user)
# exercise on user
# expectation on user
end
```
On a hunch, we comment out everything except for the FactoryBot line, and sure
enough, the test barely speeds up. At this point in the audit process, we asked
if [FactoryBot was even needed](https://thoughtbot.com/blog/speed-up-tests-by-selectively-avoiding-factory-bot),
or if we could use [build_stubbed](https://thoughtbot.com/blog/use-factory-bots-build-stubbed-for-a-faster-test).
Turns out neither of these solutions were an option as the spec required writing
to the database. We still took a peek in our factory file to see if there
was room for optimization.
```ruby
# spec/factories/user_factory.rb
FactoryBot.define do
factory :user do
# more code
after(:create) do |user|
create(:billing_profile, user: user)
end
end
```
FactoryBot is creating active record associations that are not needed as part
of our test setup. We can fix this issue by moving the association into a
[FactoryBot trait](https://thoughtbot.com/blog/remove-duplication-with-factorybots-traits)
and rerunning our tests.
```ruby
# spec/factories/user_factory.rb
FactoryBot.define do
factory :user do
# more code
trait :with_billing_profile do
after(:create) do |user|
create(:billing_profile, user: user)
end
end
end
```
Sweet! We just made our 5 slowest specs over 2x faster. We're not done just yet.
We still have to run the full test suite and add our new trait to any specs that
require a billing_profile.
### Safeguarding Against Future Slowdowns
The team was concerned that other factories might be creating unnecessary
records in additional tests. Using [Factory Bot's documentation on
ActiveSupport Instrumentation](https://thoughtbot.github.io/factory_bot/activesupport-instrumentation/summary.html),
we were able to add this logic to give us greater visibility into the problem
when needed.
```ruby
# spec/spec_helper.rb
config.before(:each, :monitor_database_record_creation) do |example|
ActiveSupport::Notifications.subscribe("factory_bot.run_factory") do |name, start, finish, id, payload|
$stderr.puts "FactoryBot: #{payload[:strategy]}(:#{payload[:name]})"
end
end
```
Now, running a spec with the metadata `:monitor_database_record_creation` allows
us to verify if the number of records created by the test are in line with our
expectations.
[1](#fn1)
Yikes! A single unit spec is writing to the database to create 13 records when
the test setup and exercise should only have only generated 4 records. We plan
to remove these [mystery guests](https://thoughtbot.com/blog/mystery-guest) in
future PRs in order to avoid test misdirection and a slow test suite.
## The Benefits of Time Savings are Compounded
By removing global stubs we didn't need, using a faster database cleaner
strategy, and simplifying factories, we were able to shave a few minutes off of
our test suite. That may sound nominal at first, but multiply those minutes by
the number of developers on the team and the number of continuous integration
builds a day. That's an investment that will pay off very quickly.
## Footnotes
1.
> What's FactoryGirl? The library was renamed to FactoryBot in 2017.
[Naming history can be found here.](https://github.com/thoughtbot/factory_bot/blob/master/NAME.md)