I was tasked with fixing a bug that looks like it was introduced some time ago. The bug was in an unfamiliar area of the code. Although I thought I found the problem, I wanted to see what commit caused the issue so I could validate my fix, so that I wasn’t patching a symptom. A complication is that there was no automated test for the bug in any of the commits. Validation required browsing the web site through multiple steps.

Enter ‘git bisect’. Bisect uses a binary search to locate the commit that caused an issue. The assumption is that within a range of commits, a commit broke something (‘bad’ in bisect terminology) and it’s stayed broken through the end of the range.

The binary search algorithm will start in the middle, say commit 5, and test that. If it’s bad, we know the first bad commit is somewhere between 1 and 5. So we try commit 3 and find it’s good. The bad commit is somewhere between 4 and 5. The process continues until we’ve narrowed down to a single commit. Usually the latest commit (HEAD) is bad. We’ve got to find a good one for the beginning of the range. Usually we know something about that, such as the last release in which the feature worked, or trying something far enough back in the past.

Bisect can be used manually or with a script. Manual usage is a combination of bisect choosing a commit to checkout for you, you build and test, and then report back to bisect whether the commit is working or broken. ‘git bisect run’ takes a script as an argument whose return code instructs bisect how things turned out. So then you issue the ‘git bisect run’ command with the appropriate arguments and some time later bisect tells you which commit is to blame. You can read the git-bisect manual page at https://www.kernel.org/pub/software/scm/git/docs/git-bisect.html for complete details.

The script is responsible for everything after the checkout. In this case that means building, deploying, browsing and verifying the output. Sometimes a patch is needed to enable testing or other behavior, that will be done here (as well as reverting so bisect can do the next checkout). The return codes are expected as follows:

• 0 = commit is good
• 1-124 = commit is bad, i.e. the test fails
• 125 = skip this commit, something else is wrong like it won’t build
• 126-127 = reserved, causes bisect to stop the process

The test script can test any issue you’d like such as build issues, unit tests, etc. A particularly hard problem is when automated processes will not expose the issue. This was my case and I decided to use curl to script a test together for bisect.

I created a Grails project and example scripts to illustrate how this works. I injected a bug in one of the commits that causes updating an existing record to fail. You can run the Grails application, add a Person record, edit it, and then try to save the changes. The saving part fails. The code is in GitHub and runs on OS X, Linux and possibly cygwin for Windows.

Get the Example

Create a directory for the example and check it out:

$ mkdir git-bisect-example
$ cd git-bisect-example
$ git clone https://github.com/double16/git-bisect-curl-app.git
$ git clone https://github.com/double16/git-bisect-curl-script.git

The application is using the Grails wrapper so all you need is JDK 6+ installed and it will handle the rest. Let’s get everything downloaded first otherwise the test script will time out. This part may take some time.

$ cd git-bisect-curl-app
$ ./grailsw RunApp
Downloading http://dist.springframework.org.s3.amazonaws.com/release/GRAILS/grails-2.3.6.zip to ~/.grails/wrapper/grails-2.3.6-download.zip
..............
| Server running. Browse to http://localhost:8090/git-bisect-curl-app

Hit Ctrl-C to stop the application. The test script will build, start and stop it as needed.

Run Bisect

You should already be in the git-bisect-curl-app directory. If not, get there. There is a process behind bisect, the manual page is good at explaining it. You need to start the bisect process and give it some hints on finding your bug, which is a good and bad commit that defines the search range.

$ git bisect start

The following commands mark commits as good or bad. If you use ‘git log’ you’ll see these are the first and last commits in this example. It doesn’t have to be this way and likely won’t be on a real project. The first part of the range needs to pass the test and the last part must fail the test. Otherwise bisect will give you a false result. Remember this uses a binary search which only works on a sorted list.

$ git bisect good bec9cb5ac8a6d37498753aa9c4c2b6ce3159f51f
$ git bisect bad 8c1a4547ed44041e1bd6f8d5a164faf50a347add
Bisecting: 3 revisions left to test after this (roughly 2 steps)
[d373d864c6f0edaf714a626f8ddfdedb3407da37] Add phone to Person

Now the cool part. Tell bisect to find your bug using the script that does the test and reports using the status code. The scripts in this example have “-x” turned on so you’ll see the commands as they run.

$ git bisect run ../git-bisect-curl-script/bisect.sh

If all goes well, bisect will tell you which commit caused the issue:

a1bd322b4a4552c0e98939be0e7811e02f52f223 is the first bad commit
commit a1bd322b4a4552c0e98939be0e7811e02f52f223
Author: Patrick Double <pat@patdouble.com>
Date:   Sun Mar 2 17:04:47 2014 -0600

    Add favorite color to Person and fix phone constraints

    This is also the place where we break the update form.

:040000 040000 6fc1c6f0fee4353d59188b92065a953f1a332f4b 9a668e34d12ad4f9702a9e078e762e92c0a3666c M	grails-app
bisect run success

Now you can look at the diff and determine what code changes are necessary to fix the issue.

If you are curious which commits bisect tested you can use the ‘git bisect log’ command. This log is designed to be used by the ‘git bisect replay’ command, which is used if something goes wrong and you need to update your test script. You can restart the bisect process and replay this log without having to re-run tests for those commits. The line starting with a # tells you whether a commit is bad or good. The next line is a bisect command that ‘git bisect replay’ will use. They tell you the same thing, that particular commit is good or bad.

$ git bisect log
git bisect start
# bad: [8c1a4547ed44041e1bd6f8d5a164faf50a347add] Add email to Person
git bisect bad 8c1a4547ed44041e1bd6f8d5a164faf50a347add
# good: [bec9cb5ac8a6d37498753aa9c4c2b6ce3159f51f] Grails generated app
git bisect good bec9cb5ac8a6d37498753aa9c4c2b6ce3159f51f
# good: [d373d864c6f0edaf714a626f8ddfdedb3407da37] Add phone to Person
git bisect good d373d864c6f0edaf714a626f8ddfdedb3407da37
# bad: [0f1228fd1653996299c8c07b4ff1f94a11608101] Add birth country to Person
git bisect bad 0f1228fd1653996299c8c07b4ff1f94a11608101
# bad: [a1bd322b4a4552c0e98939be0e7811e02f52f223] Add favorite color to Person and fix phone constraints
git bisect bad a1bd322b4a4552c0e98939be0e7811e02f52f223
# first bad commit: [a1bd322b4a4552c0e98939be0e7811e02f52f223] Add favorite color to Person and fix phone constraints

When you’re done, issue the following command to stop the bisect process and return to the HEAD of the branch you’re on:

$ git bisect reset
Previous HEAD position was a1bd322...  Add favorite color to Person and fix phone constraints
Switched to branch 'master'

Scripts

Here are the scripts. I split into two, one that manages the Grails application (bisect.sh) and one that performs the test (test.sh). With this approach I can debug my test script on a running application without starting and stopping each time. You can look at them on GitHub at https://github.com/double16/git-bisect-curl-script.

bisect.sh

#!/bin/bash -x

#
# Script intended to be used with 'git bisect' to find issues in the git-bisect-curl-app application. This script does not
# perform the actual application test. For clarity it handles starting and stopping the application only. See 'test.sh' for
# testing the application.
#
# Per git bisect man page: exit status 0 for 'good', 1-124 for 'bad', 125 to 'skip', 126-127 are reserved and will cause bisect to stop.
#

# Get the working directory, it should be the root of the application checkout
WD="$(dirname $0)"

# If there were any patches to enable debugging or install a test harness, put them here

# Start the app
./grailsw -Dserver.port=8090 -Ddisable.auto.recompile=true -non-interactive RunApp &
GRAILS_PID=$!
sleep 30s

# Run the test, includes waiting for the application to start
"${WD}/test.sh"
status=$?

# Stop the app
kill $!
sleep 5s

# undo the patching to allow clean flipping to the next commit
git reset --hard

# return control
exit $status

test.sh

#!/bin/bash -x

#
# Test the application using the web interface with 'curl'. Assume the application has been built and started.
#

# We're going to keep a log of HTML output for validating the test
mkdir -p "$(dirname $0)/log"
LOG="$(dirname $0)/log/test.log"
rm ${LOG}

# The cookie jar is used to maintain the session across curl invocations. We'll tell curl to read from here for requests, write to here for responses.
COOKIE_JAR="$(dirname $0)/log/cookies.txt"
rm -f "${COOKIE_JAR}"

# This is the root of the application we're testing
APP="http://localhost:8090/git-bisect-curl-app/"

# Common curl options:
# --silent	this is an automated script
# --insecure	ignore SSL certs for local testing
# --cookie	use the cookies found in the cookie jar, allows sessions across invocations
# --cookie-jar	store new cookies in the cookie jar, allows sessions across invocations
# --fail	curl should return a failure exit status if the HTTP request fails
# --location	follow HTTP redirects via the Location header
CURL_OPTS="--silent --insecure --cookie "${COOKIE_JAR}" --cookie-jar "${COOKIE_JAR}" --fail --location"

# Ensure the application is running by using the --fail option when an HTTP status code of 400+ is returned
# We wait a maximum of 120 seconds with 15 seconds between checks
START=$(date +%s)
while [ $((($(date +%s)-${START}))) -lt 120 ] && ! curl --silent --cookie-jar "${COOKIE_JAR}" --fail "${APP}">>"${LOG}"; do
	sleep 15s;
done
[ $? -ne 0 ] && exit 125

# Create a new record. Grails in development mode starts with an empty database, so that makes it easier because we don't need to worry about unique constraints, etc.
# --data @-	POST name-value pairs to the URL using a shell "here" document
# Exit 125 (skip commit) on error here because it means creating a new record doesn't work, which isn't what we're looking for
curl ${CURL_OPTS} --data @- "${APP}person/save">>"${LOG}" <<EOF || exit 125
firstName=John&lastName=Doe&phone=8005551212&favoriteColor=&birthCountry=&birthCity=&email=&birthYear=0&create=Create
EOF

# Show the edit record form
# Exit 125 (skip commit) on error here because it means showing the edit form doesn't work, which isn't what we're looking for
curl ${CURL_OPTS} "${APP}person/edit/1">>"${LOG}" || exit 125

# We know the issue is the update action is incorrect, so look in the log for the correct action
grep 'input.*name="_action_update"' "${LOG}" || exit 1

# This is a good commit
exit 0

Conclusion

Git bisect is a great tool that can save a lot of time. If the project has automated unit tests, integration tests and/or functional tests, it’s very easy to use. The reality is that not all projects have complete coverage using automated testing tools. The web front-end can be tested with low effort using curl. In my real world example the process was eight steps with a good amount of POST data and the script was brief and effective.