Tutorial 5: Advanced Examples

Loop over channels, combine them, and format and interrupt debug output.

In this tutorial you will learn how to list all debugging channels and how to write a loop that runs over all existing debug channels. You will make four debug channels in their own namespace and write debug output to a combination of them. You will also learn how to add an error message after a debug message, how to format a debug message, how to suppress the label and how to suppress the newline at the end. Finally you will learn how to write interrupted debug output in an example that prints the call to a system call and the result of that.

The example programs used below live in the examples5 directory of the source distribution; each one is shown in full and is exactly the program whose output is captured underneath it.

Running over all Debug Channels

In tutorial 2 you have learned how to create new Debug Channels. Each new Debug Channel is stored in an internal list, allowing you to loop over all debug channels without knowing exactly which ones exist. For example, the following code will turn on all debug channels. It is not allowed to call on() for a Debug Channel that is already on: that will result in a runtime error.

A special shortcut function is provided to list all debug channels, the following code prints a list of all channels after they have been turned on.

Compile as: g++ -g -DCWDEBUG test5.1.1.cc debug.cc -lcwd -o turn_on

#include "debug.h"
 
int main()
{
  Debug(main_reached());
  // Turn on debug object `libcw_do'.
  Debug(libcw_do.on());
 
  // Turn on all debug channels that are off.
  ForAllDebugChannels(
    if (!debugChannel.is_on())
      debugChannel.on();
  );
 
  // Print a listing of all debug channels to debug object `libcw_do'.
  Debug(list_channels_on(libcw_do));
}

This program outputs:

DEBUG   : Enabled
DUMBO   : Enabled
EINSTEIN: Enabled
ELFUTILS: Enabled
FELIX   : Enabled
HILDAGO : Enabled
NOTICE  : Enabled
SYSTEM  : Enabled
WARNING : Enabled

Debug Channels and name spaces

The custom debug channel dc::ghost that you created in tutorial 2 was put in namespace debug_channels. The debug channels of libcwd are put in namespace libcwd::channels. Nevertheless, it is not necessary to type

Dout(libcwd::channels::dc::notice, "Hello World");

By default, the macro Dout et al. automatically include a using namespace libcwd::channels. It is possible to change this default namespace by defining LIBCWD_DEBUG_CHANNELS before including the header file libcwd/debug.h. This will be shown below.

Of course, you can put your own debug channels also in namespace libcwd::channels but that wouldn't guarantee not to collide with a new debug channel added to libcwd in the future, or with debug channels of other libraries that would do the same.

In the following example we will define four new debug channels in their own namespace example::debug::channels by creating a project specific header file "debug.h" which needs to be included instead of the debug.h from libcwd.

The example application below uses the fictitious libraries libbooster and libturbo, both of which use libcwd themselves and declare their own debug channel namespaces booster::debug::channels and turbo::debug::channels according to the rules as mentioned in the Reference Manual.

The project header file "debug.h":

#ifndef EXAMPLE_DEBUG_H
#define EXAMPLE_DEBUG_H
 
#ifdef CWDEBUG
 
#ifndef LIBCWD_DEBUG_CHANNELS   // This test is only necessary in libraries.
#define LIBCWD_DEBUG_CHANNELS example::debug::channels
#endif
#include <libbooster/debug.h>     // Note that these will include
#include <libturbo/debug.h>       //   libcwd/debug.h for us.
 
namespace example {
  namespace debug {
    namespace channels {
      namespace dc {
        using namespace libcwd;         // For class Channel
 
        // The list of debug channel namespaces of the libraries that we use:
        // (These two already include libcwd::channels::dc)
        using namespace ::booster::debug::channels::dc;
        using namespace ::turbo::debug::channels::dc;
 
        // Our own debug channels:
        extern Channel elephant;
        extern Channel cat;
        extern Channel mouse;
        extern Channel owl;
 
        // When the libraries use the same name for any debug channels,
        // then here is the place to `hide' these channels by redefining them.
        // For example, if `libbooster' defined `notice' too (as does libcwd)
        // then we have to redefine it again:
        using libcwd::channels::dc::notice;
 
      } // namespace dc
    } // namespace channels
  } // namespace debug
} // namespace example
 
// The following is only necessary for libraries.
// Libraries should not use Dout() et al. in their own header files,
// instead we define our own macros here for use in those header files:
#define MyLibHeaderDout(cntrl, ...) \
      LibcwDout(example::debug::channels, ::libcwd::libcw_do, cntrl, __VA_ARGS__)
#define MyLibHeaderDoutFatal(cntrl, ...) \
      LibcwDoutFatal(example::debug::channels, ::libcwd::libcw_do, cntrl, __VA_ARGS__)
 
#else // !CWDEBUG
 
// This is needed so people who don't have libcwd installed can still compile it.
// The file "nodebug.h" is provided in the libcwd source tree and needs to be included
// in your own package.
#include "nodebug.h"
#define MyLibHeaderDout(cntrl, ...)
#define MyLibHeaderDoutFatal(cntrl, ...) LibcwDoutFatal(::std, /*nothing*/, cntrl, __VA_ARGS__)
 
#endif // !CWDEBUG
 
#endif // EXAMPLE_DEBUG_H

The source file "debug.cc":

#include "debug.h"
 
#ifdef CWDEBUG
using namespace libcwd;
 
namespace example {
  namespace debug {
    namespace channels {
      namespace dc {
        Channel elephant("DUMBO");
        Channel cat("FELIX");
        Channel mouse("HILDAGO");
        Channel owl("EINSTEIN");
      }
    }
  }
}
#endif

Combining channels

Debug channels can be on or off and they have a label. Sometimes you might want to write certain debug output to a debug object when any of a given list of debug channels is turned on. The syntax to do that is based on the fact that debug channels can be viewed upon as a bit mask: using operator|. In the following example we will write debug output to several different combinations of the custom debug channels that we defined in the previous paragraph.

The source file "test5.3.1.cc":

#include "debug.h"    // See § 5.2
 
int main()
{
  Debug(main_reached());
  // Start with everything turned on:
  Debug(libcw_do.on());
  ForAllDebugChannels(if (!debugChannel.is_on()) debugChannel.on());
 
  Dout(dc::elephant|dc::owl, "The elephant is called Dumbo, the owl is called Einstein.");
}

This program outputs:

DUMBO   : The elephant is called Dumbo, the owl is called Einstein.

using the label of the left most channel that is turned on.

If we turn off dc::elephant:

#include "debug.h"
 
int main()
{
  Debug(main_reached());
  // Start with everything turned on:
  Debug(libcw_do.on());
  ForAllDebugChannels(if (!debugChannel.is_on()) debugChannel.on());
 
  Debug(dc::elephant.off());
  Dout(dc::elephant|dc::owl, "The elephant is called Dumbo, the owl is called Einstein.");
}

Then the program outputs

EINSTEIN: The elephant is called Dumbo, the owl is called Einstein.

Formatting debug output

It is possible to control the format of debug output in two different ways:

1. Per call to Dout, using control flags.
2. Persistently per debug object, using methods of the debug object.

Control flags

Control flags are unsigned integer bit-masks and are passed along to Dout together with the debug channel(s). For example, in the following code the newline that is normally printed after each output is suppressed in the first call:

#include "debug.h"
 
int main()
{
  Debug(main_reached());
  Debug(libcw_do.on());
  Debug(dc::notice.on());
 
  Dout(dc::notice|nonewline_cf, "Hello, ");
  Dout(dc::notice, "World");
}

This program outputs:

NOTICE  : Hello, NOTICE  : World

In order to suppress the prefix in the second call we use noprefix_cf:

#include "debug.h"
 
int main()
{
  Debug(main_reached());
  Debug(libcw_do.on());
  Debug(dc::notice.on());
 
  Dout(dc::notice|nonewline_cf, "Hello, ");
  Dout(dc::notice|noprefix_cf, "World");
}

Now the output is

NOTICE  : Hello, World

There are in total eleven control flags, see the Reference Manual for an overview.

Let's get a little bit more practical now. In the next example we perform a system call and write this fact to dc::notice in the same way as strace(1) would do; the fact that the call is made is printed first. After the call returns we print the results.

#include "debug.h"
#include <sys/stat.h>
#include <cstdlib>
#include <iostream>
 
std::ostream& operator<<(std::ostream& os, struct stat const buf)
{
  os << "inode:" << buf.st_ino << "; " << "size:" << buf.st_size;
  return os;
}
 
std::ostream& operator<<(std::ostream& os, struct stat const* bufp)
{
  os << "{ " << *bufp << " }";
  return os;
}
 
int main(int argc, char* argv[])
{
  Debug(main_reached());
  Debug(libcw_do.on());
  Debug(dc::notice.on());
 
  if (argc != 2)
  {
    std::cerr << "Usage: " << argv[0] << " <file_name>\n";
    exit(-1);
  }
 
  char const* file_name = argv[1];
  struct stat buf;
 
  // Warning: this is NOT the correct way to do this (see below)
  Dout(dc::notice|nonewline_cf,
       "stat(\"" << file_name << "\", ");
 
  int ret = stat(file_name, &buf);
 
  Dout(dc::notice|noprefix_cf|cond_error_cf(ret != 0),
       &buf << ") = " << ret);
}

Note the use of cond_error_cf(*condition*) which is equal to error_cf if the condition passed is true, or zero otherwise. The result of error_cf is that an error message is printed after the debug output according to the current value of errno. When we run this program with parameter "/bin/ls" we get something like:

NOTICE  : stat("/bin/ls", { inode:3673206; size:162472 }) = 0

And when we use a file that doesn't exist, we get something like:

NOTICE       : stat("foobar", { inode:134572072; size:1 }) = -1: ENOENT (No such file or directory)

As you already might have noticed from the comment in the program, this is not the correct way to do this. The reason that it is wrong is because the call to stat could cause debug output itself. Well, it couldn't in this case, but in a more general case it could :).

Let us replace the call to stat by a function of ourselves that allocates memory (as certain system calls could do too!):

#include "debug.h"
#include <sys/stat.h>
#include <cstdlib>
#include <iostream>
 
std::ostream& operator<<(std::ostream& os, struct stat const buf)
{
  os << "inode:" << buf.st_ino << "; " << "size:" << buf.st_size;
  return os;
}
 
std::ostream& operator<<(std::ostream& os, struct stat const* bufp)
{
  os << "{ " << *bufp << " }";
  return os;
}
 
// We only use this function to show what happens with the debug output,
// you shouldn't do anything like this in a real program.
int stat_with_buf_alloc(char const* file_name, struct stat*& bufp)
{
  bufp = new struct stat;
  return stat(file_name, bufp);
}
 
int main(int argc, char* argv[])
{
  Debug(main_reached());
  Debug(libcw_do.on());
  Debug(dc::notice.on());
 
  if (argc != 2)
  {
    std::cerr << "Usage: " << argv[0] << " <file_name>\n";
    exit(-1);
  }
 
  char const* file_name = argv[1];
  struct stat* bufp;
 
  // This is NOT the correct way to do this.
  Dout(dc::notice|nonewline_cf,
       "stat_with_buf_alloc(\"" << file_name << "\", ");
 
  int ret = stat_with_buf_alloc(file_name, bufp);
 
  Dout(dc::notice|noprefix_cf|cond_error_cf(ret != 0),
       bufp << ") = " << ret);
 
  delete bufp;
}

Now the call (to stat_with_buf_alloc) writes debug output itself which is completely messing up our beautiful attempt to look like the output of strace(1):

NOTICE  : stat_with_buf_alloc("/bin/ls", { inode:3673206; size:162472 }) = 0

Therefore it isn't a good idea to use nonewline_cf and noprefix_cf like this. Use instead continued_cf, dc::continued and dc::finish which are designed especially for interrupted debug output:

#include "debug.h"
#include <sys/stat.h>
#include <cstdlib>
#include <iostream>
 
std::ostream& operator<<(std::ostream& os, struct stat const buf)
{
  os << "inode:" << buf.st_ino << "; " << "size:" << buf.st_size;
  return os;
}
 
std::ostream& operator<<(std::ostream& os, struct stat const* bufp)
{
  os << "{ " << *bufp << " }";
  return os;
}
 
// We only use this function to show what happens with the debug output.
// You shouldn't do anything like this in a real program.
int stat_with_buf_alloc(char const* file_name, struct stat*& bufp)
{
  bufp = new struct stat;
  return stat(file_name, bufp);
}
 
int main(int argc, char* argv[])
{
  Debug(main_reached());
  Debug(libcw_do.on());
  Debug(dc::notice.on());
 
  if (argc != 2)
  {
    std::cerr << "Usage: " << argv[0] << " <file_name>\n";
    exit(-1);
  }
 
  char const* file_name = argv[1];
  struct stat* bufp;
 
  Dout(dc::notice|continued_cf,
       "stat_with_buf_alloc(\"" << file_name << "\", ");
 
  int ret = stat_with_buf_alloc(file_name, bufp);
 
  Dout(dc::finish|cond_error_cf(ret != 0),
       bufp << ") = " << ret);
 
  delete bufp;
}

Now the output looks like

NOTICE  : stat_with_buf_alloc("/bin/ls", { inode:3673206; size:162472 }) = 0

Methods of the debug object

You can also change the format of debug output by calling methods of the debug object. Consider the following example:

#include "debug.h"
 
int main()
{
 
  Debug(libcw_do.on());
  ForAllDebugChannels(if (!debugChannel.is_on()) debugChannel.on());
 
  Debug(libcw_do.margin().assign("<-- margin -->", 14));
  Debug(libcw_do.marker().assign("<-- marker -->", 14));
  Dout(dc::cat|dc::mouse, "The cat chases the mouse.");
  Dout(dc::mouse|dc::elephant, "The mouse chases the elephant.");
  Dout(dc::notice|nolabel_cf, "Setting indentation to 8 spaces:");
  Dout(dc::notice|blank_label_cf, "<------>");
  Debug(libcw_do.set_indent(8));
  Dout(dc::cat, "The cat sleeps.");
  Dout(dc::elephant, "The elephant looks around:");
  Dout(dc::elephant|blank_label_cf|blank_marker_cf, "where did the mouse go?");
}

This program outputs:

<-- margin -->FELIX   <-- marker -->The cat chases the mouse.
<-- margin -->HILDAGO <-- marker -->The mouse chases the elephant.
<-- margin -->Setting indentation to 8 spaces:
<-- margin -->        <-- marker --><------>
<-- margin -->FELIX   <-- marker -->        The cat sleeps.
<-- margin -->DUMBO   <-- marker -->        The elephant looks around:
<-- margin -->                              where did the mouse go?

This concludes this part of the tutorial about debug output.