This article will give you some hints on how to produce useful diagnostic messages by enhancing OS error messages, and using your own messages to good effect. Symbolic debuggers such as !DDT have their place, but outputting messages at strategic points can produce more useful information. Also, debuggers can have side-effects which completely mask bugs, and Acorn's DDT can be rather awkward and unreliable.

Where to output messages

Rather than go to the extra trouble of opening and closing a log file from my programs, I nearly always use the stderr file stream from the standard library. Using a standard stream makes it very easy to add messages to the file using calls such as printf.

By default, messages sent to stderr appear on the screen, but it can be redirected by adding 2>LogFileName to the end of the command line which calls the C program (usually !RunImage in an application), where LogFileName is the name of the log file you want to create. Using a single '>' means any existing file with that name will be overwritten each time the program starts. If you want to preserve messages from previous runs, use a pair of symbols, '>>' instead. Note that this sort of redirection is handled by the Shared C library, not RISC OS's shell, which requires '{}' braces around the redirection and works on a lower level.

So with what we know so far, we can produce messages from anywhere in our program with lines such as:

fprintf(stderr, "The value of x" " is %d\n", x);

If you have a very serious error which crashes the system before the messages are cleared out of RAM buffers onto disc, you can add:

fflush(stderr);

Enhancing OS error messages with context

BOOL Error_Check(os_error *);

and its purpose is to check whether SWIs (or calls to veneers such as Wimp_) were successful, so where you might write:

Wimp_CreateWindow(&winblock, &handle);

instead you write:

Error_Check(Wimp_CreateWindow(&winblock, &handle));

Error_Check tests whether the value of its parameter is zero or points to an error. If zero, it returns FALSE, otherwise it calls Wimp_ReportError then returns TRUE. There is also an Error_CheckFatal, which is similar except that it has a void return type and exits instead of returning if there is an error.

Typing out Error_Check (or equivalent) every time I call a SWI or low-level function is quite inconvenient, so instead I use a macro simply called E. Using a macro also means we can perform some very useful tricks before forwarding on to Error_Check. The first trick is simply that we probably want to log the message as well as report it - that's easy.

The second trick is to add context. How often have you seen an error message which simply says something like "Illegal window handle", but you have little idea which window handle is causing the problem and where? We can do something about this, taking advantage of two macros built into the compiler, __FILE__ and __LINE__. The __FILE__ expands to a string containing the name of the source file, and __LINE__ is a numerical value of the line number the macro appears in. So we can change the definition of E to:

#define E(e) my_Error_Check((e) \, __LINE__, __FILE__)

where my_Error_Check would be defined as something like:

BOOL my_Error_Check(os_error *e, int line, const char *file)
{
    os_error lerr;
    if (!e)
        return FALSE;
    lerr.errnum = e->errnum;
    sprintf(lerr.errmess,
            "Error \"%s\" (code 0x%x) at line %d of %s",
            e->errmess, e->errnum, line, file);
    fputs(stderr, lerr.errmess);
    putc('\n', stderr);
    return Error_Check(&lerr);
}

Going back to the macro definition, note the extra brackets around the occurrence of e in the body. This is important because it allows e to be treated as a single expression even if you pass the macro a more complex one; if the expression contained a comma operator, the macro would fail to compile without those brackets. As a rule of thumb, always bracket the arguments in macro bodies unless you're sure that the macro makes it impossible for this confusion to arise (and even then, extra brackets won't hurt), or you're performing some trick - more of which below.

The third trick is that macros can easily be redefined, so during developing you'd use the above technique, then for a release, you could change it back to simply forwarding to Error_Check to avoid cluttering up the code with the extra strings. As well as E and EF (F for Fatal) you might like an additional macro which does the same as E in development builds, but ignores the error for releases:

#define EI(e) e

Similarly, when you've finished debugging, you can simplify E to:

#define E(e) Error_Check(e)

Doing the same for Desk

Desk veneers can return any type of value rather than being constrained to returning an os_error pointer with a consistent use, so an E macro for Desk will have to wrap whole statements, not just the veneer/SWI expression.

The example line we used above, converted to Desk, would become:

E(handle =
  Desk_Wimp_CreateWindow(
       &winblock));

The macro definition for E is considerably more complicated:

#define E(e) Desk_Error2_Try { \
           e; \
       } Desk_Error2_Catch { \
           my_Error_Check(__FILE__,  __LINE__); \
       } Desk_Error2_EndCatch

and my_Error_Check:

void my_Error_Check(const char *file, int line)
{
    Desk_os_error nerr, *oerr;
    oerr = Desk_Error2_ConvertToOS2();
    nerr.errnum = oerr->errnum;
    sprintf(nerr.errmess, "%s [at line %d of %s]",
            oerr->errmess, line, file);
    Desk_Error2_Check(&nerr);
}

This converts the error to an OS error (a sort of highest common denominator in terms of information made available), generates a new error message with added context information, and throws it. I have verified with a test program that you can throw a new exception from within a Desk catch block, but you might feel that it's more appropriate to modify Desk_error2_globalblock and call Desk_Error2_ReThrow. If you do, bear in mind that the result of Desk_Error2_ConvertToOS2 might point to Desk_error2_globalblock's existing data, so you should make a temporary copy of the string when modifying it.

void log_printf(const char *format, ...)
{
    va_list ap;
    va_start(ap, format);
    vfprintf(stderr, format, ap);
    /* fflush(stderr); */
    /* Uncomment the above line if
       crashes are severe enough to
       prevent automatic flushing. */
    va_end(ap);
}

An advanced macro trick

If we provide a function like the one in the box below, we can do this with the macro:

#define LOG(msg) log_printf ## msg

The important thing is that when we call LOG, we put double brackets around the message and arguments, like this:

LOG(("Value of x is %d\n", x));

Then the LOG macro will be passed a single argument:

("Value of x is %d\n", x)

and the ## operator will convert the line to:

log_printf ("Value of x is %d\n", x);

If you don't want logging enabled, simply change the macro definition to:

#define LOG(a)

and no code will be generated for calls to LOG; therefore it's important to make sure such calls have no side-effects, e.g. changing values of important variables.

Conclusion