Table of Contents
The syntax of a debugging log file is represented as:
>debugfile< :== { >debugmsg< }
>debugmsg< :== >debughdr< '\n' >debugtext<
>debughdr< :== '[' TIME ',' LEVEL ']' FILE ':' [FUNCTION] '(' LINE ')'
>debugtext< :== { >debugline< }
>debugline< :== TEXT '\n'
TEXT is a string of characters excluding the newline character.
LEVEL is the DEBUG level of the message (an integer in the range 0..10).
TIME is a timestamp.
FILE is the name of the file from which the debug message was generated.
FUNCTION is the function from which the debug message was generated.
LINE is the line number of the debug statement that generated the message.
Basically, what that all means is:
A debugging log file is made up of debug messages.
Each debug message is made up of a header and text. The header is separated from the text by a newline.
The header begins with the timestamp and debug level of the message enclosed in brackets. The filename, function, and line number at which the message was generated follow. The filename is terminated by a colon, and the function name is terminated by the parenthesis which contain the line number. Depending upon the compiler, the function name may be missing (it is generated by the __FUNCTION__ macro, which is not universally implemented, dangit).
The message text is made up of zero or more lines, each terminated by a newline.
Here's some example output:
[1998/08/03 12:55:25, 1] nmbd.c:(659)
Netbios nameserver version 1.9.19-prealpha started.
Copyright Andrew Tridgell 1994-1997
[1998/08/03 12:55:25, 3] loadparm.c:(763)
Initializing global parameters
Note that in the above example the function names are not listed on the header line. That's because the example above was generated on an SGI Indy, and the SGI compiler doesn't support the __FUNCTION__ macro.
Use of the DEBUG() macro is unchanged. DEBUG() takes two parameters. The first is the message level, the second is the body of a function call to the Debug1() function.
That's confusing.
Here's an example which may help a bit. If you would write
printf( "This is a %s message.\n", "debug" );
to send the output to stdout, then you would write
DEBUG( 0, ( "This is a %s message.\n", "debug" ) );
to send the output to the debug file. All of the normal printf() formatting escapes work.
Note that in the above example the DEBUG message level is set to 0. Messages at level 0 always print. Basically, if the message level is less than or equal to the global value DEBUGLEVEL, then the DEBUG statement is processed.
The output of the above example would be something like:
[1998/07/30 16:00:51, 0] file.c:function(128)
This is a debug message.
Each call to DEBUG() creates a new header *unless* the output produced by the previous call to DEBUG() did not end with a '\n'. Output to the debug file is passed through a formatting buffer which is flushed every time a newline is encountered. If the buffer is not empty when DEBUG() is called, the new input is simply appended.
...but that's really just a Kludge. It was put in place because DEBUG() has been used to write partial lines. Here's a simple (dumb) example of the kind of thing I'm talking about:
DEBUG( 0, ("The test returned " ) );
if( test() )
DEBUG(0, ("True") );
else
DEBUG(0, ("False") );
DEBUG(0, (".\n") );
Without the format buffer, the output (assuming test() returned true) would look like this:
[1998/07/30 16:00:51, 0] file.c:function(256)
The test returned
[1998/07/30 16:00:51, 0] file.c:function(258)
True
[1998/07/30 16:00:51, 0] file.c:function(261)
.
Which isn't much use. The format buffer kludge fixes this problem.
In addition to the kludgey solution to the broken line problem described above, there is a clean solution. The DEBUGADD() macro never generates a header. It will append new text to the current debug message even if the format buffer is empty. The syntax of the DEBUGADD() macro is the same as that of the DEBUG() macro.
DEBUG( 0, ("This is the first line.\n" ) );
DEBUGADD( 0, ("This is the second line.\nThis is the third line.\n" ) );
Produces
[1998/07/30 16:00:51, 0] file.c:function(512)
This is the first line.
This is the second line.
This is the third line.
One of the problems with the DEBUG() macro was that DEBUG() lines tended to get a bit long. Consider this example from nmbd_sendannounce.c:
DEBUG(3,("send_local_master_announcement: type %x for name %s on subnet %s for workgroup %s\n",
type, global_myname, subrec->subnet_name, work->work_group));
One solution to this is to break it down using DEBUG() and DEBUGADD(), as follows:
DEBUG( 3, ( "send_local_master_announcement: " ) ); DEBUGADD( 3, ( "type %x for name %s ", type, global_myname ) ); DEBUGADD( 3, ( "on subnet %s ", subrec->subnet_name ) ); DEBUGADD( 3, ( "for workgroup %s\n", work->work_group ) );
A similar, but arguably nicer approach is to use the DEBUGLVL() macro. This macro returns True if the message level is less than or equal to the global DEBUGLEVEL value, so:
if( DEBUGLVL( 3 ) )
{
dbgtext( "send_local_master_announcement: " );
dbgtext( "type %x for name %s ", type, global_myname );
dbgtext( "on subnet %s ", subrec->subnet_name );
dbgtext( "for workgroup %s\n", work->work_group );
}
(The dbgtext() function is explained below.)
There are a few advantages to this scheme:
The test is performed only once.
You can allocate variables off of the stack that will only be used within the DEBUGLVL() block.
Processing that is only relevant to debug output can be contained within the DEBUGLVL() block.
This function prints debug message text to the debug file (and possibly to syslog) via the format buffer. The function uses a variable argument list just like printf() or Debug1(). The input is printed into a buffer using the vslprintf() function, and then passed to format_debug_text(). If you use DEBUGLVL() you will probably print the body of the message using dbgtext().
This is the function that writes a debug message header. Headers are not processed via the format buffer. Also note that if the format buffer is not empty, a call to dbghdr() will not produce any output. See the comments in dbghdr() for more info.
It is not likely that this function will be called directly. It is used by DEBUG() and DEBUGADD().
This is a static function in debug.c. It stores the output text for the body of the message in a buffer until it encounters a newline. When the newline character is found, the buffer is written to the debug file via the Debug1() function, and the buffer is reset. This allows us to add the indentation at the beginning of each line of the message body, and also ensures that the output is written a line at a time (which cleans up syslog output).