Chasing a bad commit

Background

While working on a big project where multiple teams merge their feature branches frequently into a release Git branch, developers often run into situations where they find that some of their work have been either removed, modified or affected by someone else's work accidentally. It can happen in smaller teams as well. Two features could have been working perfectly fine until they got merged together and broke something. That's a highly possible case. There are many other cases which could cause such hard to understand and subtle bugs which even continuous integration (CI) systems running the entire test suite of our projects couldn't catch.

We are not going to discuss how such subtle bugs can get into our release branch because that's just a wild territory out there. Instead, we can definitely discuss about how to find a commit that deviated an expected outcome of a certain feature. The deviation could be any behaviour of our code that we can measure distinctively — either good or bad in general.

Finding the exact point where it changed the course of our code base in terms of either of such deviations could be difficult to trace down and involves a lot of efforts if we have to do it manually.

A common problem

Let's assume an example.

We are looking for a commit that broke something in our shipment feature which was working perfectly fine until the last release. We had tagged that release commit with v12.1.0-rc4. We also have a few tests in our test suite that can help us identify whether that commit is good or bad. Then just recently, some teams merged their feature branches that introduced about close to hundred of commits into our release branch. That's a normal practice in our project assuming we have a bunch of teams working on different feature branches constantly. Then suddenly our CI service reports a red build for the tests run on the latest release branch. CI marked that build as failed since it found that the tests related to the shipment feature were failing. That's very unfortunate and all teams are worried now. But why everyone has to worry? Because everyone have to start with the code in the release branch as the base code and build features atop meaning they would get same test failures in their feature branches, too and won't be able to merge that without a succsessful build on CI. Such a cascaded effect slows down the overall progress and morale of the teams, right?!

Cancel the team lunch! :(

Because we are the team responisble for the shipment feature, we need to fix those failing tests in the release branch. But everyone in our team is pretty sure that it's not our fault because the overall shipment feature was working until we released v12.1.0-rc4. But anyway we need to triage and fix it, right? So we start with the HEAD commit in the latest release branch. We confirm that the shipment feature breaks on it by running our test suite. Then we keep checking out to each of the previous commits in the Git history until we find a commit where our test suite passes. In a worst case scenario, that succsessful commit could be the one which is tagged with v12.1.0-rc4 — meaning we have to checkout to about hundred commits one-by-one to find a good commit. The commit made just after that good commit in the commit history tree is what we can refer a bad commit.

If we take such a route, we would end up spending unimaginable hours (or days) chasing down a bad commit. That's definitely not an ideal solution.

A bunch of solutions!

So what options do we have?

• Option 1: We can equally divide the commits between a well known good commit and a bad commit among the team members and manually checkout to each commit accordingly to reduce the overall efforts. This excercise suits that popular saying, work as a team!
• Option 2: The Nerd John in our team has a clever idea to implement a fancy tool that would utilize a binary search algorithm that automatically keeps dividing the commits equally by running the test suite until it finds a commit which was the first bad commit in the commit history. We all know, John's so nerdy!
• Option 3: Use a readymade tool git bisect which comes built-in with git that The Nerd John could have been end up building — but only in its half-baked form.

git bisect: a good solution

The git bisect command uses an efficient binary search algorithm to help us find a commit that we are looking for. It requires us to specify a bad commit and at least a good commit (can specify many good commits though to further narrow down the search). It then keeps bisecting the commits between the specified bad and good commits until it finds the first commit in the commit history that caused the deviation.

The git bisect command can run in either manual (interactive) mode or in a fully automated mode. Before each iteration, bisect needs to know whether the given commit is a bad commit or a good commit.

A very high level depiction of how git bisect works!

Interactive bisect

Let's try the interactive mode first.

We need to start a git bisect session in a clean Git directory.

$ git bisect start

Then we need to tell the SHA of a bad commit to git bisect. We can also use the branch name or a tag name pointing to a commit if we want. Let's assume that in our release branch (which is master branch), the latest commit is a bad commit. Therefore, we can specify that the current HEAD is a bad commit.

# Are we inside the correct branch?
$ git branch
bug/shipment-leg-misconfigured
feature/shipment-calculator
* master
production

# Confirm that the relevant tests are failing here.
$ rspec spec/models/shipment_spec.rb spec/controllers/shipments_controller_spec.rb
...
Finished in 53.9 seconds
238 examples, 3 failures

# Mark the HEAD commit as a bad commit.
$ git bisect bad HEAD # or simply `git bisect bad`

Now let's find the SHA or tag of a good commit that we are aware of.

# Find the SHA or tag of a commit that we assume is a good commit.
$ git log --oneline --graph

# Checkout to that commit or tag.
# Note that we are still in the middle of a bisect operation,
# but it is perfectly fine to execute other git commands such as
# `git checkout`.
$ git checkout v12.1.0-rc4

# And ensure that the relevant tests are passing over there.
$ rspec spec/models/shipment_spec.rb spec/controllers/shipments_controller_spec.rb
...
Finished in 45.8 seconds
221 examples, 0 failures

Because we are already checked out to a good commit, we can simply ask git bisect to mark the current commit as a good commit.

# Because we have already checked out to `v12.1.0-rc4` tag,
# therefore, instead of running `git bisect good v12.1.0-rc4`,
# we can just run —
$ git bisect goodBisecting: 46 revisions left to test after this (roughly 6 steps)[02b0b29] Fix: Flicker in insights graph on dashboard

Notice the output of git bisect good command above. It automatically checked out to a commit which is in the middle of the range of about 91 commits between the HEAD of master branch (bad) and v12.1.0-rc4 (good) commits. That's what bisecting is in general — dividing something in the middle! That output also shows that it would require just about 6 more steps to find out a culprit commit. Ain't that awesome?!

We can use git bisect visualize or git bisect view to see the boundary commits and the current HEAD commit.

$ git bisect view --oneline
* 5b91861 (master, origin/master) Merge 'feature/new-logistics-reports' branch into 'origin/master' branch* ...
* ...
* 02b0b29 (HEAD) Fix: Flicker in insights graph on dashboard* ...
* ...
* 4748ff8 (v12.1.0-rc4) Release v12.1.0-rc4

Let's check if the relevant tests pass or fail here and mark the current HEAD as either good or bad accordingly.

$ rspec spec/models/shipment_spec.rb spec/controllers/shipments_controller_spec.rb
...
Finished in 42.8 seconds
221 examples, 0 failures

Tests are passing meaning it's a good commit. So let's tell git bisect the same.

$ git bisect good
Bisecting: 23 revisions left to test after this (roughly 5 steps)
[794197a] Update profile mutation to allow changing middle name

We keep doing this excercise 5 more times until git bisect reports us the first bad commit.

# Tests failed on this commit, so mark it as a bad commit.
$ git bisect bad
Bisecting: 11 revisions left to test after this (roughly 4 steps)
...

# This is also a bad commit.
$ git bisect bad
Bisecting: 5 revisions left to test after this (roughly 3 steps)
...

# Same, it's a bad commit as well.
$ git bisect bad
Bisecting: 2 revisions left to test after this (roughly 1 step)
...

# Tests are passing here, so mark it as a good commit.
$ git bisect good
Bisecting: 0 revisions left to test after this (roughly 1 step)
...

# Tests are failing, so mark that as a bad commit!
$ git bisect bad
efd1083e15670fe6443e5b569b3c0be0e39e212d is the first bad commitcommit efd1083e15670fe6443e5b569b3c0be0e39e212d
Author: Brandon Ross <[email protected]>
Date:   Fri Jun 19 14:02:09 2020 -0400

    Change the courier service provider to DHL

There's that bad commit we were looking for! Thanks to git bisect — only in about 6 steps, we found the culprit commit which introduced a bug due to which our shipment feature started failing afterwards in our release branch. Now we can have a chat with Bandon who had pushed that commit and see if we can fix the bug that broke the shipment feature and made our poor CI cry!

Since we are done here, let's cleanup the bisect session as a final step. This way, git will return back to the original HEAD before the bisect session was started.

$ git bisect reset
Previous HEAD position was efd1083 Change the courier service provider to DHL
Switched to branch 'master'
Your branch is up to date with 'origin/master'.

Fully automated bisect

Until now, we have been determining ourselves whether a commit is a good commit or a bad commit and were telling the same to git bisect accordingly. That means our manual intervention was needed all the times.

Cannot we do any better?

Yes, we can!

git bisect run can execute any command or script. If that command or script exits with code 0 then git bisect would mark the current commit as a good commit. On the other hand, if that command or script exits with any other code between 1 and 127 (inclusive) except 125 then git bisect would mark the current commit as a bad one.

And we already know that once a commit is marked as either good or bad, git bisect bisects and checks out to the middle commit of the current range and would keep executing the same command or script we provided to git bisect run until it finds out the culprit commit.

Let's try it to understand it better.

# We start the bisect session by providing both good and bad
# commits at the same time.
$ git bisect start HEAD v12.1.0-rc4
Bisecting: 46 revisions left to test after this (roughly 6 steps)
[02b0b29] Fix: Flicker in insights graph on dashboard

# Then we provide our test script "rspec spec/..." that exits
# with 0 when tests pass otherwise exits with a non-zero code
# when tests fail.
$ git bisect run rspec spec/models/shipment_spec.rb spec/controllers/shipments_controller_spec.rb...
Finished in 42.8 seconds
221 examples, 0 failures
Bisecting: 23 revisions left to test after this (roughly 5 steps)
running rspec
...
Bisecting: 11 revisions left to test after this (roughly 4 steps)
running rspec
...
Bisecting: 5 revisions left to test after this (roughly 3 steps)
running rspec
...
Bisecting: 2 revisions left to test after this (roughly 1 step)
running rspec
...
Bisecting: 0 revisions left to test after this (roughly 1 step)
running rspec
...
efd1083e15670fe6443e5b569b3c0be0e39e212d is the first bad commitcommit efd1083e15670fe6443e5b569b3c0be0e39e212d
Author: Brandon Ross <[email protected]>
Date:   Fri Jun 19 14:02:09 2020 -0400

    Change the courier service provider to DHL

That's it! This time, surprisingly we didn't need to intervene at all. git bisect found us the culprit commit on its own (see the highlighted line above).

Compairing this to our initial solution in which we were manually checking out to each of those 91 commits ourselves — isn't this a far better solution?!

Here's a zine that captures this bisection flow in a simplified manner.

'git bisect' in action!

What else?

Sometimes, marking a commit as bad or good doesn't make sense. We may want to say new or old; or slow or fast, etc. depending on the deviation we are looking for.

In such cases, we can define these terms and use them instead of bad or good for marking the commits accordingly.

$ git bisect start --term-new slow --term-old fast
...
$ git bisect terms
Your current terms are fast for the old state
and slow for the new state.

That's it for now, folks. Give a read to the documentation of git bisect here to know more about it.

Until then, happy bisecting!

</div