Occasionally, something added to a gem used by one of your projects will break your application. Finding out where, when, and how it broke can be a challenge, especially if you upgrade several point releases at once. For example, if you're updating a dependency gem from (for example) version 2.0.0 to the latest release, 2.2.1, you've got dozens of commits that MIGHT be what broke something. Understand what changed will often reveal the source of the bug more quickly than debug statements or debugger consoles. This post will walk you through the process of taking a Ruby gem and slicing up the commits ("bisecting" it) to figure out what went wrong.
Git bisect will iterate through each commit between two points, but rather than going sequentially, hitting every single commit, it intellegently divides them - it will start halfway through the begin and end commit, and then iterate by halving the distance between the known good commit and the known bad commit. In computer science terms, this technique is sometimes called a "binary search". The point, though, is that it will save you a lot of time over inspecting every commit to find the one that breaks.
An example: Upgrading Adhearsion
Here’s a real issue I encountered not long ago. It happened to me when I moved from Adhearsion 2.1 to 2.2, but to make the example more dramatic, let’s upgrade all the way from 2.0.0 to 2.2.1. Say you're running along on 2.0 in production, all your tests pass, and there are no known issues. But when you upgrade to 2.2.0 to get a new feature, all hell breaks loose. Suddenly, you notice that certain conditions cause the logger to quit logging, and you get no feedback on your app. Here's how to use git bisect to track down which change to the Adhearsion project broke it.
Step 1: Check out gem sources
This should work for any gem which:
- Uses git; and,
- Has a checked in gemspec
The gemspec is needed so that Bundler can treat the checkout as a gem. For the purposes of our example, we'll use Adhearsion:
git clone git://github.com/adhearsion/adhearsion.git
Step 2: Edit your project's Gemfile
Open up your project's Gemfile, and change the line that brings Adhearsion into the project to read:
gem "adhearsion", path: "/home/jaiken/gems/adhearsion"
Be sure to put in the actual path to which you have cloned Adhearsion
At this point, it's probably helpful to have two terminal tabs open: one in your project and one in the directory in which you cloned Adhearsion.
Step 3: Find the last known "good" version's commit hash
Finding the commit where the bug began requires knowing two points: one "good" (working, non-broken) version, and one "bad" (broken) version. Hopefully the project you are using has tagged releases, like Adhearsion does. If not, you may need to look through the Git commit logs to find the hashes that correspond to the version release. For example, here is a small list of commit hashes that go with each Rubygems release for Adhearsion:
- 2.2.1 - 9542998
- 2.2.0 - c46473d
- 2.1.3 - 63b1201
- 2.1.2 - 1f342fd
- 2.1.1 - 94a601c
- 2.1.0 - f843284
- 2.0.1 - 372237d
- 2.0.0 - e6e1d6e
In the Adhearsion tab, you'll want to checkout a known good commit. Since we started with a working application on version 2.0.0, let’s use that hash to start:
git checkout e6e1d6e
In the terminal tab for your own app, we'll run
bundle install on your project to bring that first version of Adhearsion into the review. Now either run your tests or start up your app and verify that everything works. It should, since your project Gemfile is using that same version of Adhearsion that you were using before.
Step 4: Check out the first known "bad" commit
Now head back to the Adhearsion tab in your terminal, and checkout the commit where something went wrong. If it were the latest version you tried, in our example Adhearsion 2.2.1, you'd do
git checkout 9542998
Back in your application tab, you can run the test suite or start the app up and try it out. This step should fail.
Step 5: Set up git bisect
At this point, we have a choice. We can manually checkout each commit between where we were and where we are, checking each one for errors. This can be a lengthy process - especially if a simple test suite run doesn’t reveal the problem and you’re forced to go through a 5-minute process to recreate the bug. Unfortunately for me, this is exactly what I did before I knew about git bisect. It made for a very long afternoon!
To begin the process the
git bisect way, enter these 3 commands:
git bisect git bisect good e6e1d6e # the commit hash from Adhearsion 2.0.0 git bisect bad 9542998 # the commit hash from Adhearsion 2.2.1
For bisect good, we put the hash for the known working one, and for bisect bad we put the hash of the version we first noticed causing a problem. Immediately after entering the
git bisect bad command into the terminal, git checkouts a commit halfway between the two. Flip over to the tab for your application and run the app/tests to determine whether this is a good or bad commit. Occasionally, you may run into a dependency issue if the Adhearsion .gemspec has changed and requires gems that conflict with versions requested in your application - in this case, you can fix it with a
bundle install. Fortunately these case are rare. Once your tests results are back, flip to the Adhearsion tab and inform git of the results of your test:
- If the tests pass, type
git bisect good
- If the tests fail, type
git bisect bad
By narrowing down the commits by halving, Git bisect will take 4 or 5 attempts before it finds the first bad commit—not the 20 to 30 attempts it would take manually.
Step 6: Use git bisect to iterate through commits
Now we can begin the process of using git bisect's intelligent iteration to find the first known bad commit. Whenever you inform git of whether the current iteration is good or bad, it immediately checks out a new commit for you to try. Keep bouncing back and forth between rebundling, testing your app, and informing git of whether it's good or bad. Stop when git recognizes the first bad commit:
357646fa193b0f431a1ae5298c61f3c8c9efe6ff is the first bad commit
Now we have a nice pointer to a single commit where the error occurred. Since most commits (and hopefully the one you just found) are relatively small amounts of code, this should make troubleshooting much easier.
Step 7: Do your civic duty
Adhearsion is Open Source, and you've just found a bug. Since this bug probably affects other people too, you can help out your fellow developer by letting the gem's maintainers know. Extra credit (and glory, and fame!) if your report includes a fix. For our example, Adhearsion uses Github to track such problems. You might file an Adhearsion issue on Github or pull request that identifies the problem.
With that done, you can stop the bisecting process with:
git bisect reset
Don't forget to restore your app's Gemfile to point to the correct version of Adhearsion!