Why and how do we redirect debug statements?

Question

I want to know why is it preferred to redirect the debug statements to stderr like it is done here:

#ifdef DEBUG_TEST
  #define DEBUG_TEST 1
  #else
  #define DEBUG_TEST 0
  #endif

  #define DEBUG_PRINT(fmt, ...) \
             do { if (DEBUG_TEST) fprintf(stderr, fmt, ##__VA_ARGS__); } while (0)

Also: How can we redirect these debug statements to a separate log file with a timestamp on that file? I want to do this using a macro in my code.

Platform: Linux, gcc compiler

Answer 1

I can give you two examples of why you would do this: You could then easily redirect standard output to a file while keeping standard error in your terminal (and this seems to be exactly what you want to do in your second question). Your tool(s) might highlight messages sent to stderr making them easier to spot right away.

You could use the command line version to redirect stderr, as thesamet suggests. To get a timestamp in the filename, you could do something like this when you run your program:

./program 2>"logfile-`date`.txt"

If you want to do it in the program itself, one way is to simply use fopen to open another file and write to that. Here is a fully working example you can play with:

#include <time.h>
#include <stdlib.h>
#include <stdio.h>
#include <stdbool.h>

#define DEBUG_TEST true

FILE *debug_file;

#define DEBUG_PRINT(fmt, ...) \
        do { if (DEBUG_TEST) fprintf(debug_file, fmt, ##__VA_ARGS__); } while (false);



int main()
{
        time_t timestamp = time(NULL);
        char * s = malloc(snprintf(NULL, 0, "debug-%d.txt", timestamp));
        sprintf(s, "debug-%d.txt", timestamp);

        debug_file=fopen(s, "w");

        DEBUG_PRINT("YEAH\n");

        fclose(debug_file);

        return EXIT_SUCCESS;
}

Answer 2

Advantage of using stderr over stdout is that if you are redirecting the output to a file or streaming it (using a pipe) to another process, the debugging messages do not get in the way.

If you want to redirect stderr to a file on Unix, you can run your program like this:

./program 2>logfile

Answer 3

One of the reasons you report debug information to stderr rather than stdout because stdout might be sent down a pipeline and your diagnostics would go with the actual data, confusing the subsequent phases of the pipeline.

If you might want to redirect the output, or add timestamps (or PID, or any other information), then do not use fprintf() directly. Call a function of your own devising which deals with the information you want in the way you want.

Thus, your macro could be:

extern void dbg_print(const char *fmt, ...);

#define DEBUG_PRINT(fmt, ...) \
         do { if (DEBUG_TEST) dbg_print(fmt, __VA_ARGS__); } while (0)

Or:

extern void dbg_print(const char *func, const char *file, int line, const char *fmt, ...);

#define DEBUG_PRINT(fmt, ...) \
         do { if (DEBUG_TEST) dbg_print(__func__, __FILE__, __LINE__, fmt, __VA_ARGS__); } while (0)

This includes the function name, file name and line number in the information

For example, I have a moderately complex package that does that. One of the core internal routines is:

/* err_stdio - report error via stdio */
static void err_stdio(FILE *fp, int flags, int errnum, const char *format, va_list args)
{
    if ((flags & ERR_NOARG0) == 0)
        fprintf(fp, "%s: ", arg0);
    if (flags & ERR_STAMP)
    {
        char timbuf[32];
        fprintf(fp, "%s - ", err_time(timbuf, sizeof(timbuf)));
    }
    if (flags & ERR_PID)
        fprintf(fp, "pid=%d: ", (int)getpid());
    vfprintf(fp, format, args);
    if (flags & ERR_ERRNO)
        fprintf(fp, "error (%d) %s\n", errnum, strerror(errnum));
}

The debug wrappers can call onto that function with appropriate flags, and generate the desired output. Other parts of the system control the file stream used (stderr is the default, but there's a function to redirect the output to any other stream), and so on.

If you limit yourself by using fprintf() directly in the debug macro, you are stuck with what fprintf() can do, or recompiling everything.

See also my answer to 'C #define macro for debug printing' for more information about debugging macros and how to use them (though it looks as if you've taken much of what I say there on board already).

Answer 4

Forgive if I am wrong but it seems like no one mentioned buffering.

By default stdout is line buffered on most platforms and stderr is unbuffered. Basically this means that by default writes to stdout are written to memory and written to the file or console in chunks because doing output character by character is slooooow.

If you are debugging you don't want the message to appear much later then you actually mean to print it (or even potentially never print in if your program crashes or is stuck in an infinite loop(this can really mess you up when you think its looping or crashing in the wrong place) and you usually don't mind the speed hit. It could theoretically make a difference due to timing and synchronisation bugs but those it can be hard to catch/debug those in any case.

TL;DR when debugging print to stderr not stdout (other people might suggest logging to a file instead and or allowing runtime options like enabling/disabling printing file,style,threshold,ect).