RSS

CEK.io

Chris EK, on life as a continually learning software engineer.

Debugging With Git: Log -S, Bisect, and Blame

At a recent meetup, Danielle Sucher discussed debugging in Ruby. Be jealous—those who came were given rubber duckies, since no talk on debugging would be complete without mentioning rubber duck debugging.

Rubber ducks aside, Danielle mentioned some helpful git commands when it comes to debugging—git bisect, git blame, and git log -S—which I’ll cover in more detail here.

Log -S

git log is a common command. It shows the commit logs. But what happens with the -S flag? Quoting the documentation here, git log -S [string] “look[s] for differences that change the number of occurrences of the specified string (i.e. addition/deletion) in a file.”

In the Bitcoin payment app I built (with Alex, whose name appears below), the send_bitcoin method was an obviously important one. If I wanted to see all commits in which that method was newly introduced or called, I could run git log -S “send_bitcoin”, and I’d see the log below.

Blame

git blame“show[s] what revision and author last modified each line of a file”. What does that mean? You can “blame” a given developer for a line of code they changed or, more generally, just understand who has made the most recent changes to each line.

Sticking to the Bitcoin payment app, suppose I wanted to see the most recent change to the send_bitcoin message, within its context. Since that method occurs in the user model, I can run git blame app/models/user.rb to see the commit hash, the author, the date/time, and the actual code for each line in that file. I know that the method appears in lines 66-71, so I can add -L [start, end] to see a specific range of lines. In this case, git blame -L 66,71 app/models/user.rb:

Handy, no?

Bisect

Most anyone who’s used git has heard of git bisect, but a lot of us know it as one of those advanced git commands that we shouldn’t mess with. That’s a mistake.

Bisect—“find[ing] by binary search the change that introduced a bug”—can be an invaluable debugging technique. When I first tried it, it seemed that there was a lot going on, but it’s actually pretty simple (at least the basic bisect commands).

The example below shows how it can be done. In a sample app with a long commit history, assume there’s a bug that was introduced somewhere between commit cd27e52 and the current master. There are about a dozen commits between, so the “bug” could be in any one of them. Four main steps:

  1. I run git bisect start to initiate the bisect process.
  2. I mark the current commit (on master) as good with git bisect bad.
  3. I indicate the most recent “good” commit (without the bug) with git bisect good [commit]. Bisect will now binary search through the recent commit history to determine where the bug got started.
  4. Bisect will pull up commits to be checked, which I designate as git bisect good or git bisect bad. Do this enough times, and you’ll see “[commit hash] is the first bad commit”.

Just a couple minutes of debugging, and we’ve already determined the bad commit! (Some bug it must’ve been, in a markdown file). The Git documentation describes a lot of additional git bisect commands.

Bonus: commit messages

Write multi-line commit messages! Somehow I had missed that concept until recently. I thought “good commit messages” meant clearly summarizing the code that was changed and avoiding terrible messages like “ok” or “change method” (though we all know we’ve done it). Tim Pope has written perhaps the best post on git commit messages. If nothing else, write multi-line messages that summarize (first line) and give a detailed explanation of changes (in the full paragraph afterwards).