Lessons Learned from Three Rails Test Audits: How To Audit and Improve the Performance of Your RoR test Suite
- The Guide
Author’s note: This is a very work-in-progress guide, more of a scratchpad than finished page/guide/product/”thing”. Please keep that in mind as you read! Stick questions in comments below, or add a comment to this twitter thread:
A few weeks ago, I tweeted this thread:
How long do your tests take to run?— Josh Thompson (@josh_works) May 13, 2021
Some tests suites take 5 minutes. Others take 45 minutes.
I've done work around speeding up tests, and want to test my skills against real-world applications.
Will you pay me at least $100 to audit your #RoR test suite?
I offered to do this for $100. 🤦♀️, quickly upgraded it to $1000 after a few tweets suggested $1000 was the minimum possible amount for this service:
Strongly recommend you charge at least $1,000 to signal you're serious and know what you're doing.— Ben Orenstein (@r00k) May 14, 2021
"I gave access to our source code to an extremely cheap contractor" is not something most folks want to say to their boss.
Since then, I’ve had three customers! It’s been an absolute blast, and I’ve learned a ton. (For example, getting an entire app running locally, from
git clone to
rails test and having all passing tests never takes just a few minutes). I’ll charge substantially more next time around.
This document will be a living guide for how I accomplished the audit (and how I’ll conduct future audits) and what steps I’ve taken to do two things:
- Profile the test suite (and what this actually means/why it’s important, if it seems odd to spend time on this topic.)
- Reduce the test run time (or related times, like file load time, CircleCI “time”, etc)
For one customer, I took a 5 min test suite to 1:10, a 75% reduction in speed, thanks to VCR. I’ll show you exactly how I did this.
For another customer, I got a ~20min test suite to ~11min, but it failed when getting pushed to CircleCI, and then the underlying issue (some really slow DB queries) got partially fixed, so I’m auditing the app a second time, expecting to find a different set of issues.
For the third customer, the app is huge, complicated, and the tests take so long they don’t run the whole suite on a regular laptop - it’s delegated to CircleCI, and test runs eat up a lot of credits and time.
I’m going to offer all of my lessons learned as this finished guide soon. Preorder the guide for $49, or an upgrade package that will come with at least a 1-hour call, where we talk about your questions, we can screenshare through your codebase, etc. Any purchaser gets added to my slack group, and you can ping me with questions at any time.
I’m offering this on pre-order, because I’ve not finished the guide yet! Once the guide is done )especially when I do this again and get a bit more experienced/sophisticated), I’ll raise the rates quite a bit. I don’t know when that’ll be - could be months from now.
Early adapters will obviously work more closely with me, and vice versa - as I/my written instructions create additional value, I’ll raise my rates.
If you’d like a student discount, email me! I’ll hook you up!
The Guide #
I’m keeping some running notes in this document. I’ll eventually expand it into a coherent, elegant document, titled
The Complete Guide to Making Your Rails Tests Run Faster, but like anything I make, it goes through many rounds of iteration and testing, and I need a “dump my thoughts” spot somewhere close to hand and easily accessible.
Before I go farther, please know that I, of course stand on shoulders of giants.
Both of those guides are extensive, and incredible collections of learning and knowledge. In ways I’m trying to apply lessons from both of them to this problem, and nearly any thought I have in this domain that is correct comes directly from Nate or Jason. (If you’ve not bought their books/courses for yourself or especially your development team I’d encourage you to do so! You and your team will be thrilled!)
Benchmarking & Profiling #
Step 1 is always “benchmark and profile”.
Ideally, I use a command like:
$ time bundle exec rails test --profile 40 $ time bundle exec rspec --profile 40
time command is easy - look it up on your machine, or use TLDR. It
times whatever comes next.
bundle exec (I have aliased to
b ) runs the exact gems/versions specified in the
rspec run the test suite
rspec has this
profile functionality already included. It prints out diagnostic information about the slowest
n tests, defaults to 10, I usually look at the slowest 40. There’s a minitest gem for enabling profiling in minitest.
Get the app running locally #
Oh man, this was a doozy. I ran into many issues. Many were tiny, required just a few Google queries to get through. Others were heftier.
We’re used to something like:
$ git clone <company_app> $ cd <company_app> $ bundle install $ bin/rails rspec
It’s often quite a bit more. I actually wanna build a service that times how long from
git clone to tests being done running and passing, or the app running locally and DB properly seeded, or both.
- xcode-select commandline tools. Reinstalling fixes many things that get inexplicably broken.
- Elasticsearch can be a PITA to get running w/Homebrew
- MySQL can be a doozy to get various flavors of databases connected to the app.
- services are not trivial. (mongdb, mysql/mysqld, elasticsearch, running them in a container, or locally, or via homebrew, or all of the above, credentials/ports so all services can connect appropriately.)
There are lots of services that developers can install on their machines.
More on this to come someday.
After you’ve run some profiling/benchmarks #
I’m free-associating through this. Each time I’ve done this, my “eye” is drawn in different directions to explore, so I’m hesitant to suggest hard-and-fast rules.
- Tons of deprecation warnings, and a slow file load time? Maybe look into that.
- Clean/easy test run, fast file load time? Look for common threads among the slowest tests.
Here’s the specific items I’m auditing:
- Best-case test run time
- File load time
- No-wifi run time/results
- Flaky test count (if any)
Lets say you’re investigating a slow file load time, especially if it’s a low file load time for every test:
Finished in 1.77 seconds (files took 1 minute 4.97 seconds to load)
That’s the output of running a sample little test I built. I just created an empty file, and write a minimum-viable-spec for
# spec/models/string_spec.rb require 'rails_helper' describe String do it "should be capitalizable" do string = "josh" expect(string.capitalize).to eq("Josh") end end
When I run:
$ time bin/rspec spec/models/string_spec.rb String should be capitalizable Finished in 1.77 seconds (files took 1 minute 40.54 seconds to load) 1 example, 0 failures bin/rspec spec/models/string_spec.rb 0.25s user 0.14s system 0% cpu 1:44.37 total
There’s a few reasons this high file load time causes problems, some obvious, some subtle. All there is to say is it’s worth fixing. It’s a big, complicated application, so I’m just capturing my thoughts…
Next, lets use two very sophisticated benchmarking tools to explore this ~2min file load time:
- commenting things out
- Strategic shotgunning of well-formatted
See, first, I commented out pretty much everything in
rails_helper, to try to get the file load time down. Where might you start commenting things out, to see what is causing the slowdown?
Try commenting out
require 'rails_helper. When I do that, the files now load in about .7 seconds.
I’ve come to enjoy Spring w/Rspec: https://github.com/jonleighton/spring-commands-rspec
# Gemfile group :test do gem 'spring-commands-rspec'
bundle install and then
bundle exec spring binstub rspec
Now the first time I run
b rspec spec/models/string_spec.rb Spring re-loads the app, but all subsequent runs, the app is pre-loaded and it seems to run much faster:
$ b rspec spec/models/string_spec.rb String should be capitalizeable Finished in 0.00503 seconds (files took 0.19154 seconds to load) 1 example, 0 failures
So we’re loading files in 0.19 seconds, more or less. maybe. This is just early recon, with
require 'rails_helper' still commented out. Uncommenting that will inject lots of slowness, but it’s OK!
Running single spec with
require 'rails_helper' #
String should be capitalizeable Finished in 1.4 seconds (files took 1 minute 17.78 seconds to load) 1 example, 0 failures
I’m running this a few times to see how much variability there is on the file load time. The times I’m seeing are all around 1.5 minutes. An improvement off of 2 minutes, but not good enough. I can see from the terminal output, however, thanks to my
puts statements (which all look like:
puts "TIMING: doing_such_and_such" puts "TIMING: DB Cleaner" puts "TIMING: setting up users" puts "TIMING: connection.execute"
etc. I stick these throughout
application.rb, various helper files, etc, to see where things are moving “quickly” and “slowly”. This is extremely imprecise - if I wanted to be fancy, I could create a little timer class, and then do fancy calls that time exactly how long has elapsed between calls, and could order by the longest elapsed time between calls. Maybe next time.
Anyway, in iTerm, i can then
TIMING and have my statements highlighted as they come out:
This means that even when deprecation warnings and logs are being printed out, by just watching the presence of those little highlighted boxes popping up, I can get a sense of how long various components of the application/tests take to process. I’m aiming to shave minutes from the test time, not milliseconds.
Resources for file load time issues #
- How I got RSpec to boot 50 times faster
- RSpec load time incredible long on OS X
- Testing Rails (by ThoughtBot)
- Rails Testing: Files Took ‘x’ Seconds To Load
- How Fast is Spring?
This guide is a heavy work-in-progress. If you’ve got questions on anything, leave a comment below. It’s hooked up to a Github issue, so it’s really just leaving comments via Github.