14C. Avoiding the Swamp: Tracing


Tracing

The most useful general tool for debugging software is tracing. Put prints in your program that turn on the lights so that you can see what is happening. A trace print typically says where the program is, what it is doing and what the relevant variables contain.


What to show in a trace

Never print raw numbers in a trace print. Trace

  printf("%d %d\n", x, y);
is worse than useless. It writes a bunch of numbers. Never print a silly string like
  printf("I am here\n");
That is about like writing "taken last Thursday" on the back of a photograph. (Yes, a person I knew did that.)

  1. Say who is talking. There will typically be many trace prints in your software. Each one should say where it is by giving the name of the function (and possibly the module) in which it occurs. A typical way to do that in function insert is

      if(tracing > 0)
      {
        printf("insert: ...");
      }
    
    showing the name of the function as if you are writing a play and this is a line for insert to speak.

  2. Say where this trace occurs in the function. Is it at the beginning? The end? At the top of a loop body?

  3. Provide relevant information. If you are showing the size of something, write "size = ...", where ... tells the size. Be sure to include important information. You will want to see it for diagnosing errors.

  4. Make traces readable. Do not run consecutive traces all onto one line. Put spaces between different pieces of information. If each trace contains a time, make sure the times are lined up in different traces so that a sequence of lines is easy to read. The reader should be able to scan to a particular part of the scan quickly. Avoid forcing someone reading the trace (you) to read every line carefully. Unreadable trace prints are worse than useless.

    Making a trace readable is more important than following a rigid format. If it improves readability, show the function somewhere after the beginning of a trace line. If showing the function is less important than saying what the program is doing, fine.


Leaving traces in the program

After you have finished debugging a function, do not get rid of trace prints in that function. Leave them in place. But surround each one by a test such as

  if(traceLevel > 0)
  {
    ...
  }
where traceLevel is a global variable (declared outside of functions). Global variables are shared by all functions that occur after their declaration. Normally, the standards forbid the use any global variables, but a variable to control tracing is an exception. If traceLevel is 0, traces are skipped. You turn traces on by setting traceLevel to a positive integer. For example,
  if(traceLevel > 1)
  {
    ...
  }
says only to do this trace for when the trace level 2 or higher.

You can also have more than one variable to control tracing. You typically have a variable for each module or collection of related modules, so that you can trace only what is happening in those modules.

Experts plan for mistakes. They write traces in the software right from the beginning, and do not take the traces out ever.


Standards for tracing

See the standards for tracing.


Adding a compile-time switch

Sometimes you want to leave trace prints in a a piece of software, but also want to be able to avoid the overhead of constantly checking if tracing is turned on in a version that is shipped to customers.

In a C++ program it is easy to get rid of trace prints automatically using conditional compilation. Either do or do not define a preprocessor symbol DEBUG. Then

  #ifdef DEBUG
    if(tracing > 0)
    {
      ...
    }
  #endif
allows you to avoid compiling the entire debug print, including the test of whether tracing > 0.


Avoiding clutter

An unfortunate drawback of trace prints is that they clutter function definitions, making the definitions more difficult to read. One way to avoid that is to move the trace prints out of the definition. Here is an example.

  #ifdef DEBUG
  #  define TRACE_INSERT1\
       if(tracing > 0)\
       {\
         printf("insert [top]: k = %i\n", k);\
       }
  #else
  #  define TRACE_INSERT1 {}
  #endif

  void insert(int k)
  {
    TRACE_INSERT1
    ... (body of insert)
  }
Now each trace print is replaced by one short line inside the function body, so it has minimal impact on the readability of the body.