Debug Logging on AmigaOS

Introduction

The sole purpose of this article is to introduce developers that may be new to AmigaOS to its debug logging function. The Exec library has a function called DebugPrintF() that provides a printf() like API for outputting text to a debug buffer. This buffer can be dumped to disk via the dumpdebugbuffer command, or it can be redirected to a serial port. The debug buffer can survive a warm-reboot so its contents can be recovered after most crashes (so long as the machine does not require a complete reset).

In brief:

• IExec->DebugPrintF() uses the same syntax as printf() and outputs to a debug buffer,
• The debug buffer can either be directed to memory (the default), or to the serial port. See the documentation for kdebug in the sys:documentation/kernel drawer of AmigaOS, and
• The debug buffer in memory can be saved to disk and cleared via: dumpdebugbuffer log.txt clear.

For those who are experienced programmers, the details above are probably all that you require; for everyone else, read on to see how and why debug logging is important, and how it can be used.

The Importance of Debug Logging

Developing software is a complex task. The more functions, if/else calls and loops that a program has, the more complicated its operation becomes. Sooner or later it becomes necessary to examine what a program is doing internally. Many compilers (including GCC on AmigaOS) come with debuggers that allow one to step through a program line by line. However, this can be extremely tedious and is also unsuitable for any program that requires real-time operation. For example, it may be impossible to debug a game by stepping through the code because it has to respond to a player's joystick input (which changes which parts of the program are executed). Regardless, it is useful to provide a log of significant events in a program's operation. See the debug logs output for the RadeonHD driver here and here, as examples.

So, what should be logged. Essentially, this is up to you, the programmer. Whatever information you think will be useful in tracking down bugs/issues, should be logged. Often it would be nice to have a hierarchy of debug levels so that it is not necessary to wade through huge debug files when only high-level information (e.g., warnings and errors) are required. I have created a debug module with a template makefile and test code precisely for this purpose.

The Debug Logging Template

The debug logging module provides a framework for multi-level debug logging. By providing a debug level, it is possible to specify what level of logging is required. An example executable (DebugLoggingTest) and makefile have been provided that show how to use the module.

USING THE DEBUG LOGGING MODULE

The easiest way to learn how to use the debug module is to simply download the template file and look at the provided makefile. After initial download the template is configured to output all debug messages. Type make, and then DebugLoggingTest. Now enter dumpdebugbuffer log.txt clear. Examining log.txt will show all the output messages, each of which can be matched to dprintf() calls in DebugLoggingTest.c.

In the makefile there are three lines containing "CFLAGS." Two of them are commented out (with a # character). The example code can be reconfigured to the other two modes by uncommenting the desired line, and commenting out the other two. Remember to perform a "make clean" before recompiling after making any change to the makefile. The most interesting configuration is the last one. In this configuration the user can enter a debug log level on the command line (e.g., "DebugLoggingTest 10") and thus choose how much debug information is to be output.

To use the debug module in other programs:

• Set the TARGET variable in the makefile to the name of the appliation,
• compile files with the appropriate DEBUG flags set:
  • -DTARGET="$(TARGET)", and
  • -DDEBUG and (optionally) -DDEBUG_LOGLEVEL, or, -DVARLEVEL_DEBUG.
• Insert dprintf() calls into the program where appropriate (e.g., dprintf(DBG_CRITICAL, "A critical error occurred.\n");), and
• the LOG_FUNCTION or LOG_FUNCENTRY/LOG_FUNCEXIT macros could also be useful.

DOCUMENTATION

The debug module/template expects TARGET to be defined as a string giving the name of the program (e.g., in the makefile use -DTARGET="AppName"). It provides two functions:

• dprintf(debugLevel, fmt, ...) whichoutputs debug messages formatted printf style and adds a header giving the application name and the debug level of the message, and
• dprintf_cont(debugLevel, fmt, ...) also outputs debug messages, but minus the header (so that more complicated messages can be output).

Several debug levels have been predefined:

• DBG_CRITICAL for critical errors,
• DBG_WARNING for warnings,
• DBG_INFO for more detailed information,
• DBG_FUNCTIONCALL which should be used for identifying function calls, and
• DBG_INTERNALINFO for even more detailed information

There are also three modes of operation. If DEBUG is defined alone, it will output all debug messages. If, DEBUG_LOGLEVEL is set to a number, all messages will be output that have a debug level at or below that value. Finally, if VARLEVEL_DEBUG is defined, the user (or external code) can set the debug logging level on demand; in this case, the following two functions are defined:

• void setDebugLevel(int debugLevel) which sets the debug logging level, and
• int getDebugLevel() which returns the currently set logging level.

An example debug log message would be:

DebugLoggingTest (0): An example critical error

There are also three macros defined that are useful for monitoring function entries and exits:

• LOG_FUNCTION logs the name of the function that was called,
• LOG_FUNCENTRY logs the entry to a function, but is useful to put at the top of a function, and
• LOG_FUNCEXIT should be put before any return statement, it logs a funciton exit.

LOG_FUNCENTRY and LOG_FUNCEXIT should be used together.

DOWNLOAD

The debug logging module and template.

Author

Copyright (c) 2008 Hans de Ruiter.
Reproduced with permission.
See the original article here.