I’ve been thinking a lot about testing recently. Perhaps the most inconvenient truth about automated testing is that even though it’s many orders of magnitude faster than manual testing, it’s not infinitely fast, and the marginal cost does add up. This is especially true in slower, interpreted languages like Ruby.

Recently our test suite at The Auteurs has been approaching 15 minutes on a fast MacBook Pro. The obvious solution to this is continuous integration, but I believe there is lower-hanging fruit. Being able to run the full suite (or at least the majority of it) fast means a lot to the agility of the team. There is always room to optimize the tests themselves, but I’ll leave that topic for another post. What was of interest to me is that the default Rails testing tasks seemed to be getting quite slow on a code base of our size (30k lines).

How to attack the problem?

Benchmarking Rake

Rake 0.8.7 doesn’t come with any built-in benchmarking options, but hooking in proved extremely straightforward (thank you Ruby!):

require 'benchmark'

class Rake::Task
  def execute_with_benchmark(*args)
    bench = Benchmark.measure do
      execute_without_benchmark(*args)
    end
    puts "  #{name} --> #{bench}"
  end
  alias_method_chain :execute, :benchmark
end

That produces output like:

environment -->   8.580000   1.390000   9.970000 ( 10.408723)
db:abort_if_pending_migrations -->   2.600000   0.040000   2.640000 (  2.662062)
db:test:purge -->   0.010000   0.000000   0.010000 (  0.146904)
db:schema:load -->   0.810000   0.070000   0.880000 ( 49.263301)
db:test:load -->   0.820000   0.070000   0.890000 ( 49.274854)
db:test:prepare -->   0.830000   0.070000   0.900000 ( 49.422403)
test:units -->   0.050000   0.080000 103.930000 (118.107608)

It’s important to note here that this output doesn’t explicitly communicate nested tasks, and thus you can’t naively sum the totals. Rake mostly operates using prerequisites so that things run one at a time without being nested, but in this case db:test:prepare invokes db:test:load which invokes db:schema:load, thus the former includes the latter execution times.

Also I benchmarked a bunch of things in test_helper.rb, but most significant ended up being the environment:

require 'benchmark'

bench = Benchmark.measure do
  require File.expand_path(File.dirname(__FILE__) + "/../config/environment")
end
puts "  Require Rails Env --> #{bench}"

which ended up being around 10 seconds just like in the rake task:

Require Rails Env -->   8.270000   1.820000  10.090000 ( 10.205786)

Rolling Up Testing Tasks Into One

If you aren’t thinking carefully you might assume that rake loading the environment is basically free since the tests need it anyway, but remember, the rake process is just running commands in a shell, it’s not invoking the tests in the same Ruby process. Therefore each block of tests (ie. unit, functional, integration) needs to startup the environment from scratch. That works fine for small applications, but as they grow the overhead becomes significant. In our case we even have a couple extra blocks of tests beyond the Rails defaults, all of which adds up to significant overhead.

However it’s easy to write a task that runs all the tests in one block:

namespace :test do
  Rake::TestTask.new(:fast) do |t|
    files = FileList["test/unit/**/*_test.rb",
      "test/functional/**/*_test.rb", "test/integration/**/*_test.rb"]

    t.libs << 'test'
    t.verbose = true
    t.test_files = files
  end
  Rake::Task['test:fast'].comment =
    "Runs unit/functional/integration tests in a single block"

The potential issue with this is that you lose the namespacing of the tests, which could lead to test name collisions, or there may be other types of environment collisions depending on the specifics of your app. However in our case this worked right out of the box.

Drop Test Preparations

The other thing you’ll notice about that rake task if you compare to the ones defined in railties/lib/tasks/testing.rake is that I’ve dropped the prerequisite db:test:prepare from the definition. That means that the task won’t automatically reload the database schema, and it won’t warn you if migrations haven’t been run. It also means the environment isn’t required either, yielding a savings of over a minute. Obviously this is highly dependent on the number of tables in the schema. In our case we have 130 which doesn’t seem like a tremendous amount—each table is adding over a third of a second of overhead. If our unit tests were optimized a bit this overhead could end up dominating the execution time.

The downside here is that you are basically on the hook for calling db:migrate and db:test:prepare, but the number of times we need to call those is dwarfed by frequency of test runs. It does require a bit of mental overhead to recognize test failures caused by a bad schema, but the performance gains are well worth it for a large app.

Isolate Slow Tests

Now that the rake overhead is removed, the next logical step is to optimize individual tests. So grab the test_benchmark gem and profile your tests. In our case there were a few super slow tests dominating the runtime profile. These tests are important, but not necessarily in proportion to their runtime. My solution was to cordon off the slow tests in their own directory:

Rake::TestTask.new(:slow) do |t|
  t.libs << 'test'
  t.verbose = true
  t.pattern = 'test/slow/**/*_test.rb'
end
Rake::Task['test:slow'].comment = "Runs the slow tests"

Just to be clear, I recognize that having a set of isolated tests like this is a code smell. In order to be fully comfortable with this I need to have continuous integration setup running these tests so that any developer pushing code will be notified within 20-30 minutes if one of these tests is failing. The other mitigator is that these tests should not be regression tests of core functionality. That’s a judgement call, but with experience it’s not hard to classify some tests as more important than others.

Roll It In

I don’t want to mess around with the built-in Rails tasks because that is confusing to new developers. However I do want test:fast to be the default task because that’s going to be our bread and butter. So in the end I came up with these changes:

Rake::Task[:default].clear
task :default => "test:fast"

task "test" => ["test:slow"]

The last bit ensures that rake test will first run test:slow which means that we now have the best of both worlds at our finger tips. rake will run the fast tests, and rake test will run the standard Rails test blocks, preceded up the slow tests.

I chose to move 4 out of 250 test classes to the slow/ set. Testing the total runtime from the shell using the time utility yields:

sh> time(rake test)
real 11m54.247s
user 8m56.002s
sys  0m30.125s

sh> time(rake)
real 8m1.043s
user 6m36.532s
sys  0m16.860s

So we went from 12 minutes down to 8 minutes by dropping less than 2% of the test classes. Not a bad first effort. Next up: optimization techniques for Rails test suites.