Tuesday, October 04, 2005

 

Debugging Output

Most computer users have no idea how complicated software can be. It seems very simple, almost like a law of nature, that if one hits the 'A' key on the keyboard, an 'A' will just appear on the screen. Unbeknownst to software users, thousands or even millions of lines of program code may have been executed to make that happen, and it was all written by fallable people. When there is a bug somewhere in those thousands or millions of lines of code, finding it is a daunting task.

To help find exactly where a problem is occurring, software developers create debug output. This is information about program execution which is invisible to the typical user, but which the developer can view when needed. The output usually goes to a log file, or may be visible in a debugger window or other special viewer application while the program is running.

There are two times when developers add debug output to their programs:

  1. while adding new functionality, and
  2. while trying to figure out why some damn thing isn't working like it should.

It is easy to tell the difference between the two kinds of output. The first kind tends to be orderly and descriptive, providing clear feedback about the operation of the program, like this:

10:08:27  opened file "userdata.dat"
10:08:27  24 record(s) read from "userdata.dat"
10:08:28  closed file "userdata.dat"
10:08:29  24 record(s) inserted into data view

The second kind of debug output, typically written in the wee hours while bouncing between states of intense frustration and sleepy delirium, usually looks more like this:

04:23:17  Boo!
04:23:17  open file "userdata.dat"
04:23:18  its working (2)
04:23:18  24 record(s) read from "userdata.dat"
04:23:18  I'm here (2)
04:23:18  closed file "userdata.dat"
04:23:18  hwnd=0x001248de
04:23:19  its still working (2)
04:23:19  it's still still working (2)
04:23:20  hwnd=0x001248de
04:23:20  Hello, and welcome to the comm thread
04:23:23  it's still^3 working (2)
04:23:24  it's still^4 workign (2) and yeah, I know it's misspelled, so what???
04:23:24  xyzzy
04:23:24  hwnd=0x001248de
04:23:25  !!!hey, this shouldn't happen!!!
04:23:25  Sydney Bristow kicks ass
04:23:25  Entering update_data()
04:23:25  I love bourbon
04:23:25  Dave told me to type this
04:23:26  Take this, beeyotch (2)
04:23:26  24 record(s) inserted into data view
04:23:26  Exiting update_data()
04:23:26  hwnd=0x001248de

That second example may seem like complete gibberish, but its usefulness comes from the fact that the developers know exactly what line of code was being executed when each one of those lines of output was generated. What each line says doesn't really matter—all that matters is that each be uniquely identifiable, so that when something unexpected shows up in the output, the developers know where to look. There is no point in trying to make it clear or meaningful, because the developers didn't really know its significance while writing it. The whimsy and crassness in the messages is the developers' way of entertaining themselves during a time when they wish somebody would be kind enough to sneak up from behind with a baseball bat and end the misery.

Ideally, when a problem is found and corrected, the developers will remove the second kind of debug output, or change it to something that would be more useful. Often, they don't, because when the problem is found, they just want to go home rather than cleaning up the mess. This leads to all sorts of stories about embarrassing messages popping up while users are running the program, while giving a demo to an important customer, or while the boss is looking over one's shoulder. Developers should be more careful about what they write, but their senses of humor and judgment often deteriorate while debugging.

If you ever run across strange or insulting messages while running a program, don't take offense. Just think of the poor developers working a 16-hour workday who wrote the message. The developers didn't really want you to see the message, but it is a human plea for help and comfort. You're getting a glimpse behind the curtain.

I'm an obsessive believer in beautiful code, so I have an irresistable urge to delete or fix this stuff whenever I find it in code that I have to maintain. (If I don't remove it, at the least I need to fix the spelling and punctuation.) So my plea to other programmers is to please clean this stuff up when you don't need it any more.


Comments: Post a Comment

<< Home

This page is powered by Blogger. Isn't yours?