Tracking origin of bugs with git bisect

Disect
Disect the rocket, image by ProudloveNathan Proudlove

I’ve been involved with a iOS project this past week. I’m adding functionalities to the CommonSense iOS library. One of the most annoying thing is that it took about 2 minute to load the project. This is only happened in the unstable branch. The master branch seems to be working fine. So I knew that somewhere there is a commit when this starts happening.

Now this is a good example where git bisect is very useful. It will perform a binary search through commit history until the first bad commit found. So you start with a commit and you marked is as a ‘good’ or ‘bad’. Then every time you mark a commit as good / bad, it will then checkout another commit half way in the middle point between previous history. In each checkout then you test the code and see whether the bugs exist or not.

Here is an example

1# let's start  bisecting, Im in unstable branch,
2➜ sense-ios-library git:(unstable) $ git bisect start

the prompt sense-ios-library shows the current folder, and git:(unstable) show current commit. it’s part of oh-my-zsh plugin

 1# I open the xcode, and it took quite a long time. so let's marks current revision as bad
 2➜ sense-ios-library git:(unstable) $ git bisect bad
 3
 4# I know the master branch don't have this problem, so let's mark it as good
 5➜ sense-ios-library git:(unstable) $ git bisect good master 
 6
 7Bisecting: 9 revisions left to test after this (roughly 3 steps)
 8[c1841c0f99a4fa788c14c7437fac7c9547c768c9] Merge pull request #45 from senseobservationsystems/feature-KeepDataLocally
 9
10# now I'm in c1841 commit, I tested again with xcode, and found no problem, mark it as good
11
12➜  sense2 git:(c1841c0) $ git bisect good
13
14Bisecting: 4 revisions left to test after this (roughly 2 steps)
15[06bbd23c4af8f7008abfb814e1375b271e0b23e9] Update interface and write tests lsit( APPEND CMAKE_CXX_FLAGS "-std=c++0x")
16
17# tested again, it's good
18➜  sense2 git:(06bbd23) $ git bisect good
19
20Bisecting: 2 revisions left to test after this (roughly 1 step)
21[71517b7923143a8cf1ce205341dd6942c9468198] Added threshold for checking to remove old data from local storage to save battery life
22
23# Tested again, Now I'm beginning to see the problem. Let's mark this bad
24➜  sense2 git:(71517b7) $ git bisect bad
25
26Bisecting: 0 revisions left to test after this (roughly 0 steps)
27[e5c40d450193ac14fc2faa8c1f4dba2c7c2646f1] Updated functionality and tests of getting local data
28
29# .... 
30# and we keep doing this until we find the first commit when it was introduced.
31
32# Now let's check our progress using log
33
34➜  sense-ios-library git:(71517b7) $ git bisect log
35
36git bisect start
37# bad: [af42213324297e1234767f9224ec1af326514292] Merge pull request #48 from senseobservationsystems/feature-LocalStorageInterface
38git bisect bad af42213324297e1234767f9224ec1af326514292
39# good: [19f751627d152b89d3f2ecadb144507fcf9293fc] Merge pull request #43 from senseobservationsystems/unstable
40git bisect good 19f751627d152b89d3f2ecadb144507fcf9293fc
41# good: [c1841c0f99a4fa788c14c7437fac7c9547c768c9] Merge pull request #45 from senseobservationsystems/feature-KeepDataLocally
42git bisect good c1841c0f99a4fa788c14c7437fac7c9547c768c9
43# good: [06bbd23c4af8f7008abfb814e1375b271e0b23e9] Update interface and write tests lsit( APPEND CMAKE_CXX_FLAGS "-std=c++0x")
44git bisect good 06bbd23c4af8f7008abfb814e1375b271e0b23e9
45
46# when you reach the final commit, you will be shown the commit log and modified file
47
48➜  sense2 git:(e5c40d4) $ git bisect bad
49
50e5c40d450193ac14fc2faa8c1f4dba2c7c2646f1 is the first bad commit
51commit e5c40d450193ac14fc2faa8c1f4dba2c7c2646f1
52Author: Jhon Doe <jhon-doe@sense-os.nl>
53Date:   Thu Jan 8 14:38:07 2015 +0100
54
55    Updated functionality and tests of getting local data
56
57:040000 040000 0a82ee52c68bae4dacc1fec603ce0747b1df426c cd55743c27d2ba7554dfc3d021616b62957c4bba M  Sense Library Tests
58:040000 040000 8a01944a75e80534124a7a657254e38002518f62 5d14fb11caa352acc7352c85e6a1c08794ae9e65 M  SensePlatform.xcodeproj
59:040000 040000 a5e3eb78c4c352e7c010b8a4e90c12248f0ec9b0 2174d7ad531a7d989d313c826445434a073b433c M  SensePlatformTestAppTests
60:040000 040000 4a40764a31981c172a089cd834eb9666b081f3f5 0713beb3c64f1b6f1d2a7811f59be4a82ec30d66 M  sense platform

Now that you know when was the bugs introduced. you can now start looking at the problem.

I found out there is something that doesn’t feel right here github:commit/e5c40. There is a reference to Xcode.app in one of the folder. So every time I open the project, or switch branch, it will try to look into things inside Xcode.app. So removing the reference indeed solve the problem.

The bisect function is very versatile tool to track down when a bug was introduced. You can even automate the test so you don’t have to check each bisect commit your self. The bisect documentation provide a good explanation about the command and also an example on how to automate the test.

Now go on catch and squash those annoying bug!