source3/lib/debug.c

   1 /*
   2    Unix SMB/Netbios implementation.
   3    Version 1.9.
   4    Samba utility functions
   5    Copyright (C) Andrew Tridgell 1992-1998
   6
   7    This program is free software; you can redistribute it and/or modify
   8    it under the terms of the GNU General Public License as published by
   9    the Free Software Foundation; either version 2 of the License, or
  10    (at your option) any later version.
  11
  12    This program is distributed in the hope that it will be useful,
  13    but WITHOUT ANY WARRANTY; without even the implied warranty of
  14    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  15    GNU General Public License for more details.
  16
  17    You should have received a copy of the GNU General Public License
  18    along with this program; if not, write to the Free Software
  19    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
  20 */
  21
  22 #include "includes.h"
  23
  24 /* -------------------------------------------------------------------------- **
  25  * Defines...
  26  *
  27  *  FORMAT_BUFR_MAX - Index of the last byte of the format buffer;
  28  *                    format_bufr[FORMAT_BUFR_MAX] should always be reserved
  29  *                    for a terminating nul byte.
  30  */
  31
  32 #define FORMAT_BUFR_MAX ( sizeof( format_bufr ) - 1 )
  33
  34 /* -------------------------------------------------------------------------- **
  35  * This module implements Samba's debugging utility.
  36  *
  37  * The syntax of a debugging log file is represented as:
  38  *
  39  *  <debugfile> :== { <debugmsg> }
  40  *
  41  *  <debugmsg>  :== <debughdr> '\n' <debugtext>
  42  *
  43  *  <debughdr>  :== '[' TIME ',' LEVEL ']' [ [FILENAME ':'] [FUNCTION '()'] ]
  44  *
  45  *  <debugtext> :== { <debugline> }
  46  *
  47  *  <debugline> :== TEXT '\n'
  48  *
  49  * TEXT     is a string of characters excluding the newline character.
  50  * LEVEL    is the DEBUG level of the message (an integer in the range 0..10).
  51  * TIME     is a timestamp.
  52  * FILENAME is the name of the file from which the debug message was generated.
  53  * FUNCTION is the function from which the debug message was generated.
  54  *
  55  * Basically, what that all means is:
  56  *
  57  * - A debugging log file is made up of debug messages.
  58  *
  59  * - Each debug message is made up of a header and text.  The header is
  60  *   separated from the text by a newline.
  61  *
  62  * - The header begins with the timestamp and debug level of the message
  63  *   enclosed in brackets.  The filename and function from which the
  64  *   message was generated may follow.  The filename is terminated by a
  65  *   colon, and the function name is terminated by parenthesis.
  66  *
  67  * - The message text is made up of zero or more lines, each terminated by
  68  *   a newline.
  69  */
  70
  71 /* -------------------------------------------------------------------------- **
  72  * External variables.
  73  *
  74  *  dbf           - Global debug file handle.
  75  *  debugf        - Debug file name.
  76  *  append_log    - If True, then the output file will be opened in append
  77  *                  mode.
  78  *  DEBUGLEVEL    - System-wide debug message limit.  Messages with message-
  79  *                  levels higher than DEBUGLEVEL will not be processed.
  80  */
  81
  82 FILE   *dbf        = NULL;
  83 pstring debugf     = "";
  84 BOOL    append_log = False;
  85 int     DEBUGLEVEL = 1;
  86
  87
  88 /* -------------------------------------------------------------------------- **
  89  * Internal variables.
  90  *
  91  *  stdout_logging  - Default False, if set to True then dbf will be set to
  92  *                    stdout and debug output will go to dbf only, and not
  93  *                    to syslog.  Set in setup_logging() and read in Debug1().
  94  *
  95  *  debug_count     - Number of debug messages that have been output.
  96  *                    Used to check log size.
  97  *
  98  *  syslog_level    - Internal copy of the message debug level.  Written by
  99  *                    dbghdr() and read by Debug1().
 100  *
 101  *  format_bufr     - Used to format debug messages.  The dbgtext() function
 102  *                    prints debug messages to a string, and then passes the
 103  *                    string to format_debug_text(), which uses format_bufr
 104  *                    to build the formatted output.
 105  *
 106  *  format_pos      - Marks the first free byte of the format_bufr.
 107  */
 108
 109 static BOOL    stdout_logging = False;
 110 static int     debug_count    = 0;
 111 #ifdef WITH_SYSLOG
 112 static int     syslog_level   = 0;
 113 #endif
 114 static pstring format_bufr    = { '\0' };
 115 static size_t     format_pos     = 0;
 116
 117
 118 /* -------------------------------------------------------------------------- **
 119  * Functions...
 120  */
 121
 122 /****************************************************************************
 123 receive a "set debug level" message
 124 ****************************************************************************/
 125 void debug_message(enum message_type msg_type, pid_t src, void *buf, size_t len)
 126 {
 127         int level;
 128         memcpy(&level, buf, sizeof(int));
 129         DEBUGLEVEL = level;
 130         DEBUG(1,("Debug level set to %d from pid %d\n", level, (int)src));
 131 }
 132
 133 /****************************************************************************
 134 send a "set debug level" message
 135 ****************************************************************************/
 136 void debug_message_send(pid_t pid, int level)
 137 {
 138         message_send_pid(pid, MSG_DEBUG, &level, sizeof(int));
 139 }
 140
 141
 142 /* ************************************************************************** **
 143  * get ready for syslog stuff
 144  * ************************************************************************** **
 145  */
 146 void setup_logging(char *pname, BOOL interactive)
 147 {
 148         message_register(MSG_DEBUG, debug_message);
 149
 150         if (interactive) {
 151                 stdout_logging = True;
 152                 dbf = stdout;
 153         }
 154 #ifdef WITH_SYSLOG
 155         else {
 156                 char *p = strrchr( pname,'/' );
 157                 if (p)
 158                         pname = p + 1;
 159 #ifdef LOG_DAEMON
 160                 openlog( pname, LOG_PID, SYSLOG_FACILITY );
 161 #else /* for old systems that have no facility codes. */
 162                 openlog( pname, LOG_PID );
 163 #endif
 164         }
 165 #endif
 166 } /* setup_logging */
 167
 168 /* ************************************************************************** **
 169  * reopen the log files
 170  * note that we now do this unconditionally
 171  * ************************************************************************** **
 172  */
 173 void reopen_logs( void )
 174 {
 175         pstring fname;
 176         mode_t oldumask;
 177
 178         if (DEBUGLEVEL <= 0) {
 179                 if (dbf) {
 180                         (void)fclose(dbf);
 181                         dbf = NULL;
 182                 }
 183                 return;
 184         }
 185
 186         oldumask = umask( 022 );
 187
 188         pstrcpy(fname, debugf );
 189         if (lp_loaded() && (*lp_logfile()))
 190                 pstrcpy(fname, lp_logfile());
 191
 192         pstrcpy( debugf, fname );
 193         if (dbf)
 194                 (void)fclose(dbf);
 195         if (append_log)
 196                 dbf = sys_fopen( debugf, "a" );
 197         else
 198                 dbf = sys_fopen( debugf, "w" );
 199         /* Fix from klausr@ITAP.Physik.Uni-Stuttgart.De
 200          * to fix problem where smbd's that generate less
 201          * than 100 messages keep growing the log.
 202          */
 203         force_check_log_size();
 204         if (dbf)
 205                 setbuf( dbf, NULL );
 206         (void)umask(oldumask);
 207 }
 208
 209
 210 /* ************************************************************************** **
 211  * Force a check of the log size.
 212  * ************************************************************************** **
 213  */
 214 void force_check_log_size( void )
 215 {
 216   debug_count = 100;
 217 }
 218
 219 /***************************************************************************
 220  Check to see if there is any need to check if the logfile has grown too big.
 221 **************************************************************************/
 222
 223 BOOL need_to_check_log_size( void )
 224 {
 225         int maxlog;
 226
 227         if( debug_count++ < 100 )
 228                 return( False );
 229
 230         maxlog = lp_max_log_size() * 1024;
 231         if( !dbf || maxlog <= 0 ) {
 232                 debug_count = 0;
 233                 return(False);
 234         }
 235         return( True );
 236 }
 237
 238 /* ************************************************************************** **
 239  * Check to see if the log has grown to be too big.
 240  * ************************************************************************** **
 241  */
 242
 243 void check_log_size( void )
 244 {
 245   int         maxlog;
 246   SMB_STRUCT_STAT st;
 247
 248   /*
 249    *  We need to be root to check/change log-file, skip this and let the main
 250    *  loop check do a new check as root.
 251    */
 252
 253   if( geteuid() != 0 )
 254     return;
 255
 256   if( !need_to_check_log_size() )
 257     return;
 258
 259   maxlog = lp_max_log_size() * 1024;
 260
 261   if( sys_fstat( fileno( dbf ), &st ) == 0 && st.st_size > maxlog )
 262     {
 263     (void)fclose( dbf );
 264     dbf = NULL;
 265     reopen_logs();
 266     if( dbf && get_file_size( debugf ) > maxlog )
 267       {
 268       pstring name;
 269
 270       (void)fclose( dbf );
 271       dbf = NULL;
 272       slprintf( name, sizeof(name)-1, "%s.old", debugf );
 273       (void)rename( debugf, name );
 274       reopen_logs();
 275       }
 276     }
 277   /*
 278    * Here's where we need to panic if dbf == NULL..
 279    */
 280   if(dbf == NULL) {
 281     dbf = sys_fopen( "/dev/console", "w" );
 282     if(dbf) {
 283       DEBUG(0,("check_log_size: open of debug file %s failed - using console.\n",
 284             debugf ));
 285     } else {
 286       /*
 287        * We cannot continue without a debug file handle.
 288        */
 289       abort();
 290     }
 291   }
 292   debug_count = 0;
 293 } /* check_log_size */
 294
 295 /* ************************************************************************** **
 296  * Write an debug message on the debugfile.
 297  * This is called by dbghdr() and format_debug_text().
 298  * ************************************************************************** **
 299  */
 300 #ifdef HAVE_STDARG_H
 301  int Debug1( char *format_str, ... )
 302 {
 303 #else
 304  int Debug1(va_alist)
 305 va_dcl
 306 {
 307   char *format_str;
 308 #endif
 309   va_list ap;
 310   int old_errno = errno;
 311
 312   if( stdout_logging )
 313     {
 314 #ifdef HAVE_STDARG_H
 315     va_start( ap, format_str );
 316 #else
 317     va_start( ap );
 318     format_str = va_arg( ap, char * );
 319 #endif
 320     if(dbf)
 321       (void)vfprintf( dbf, format_str, ap );
 322     va_end( ap );
 323     errno = old_errno;
 324     return( 0 );
 325     }
 326
 327 #ifdef WITH_SYSLOG
 328   if( !lp_syslog_only() )
 329 #endif
 330     {
 331     if( !dbf )
 332       {
 333       mode_t oldumask = umask( 022 );
 334
 335       if( append_log )
 336         dbf = sys_fopen( debugf, "a" );
 337       else
 338         dbf = sys_fopen( debugf, "w" );
 339       (void)umask( oldumask );
 340       if( dbf )
 341         {
 342         setbuf( dbf, NULL );
 343         }
 344       else
 345         {
 346         errno = old_errno;
 347         return(0);
 348         }
 349       }
 350     }
 351
 352 #ifdef WITH_SYSLOG
 353   if( syslog_level < lp_syslog() )
 354     {
 355     /* map debug levels to syslog() priorities
 356      * note that not all DEBUG(0, ...) calls are
 357      * necessarily errors
 358      */
 359     static int priority_map[] = {
 360       LOG_ERR,     /* 0 */
 361       LOG_WARNING, /* 1 */
 362       LOG_NOTICE,  /* 2 */
 363       LOG_INFO,    /* 3 */
 364       };
 365     int     priority;
 366     pstring msgbuf;
 367
 368     if( syslog_level >= ( sizeof(priority_map) / sizeof(priority_map[0]) )
 369      || syslog_level < 0)
 370       priority = LOG_DEBUG;
 371     else
 372       priority = priority_map[syslog_level];
 373
 374 #ifdef HAVE_STDARG_H
 375     va_start( ap, format_str );
 376 #else
 377     va_start( ap );
 378     format_str = va_arg( ap, char * );
 379 #endif
 380     vslprintf( msgbuf, sizeof(msgbuf)-1, format_str, ap );
 381     va_end( ap );
 382
 383     msgbuf[255] = '\0';
 384     syslog( priority, "%s", msgbuf );
 385     }
 386 #endif
 387
 388   check_log_size();
 389
 390 #ifdef WITH_SYSLOG
 391   if( !lp_syslog_only() )
 392 #endif
 393     {
 394 #ifdef HAVE_STDARG_H
 395     va_start( ap, format_str );
 396 #else
 397     va_start( ap );
 398     format_str = va_arg( ap, char * );
 399 #endif
 400     if(dbf)
 401       (void)vfprintf( dbf, format_str, ap );
 402     va_end( ap );
 403     if(dbf)
 404       (void)fflush( dbf );
 405     }
 406
 407   errno = old_errno;
 408
 409   return( 0 );
 410   } /* Debug1 */
 411
 412
 413 /* ************************************************************************** **
 414  * Print the buffer content via Debug1(), then reset the buffer.
 415  *
 416  *  Input:  none
 417  *  Output: none
 418  *
 419  * ************************************************************************** **
 420  */
 421 static void bufr_print( void )
 422   {
 423   format_bufr[format_pos] = '\0';
 424   (void)Debug1( "%s", format_bufr );
 425   format_pos = 0;
 426   } /* bufr_print */
 427
 428 /* ************************************************************************** **
 429  * Format the debug message text.
 430  *
 431  *  Input:  msg - Text to be added to the "current" debug message text.
 432  *
 433  *  Output: none.
 434  *
 435  *  Notes:  The purpose of this is two-fold.  First, each call to syslog()
 436  *          (used by Debug1(), see above) generates a new line of syslog
 437  *          output.  This is fixed by storing the partial lines until the
 438  *          newline character is encountered.  Second, printing the debug
 439  *          message lines when a newline is encountered allows us to add
 440  *          spaces, thus indenting the body of the message and making it
 441  *          more readable.
 442  *
 443  * ************************************************************************** **
 444  */
 445 static void format_debug_text( char *msg )
 446   {
 447   size_t i;
 448   BOOL timestamp = (!stdout_logging && (lp_timestamp_logs() ||
 449                                         !(lp_loaded())));
 450
 451   for( i = 0; msg[i]; i++ )
 452     {
 453     /* Indent two spaces at each new line. */
 454     if(timestamp && 0 == format_pos)
 455       {
 456       format_bufr[0] = format_bufr[1] = ' ';
 457       format_pos = 2;
 458       }
 459
 460     /* If there's room, copy the character to the format buffer. */
 461     if( format_pos < FORMAT_BUFR_MAX )
 462       format_bufr[format_pos++] = msg[i];
 463
 464     /* If a newline is encountered, print & restart. */
 465     if( '\n' == msg[i] )
 466       bufr_print();
 467
 468     /* If the buffer is full dump it out, reset it, and put out a line
 469      * continuation indicator.
 470      */
 471     if( format_pos >= FORMAT_BUFR_MAX )
 472       {
 473       bufr_print();
 474       (void)Debug1( " +>\n" );
 475       }
 476     }
 477
 478   /* Just to be safe... */
 479   format_bufr[format_pos] = '\0';
 480   } /* format_debug_text */
 481
 482 /* ************************************************************************** **
 483  * Flush debug output, including the format buffer content.
 484  *
 485  *  Input:  none
 486  *  Output: none
 487  *
 488  * ************************************************************************** **
 489  */
 490 void dbgflush( void )
 491   {
 492   bufr_print();
 493   if(dbf)
 494     (void)fflush( dbf );
 495   } /* dbgflush */
 496
 497 /* ************************************************************************** **
 498  * Print a Debug Header.
 499  *
 500  *  Input:  level - Debug level of the message (not the system-wide debug
 501  *                  level.
 502  *          file  - Pointer to a string containing the name of the file
 503  *                  from which this function was called, or an empty string
 504  *                  if the __FILE__ macro is not implemented.
 505  *          func  - Pointer to a string containing the name of the function
 506  *                  from which this function was called, or an empty string
 507  *                  if the __FUNCTION__ macro is not implemented.
 508  *          line  - line number of the call to dbghdr, assuming __LINE__
 509  *                  works.
 510  *
 511  *  Output: Always True.  This makes it easy to fudge a call to dbghdr()
 512  *          in a macro, since the function can be called as part of a test.
 513  *          Eg: ( (level <= DEBUGLEVEL) && (dbghdr(level,"",line)) )
 514  *
 515  *  Notes:  This function takes care of setting syslog_level.
 516  *
 517  * ************************************************************************** **
 518  */
 519
 520 BOOL dbghdr( int level, char *file, char *func, int line )
 521 {
 522   /* Ensure we don't lose any real errno value. */
 523   int old_errno = errno;
 524
 525   if( format_pos ) {
 526     /* This is a fudge.  If there is stuff sitting in the format_bufr, then
 527      * the *right* thing to do is to call
 528      *   format_debug_text( "\n" );
 529      * to write the remainder, and then proceed with the new header.
 530      * Unfortunately, there are several places in the code at which
 531      * the DEBUG() macro is used to build partial lines.  That in mind,
 532      * we'll work under the assumption that an incomplete line indicates
 533      * that a new header is *not* desired.
 534      */
 535     return( True );
 536   }
 537
 538 #ifdef WITH_SYSLOG
 539   /* Set syslog_level. */
 540   syslog_level = level;
 541 #endif
 542
 543   /* Don't print a header if we're logging to stdout. */
 544   if( stdout_logging )
 545     return( True );
 546
 547   /* Print the header if timestamps are turned on.  If parameters are
 548    * not yet loaded, then default to timestamps on.
 549    */
 550   if( lp_timestamp_logs() || !(lp_loaded()) ) {
 551     char header_str[200];
 552
 553         header_str[0] = '\0';
 554
 555         if( lp_debug_pid())
 556           slprintf(header_str,sizeof(header_str)-1,", pid=%u",(unsigned int)sys_getpid());
 557
 558         if( lp_debug_uid()) {
 559       size_t hs_len = strlen(header_str);
 560           slprintf(header_str + hs_len,
 561                sizeof(header_str) - 1 - hs_len,
 562                            ", effective(%u, %u), real(%u, %u)",
 563                (unsigned int)geteuid(), (unsigned int)getegid(),
 564                            (unsigned int)getuid(), (unsigned int)getgid());
 565         }
 566
 567     /* Print it all out at once to prevent split syslog output. */
 568     (void)Debug1( "[%s, %d%s] %s:%s(%d)\n",
 569                   timestring(lp_debug_hires_timestamp()), level,
 570                                   header_str, file, func, line );
 571   }
 572
 573   errno = old_errno;
 574   return( True );
 575 }
 576
 577 /* ************************************************************************** **
 578  * Add text to the body of the "current" debug message via the format buffer.
 579  *
 580  *  Input:  format_str  - Format string, as used in printf(), et. al.
 581  *          ...         - Variable argument list.
 582  *
 583  *  ..or..  va_alist    - Old style variable parameter list starting point.
 584  *
 585  *  Output: Always True.  See dbghdr() for more info, though this is not
 586  *          likely to be used in the same way.
 587  *
 588  * ************************************************************************** **
 589  */
 590 #ifdef HAVE_STDARG_H
 591  BOOL dbgtext( char *format_str, ... )
 592   {
 593   va_list ap;
 594   pstring msgbuf;
 595
 596   va_start( ap, format_str );
 597   vslprintf( msgbuf, sizeof(msgbuf)-1, format_str, ap );
 598   va_end( ap );
 599
 600   format_debug_text( msgbuf );
 601
 602   return( True );
 603   } /* dbgtext */
 604
 605 #else
 606  BOOL dbgtext( va_alist )
 607  va_dcl
 608   {
 609   char *format_str;
 610   va_list ap;
 611   pstring msgbuf;
 612
 613   va_start( ap );
 614   format_str = va_arg( ap, char * );
 615   vslprintf( msgbuf, sizeof(msgbuf)-1, format_str, ap );
 616   va_end( ap );
 617
 618   format_debug_text( msgbuf );
 619
 620   return( True );
 621   } /* dbgtext */
 622
 623 #endif
 624
 625 /* ************************************************************************** */