Talk About Quality

Tom Harris

Read Before Running

leave a comment »

Debugging: How to Start (commonly accepted method)

Search for “debugging” on the internet and most entries will tell you the first step is to reproduce the problem (properly called “the software failure”) and the second step is to create the simplest configuration that also reproduces the problem.

I agree that it is essential to reproduce the problem, because you need to know you’re working on the right problem.

Fun to Run, or “the thrill of the chase”

But programmers, myself included, like to run things—to let the computer do the work—so there’s a great temptation to reproduce the problem, change something, run the software, add some “debugging statements”, and run it again. And there goes an hour of valuable time.

Does readability fit in here somewhere?

If the code is written clearly, and by that I mean that it’s readable, with meaningful variable names and the proper levels of abstraction, then the second step might be to actually read through the code.

A short debugging story

Today, I showed myself both the wrong way, and the right way, to respond to a “bug report”.

Where I work, I’ve turned out to be the owner of a small set of text-parsing scripts, written in awk. We use them to pull out compiler warning messages from the long build logs, so that developers can see them and address them. These parsing scripts are short—half a page of code including comments—and are tested only with the few build logs that I’ve had time to try. Given limited time (it is not my main job to write parsing scripts!), I have to hope that all the build logs for a given compiler are pretty similar, so whatever pattern I’ve identified will be followed in other build logs. It isn’t always so.

A developer noticed (first by eye, confirmed with a simple “grep”) that there were more compiler warnings in his build log than in the parsed csv (comma-separated-value) output file. Not good. I set about debugging!

It took about 5 minutes to reproduce the problem. Really just gathering the sample input and bad output files, and setting up a copy of the relevant scripts. One run (takes about 2 seconds) showed that, indeed, some warnings were missing.

My next step, by the standard debugging technique, was to start printing all the partial results, run the script over and over again, and look to see where it was failing. Then some more time to adjust the failing script and retest.

Haven’t I seen this somewhere before?

After the first 5 minutes (reproducing the problem), I already had a pretty good idea of which script was failing. A sed one-liner that adds newlines after each compilation command line, and before the first warning message, so that the awk script would be able to separate the first warning message as a record and select it. What was odd was that when I opened that script (just one executable line—the rest is comments including change history), the last modification comment was about how I had fixed exactly the same problem before. Briefly I wondered about that, but rushed onward to more than half an hour of running parts of the script pipeline to prove to myself exactly what was failing and why.

I could have saved myself the time.

Debugging: How to Start (the code-reading method)

After reproducing the initial problem (again, just 5 minutes), and arriving at the suspect script with the worrisome comment, I should have stopped running the code, and started reading it. After all, if my last modification was to fix this same problem, then apparently that modification was either wrong, or insufficient.

It turned out, and this was visible by comparing the one-line script and the new build log on which it failed, that it was insufficient. The new build log had some extra spaces at the end of the compilation command line, and the sed one-liner, designed to identify such lines, was unprepared for the extra spaces.

It did take me another 15 minutes to verify that most new build logs had a random number of extra spaces, and thus to pick the right two-character adjustment to the regular expression. Regression testing took another half hour.

But I could have saved myself almost an hour in the middle of “debugging-by-running” if I had applied a few minutes of “debugging by reading the code”.

Even better would have been reading it out loud, or reading and explaining it to someone else.

Written by Tom Harris

February 27, 2008 at 12:04 am

Posted in Code Review

Tagged with

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s