Git debugging – blame and bisect

If the development work is your everyday job, you are dealing with code debugging on daily basis. Various programming languages provide multiple possibilities but Git can also help. Let’s take a look at two useful tools Git provides to help you with this.

If you already know what the problem is

Assume that you already found the piece of code that is the problem. You may wonder when this piece of code was added and by who. If you are using proper commit annotations, such information can be really helpful – given piece of code might be useful back then but should be adjusted today…

Git blame is giving you the information when given piece of code was edited for the last time and by who. Let’s take a look at this:

$ git blame -L 44,46 tools.js
feaf7d3f (dulare 2018-02-14 22:12:26 +0100 44) var executions = req.app.get('executionsThisTime');
feaf7d3f (dulare 2018-02-14 22:12:26 +0100 45) res.removeListener('finish', afterResponse);
feaf7d3f (dulare 2018-02-14 22:12:26 +0100 46) res.removeListener('close', afterResponse);

I simply asked Git to show me the last information about the lines 44-46 of the tools.js file. I can see the partial SHA-1 of the commit (feaf7d3f) the user who adjusted these lines and the date. I can now use git show:

$ git show feaf7d3f
commit feaf7d3f8d4d8c7342daf2edf001aef07e32269d
Author: dulare
Date:   Wed Feb 14 22:12:26 2018 +0100

    code cleanup, request start and end functions moved to the tools module

[...]

It looks like some of the code was moved from somewhere else to the tools module. Let’s see if this is the case also for the code I’m reviewing right now – we will use git blame with -C option which allows us to track file renames and pieces of code being moved from one place to another:

$ git blame -C -L 44,46 tools.js
e57e1c0d app.js (dulare 2018-02-11 23:36:06 +0100 44) var executions = req.app.get('executionsThisTime');
e57e1c0d app.js (dulare 2018-02-11 23:36:06 +0100 45) res.removeListener('finish', afterResponse);
e57e1c0d app.js (dulare 2018-02-11 23:36:06 +0100 46) res.removeListener('close', afterResponse);

Right now, we can see that the original piece of code comes from the app.js file. There is also new commit SHA-1 so we can check the original commit these lines came from:

$ git show e57e1c0d
commit e57e1c0dc4d2c935b4b5951edfd32a920f9efd41
Author: dulare
Date:   Sun Feb 11 23:36:06 2018 +0100

    After response handler - peform actions after the request end

[...]

Unfortunately, you are not always sure where given issue came from. In some cases, you only know that the code was working some time ago but it is not working now.

Finding the problem source with git bisect

Git bisect is the powerful way to find the commit that introduced the issue. Sometimes you have hundreds of commits to check, and the most efficient way is to do the binary search – assuming that the current state is not working, find the place where the code was working for sure and start searching. You may select the commit in the middle between “working” and “not working” manually, check if the code is working and change boundaries. The same can be achieved with less effort using git bisect.

Assume that the current state is not working. I know for sure that the e57e1c0 commit was still good. I will start my bisect section with:

$ git bisect start
$ git bisect bad
$ git bisect good e57e1c0
Bisecting: 19 revisions left to test after this (roughly 4 steps)
[b26eff2f2cfbf34ef16d954b9dca26ab820d6b22] Cleanup of config

I started the bisect session with git bisect start, I told git that the current version is bad and I pointed last good version by using git bisect good e57e1c0. Git started the session, informed me that there are 19 revisions to test in roughly 4 steps and checked out to the commit in the middle.

Now I should test the code and let git know if it is bad or good. I found out that it is still not working so I will use:

$ git bisect bad
Bisecting: 9 revisions left to test after this (roughly 3 steps)
[7494c2135d661cfe4a0a693da7a3d3d16303f25e] Removed unnecessary app setter and usage from tools.js

I’m now checked out to the new place in my commit time line and I can check again. I repeated this for a few times and I finally got my answer:

$ git bisect good
Bisecting: 4 revisions left to test after this (roughly 2 steps)
[7f0db3781ce2e3eaf5e07f7caa59ebaa1d0b2ae6] Installed sequelize, mysql2, sqlite3 packages
$ git bisect good
Bisecting: 2 revisions left to test after this (roughly 1 step)
[be572f848d84e9c7d4fb3d1601cb42aa42add8df] Sqlite basic connection and initial setup
$ git bisect good
Bisecting: 0 revisions left to test after this (roughly 1 step)
[9ce64da9feb8919b10ff7b44dfaf0e4ea7b74cc1] Reorganized, added mocha, added links to the blog
$ git bisect good
b26eff2f2cfbf34ef16d954b9dca26ab820d6b22 is the first bad commit
commit b26eff2f2cfbf34ef16d954b9dca26ab820d6b22
Author: dulare
Date:   Mon Mar 19 20:21:03 2018 +0100

    Cleanup of config

:100644 100644 b8e6b2e197efbf629866ee3b5e7e976e846b3ac1 a548157a756ec511b37dbf2c080adcd358d94f9a M	.gitignore
:100644 100644 461aebbb6f98bc12d147e1a415c2e96f7b584731 e2a5c45192466ac88b7d1a0fc7caf33934107259 M	app.js

Git informed me that the error was introduced in particular commit. I can now check changes made and find the source of an issue. As the last step, I have to reset the state of my repository:

$ git bisect reset
Previous HEAD position was 9ce64da... Reorganized, added mocha, added links to the blog
Switched to branch 'master'

You may note that the repository before reset was not checked out to the first bad commit, but to the previous one, we checked.