Added info about parsing debug messages.
authorChristopher R. Hertel <crh@samba.org>
Tue, 27 Oct 1998 21:07:52 +0000 (21:07 +0000)
committerChristopher R. Hertel <crh@samba.org>
Tue, 27 Oct 1998 21:07:52 +0000 (21:07 +0000)
Chris -)-----
(This used to be commit 26fcdfd082e84df675ad06c7ba8c0cdbf07eed98)

source3/parsing.doc

index d024a22a5159035a47ec93e139478f6e35f4e47a..d26a64ae4e8a264f17d0135ce2bf96461ab2680e 100644 (file)
@@ -150,32 +150,214 @@ About params.c:
   are performed by params.c.  Values are loaded via callbacks to
   loadparm.c.
 
-  
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
+--------------------------------------------------------------------------
 
+                                  Samba DEBUG
+                                       
+Chris Hertel, Samba Team
+July, 1998
+   
+   Here's the scoop on the update to the DEBUG() system.
+   
+   First, my goals are:
+     * Backward compatibility (ie., I don't want to break any Samba code
+       that already works).
+     * Debug output should be timestamped and easy to read (format-wise).
+     * Debug output should be parsable by software.
+     * There should be convenient tools for composing debug messages.
+       
+   NOTE: the Debug functionality has been moved from util.c to the new
+   debug.c module.
+   
+New Output Syntax
+
+   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.
+   
+The DEBUG() 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.
+   
+The DEBUGADD() Macro
+
+   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.
+
+The DEBUGLVL() Macro
+
+   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.
+       
+New Functions
+
+   dbgtext()
+          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(). 
+          
+   dbghdr()
+          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().
+          
+   format_debug_text()
+          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).