Rspec Bisect

The Problem

Sometimes you have a test that fails, but not all the time -- an erratic test (one of the four test smells covered in the Testing Antipatterns episode of TWI). You usually see this on CI, even when tests are all passing locally.

This is usually caused by one of two things:

• The test relies on timing (e.g. race conditions).
• The test is coupled with another test, and the order in which they run matters.

The latter case, an order-dependent failure, is what Rspec's bisect can help us with.

Randomized Ordering of Tests

A number of versions ago, Rspec introduced the idea of running your tests in random order, to help bring to light any potential failures hidden in your test suite that can be triggered by a certain ordering of the tests. In all of our Suspenders applications, we run tests with random ordering on.

However, the randomizer also tells you what "seed" it is using to generate the ordering, so that if you want to, you can reproduce the exact same ordering by reusing the same seed:

$ rspec spec --seed 61655

If we're able to consistently reproduce the failure with a given seed, then we know our erratic test is in fact an order-dependent test. Once we can consistently reproduce it locally, we're on our way to tracking it down.

Note: If you'd like to follow along with this episode, you can checkout the version of the Upcase codebase that has the erratic test with:

$ git checkout 3144273

Then, set it up with:

$ bin/setup

and, finally, see the erratic test with:

$ rspec spec               # all tests should pass
$ rspec spec --seed 61655  # one test should fail

Once you are finished following along with this episode, you can get back to your most current version of the codebase with:

$ git checkout master
$ bin/setup

How Rspec Bisect Can Help

As of Rspec 3.3, we have the bisect flag to help us chase down order- dependent test failures.

The bisect flag will perform a binary search through the ordering of your test suite to determine the minimum number of tests, and the ordering of them, that produces the test failure.

A Binary What Now?

Have you ever debugged code by commenting out half of it and seeing if the error still occurs, and if not, then trying the other half? And then half again of the problematic section? Et cetera? Then you've done a binary search.

If you've ever done this, you know it can be a time consuming process. With a large test suite, and a huge number of possible orderings of them, it would take a long time to find an order-dependent failure manually. Fortunately, Rspec bisect automates this process for us.

$ rspec spec --bisect --seed 61655

Now, go grab a coffee.

Ultimate Trust in Your Test Suite

This may seem like overkill, but having an order-dependent failure is subtly dangerous. You don't want your client to see a failure once in a while, and have to hand-wave it away. You want your client, and yourself, to have ultimate trust in your test suite, so that you can push to production with confidence.

Minimal Reproduction Command

When you get back from your coffee break, if you're lucky, Rspec will have narrowed it down for you and told you exactly how to reproduce the failure with the minimum number of dependencies:

The minimal reproduction command is:
  rspec './spec/features/user_removes_pending_invitation_spec.rb[1:1]' '.spec/lib/slug_constraint_spec.rb[1:1:1:1]' --seed 61655

In this case, we only need to run one other test besides the problematic one in order to cause the failure. With just this one test to examine, it becomes dramatically easier to spot and understand the problem.

The Happy Ending

We immediately notice a before block in the test that Rspec bisect identified for us that sets up a store, but doesn't tear it down afterward:

# slug_constraint_spec.rb

describe SlugConstraint do
  before(:each) { RequestStore.clear! }

  describe "#matches?" do
  # ...

A bit of experimentation reveals that this is, indeed, the issue:

# slug_constraint_spec.rb

describe SlugConstraint do
  around do |example|
    RequestStore.clear!
    example.run
    RequestStore.clear!
  end

  describe "#matches?" do
  # ...

Victory!