cups/debug.c

   1 /*
   2  * "$Id$"
   3  *
   4  *   Debugging functions for the Common UNIX Printing System (CUPS).
   5  *
   6  *   Copyright 2008-2009 by Apple Inc.
   7  *
   8  *   These coded instructions, statements, and computer programs are the
   9  *   property of Apple Inc. and are protected by Federal copyright
  10  *   law.  Distribution and use rights are outlined in the file "LICENSE.txt"
  11  *   which should have been included with this file.  If this file is
  12  *   file is missing or damaged, see the license at "http://www.cups.org/".
  13  *
  14  *   This file is subject to the Apple OS-Developed Software exception.
  15  *
  16  * Contents:
  17  *
  18  *   debug_vsnprintf()    - Format a string into a fixed size buffer.
  19  *   _cups_debug_printf() - Write a formatted line to the log.
  20  *   _cups_debug_puts()   - Write a single line to the log.
  21  */
  22
  23 /*
  24  * Include necessary headers...
  25  */
  26
  27 #include "globals.h"
  28 #include "debug.h"
  29 #include <sys/time.h>
  30 #include <fcntl.h>
  31 #include <unistd.h>
  32 #include <regex.h>
  33
  34
  35 /*
  36  * Globals...
  37  */
  38
  39 int                     _cups_debug_fd = -1;
  40                                         /* Debug log file descriptor */
  41
  42
  43 #ifdef DEBUG
  44 /*
  45  * Local globals...
  46  */
  47
  48 static regex_t          *debug_filter = NULL;
  49                                         /* Filter expression for messages */
  50 static int              debug_init = 1; /* Did we initialize debugging? */
  51 #  ifdef HAVE_PTHREAD_H
  52 static int              debug_level = 0;/* Log level (0 to 9) */
  53 static pthread_mutex_t  debug_mutex = PTHREAD_MUTEX_INITIALIZER;
  54                                         /* Mutex to control initialization */
  55 #  endif /* HAVE_PTHREAD_H */
  56
  57
  58 /*
  59  * 'debug_vsnprintf()' - Format a string into a fixed size buffer.
  60  */
  61
  62 int                                     /* O - Number of bytes formatted */
  63 debug_vsnprintf(char       *buffer,     /* O - Output buffer */
  64                 size_t     bufsize,     /* O - Size of output buffer */
  65                 const char *format,     /* I - printf-style format string */
  66                 va_list    ap)          /* I - Pointer to additional arguments */
  67 {
  68   char          *bufptr,                /* Pointer to position in buffer */
  69                 *bufend,                /* Pointer to end of buffer */
  70                 size,                   /* Size character (h, l, L) */
  71                 type;                   /* Format type character */
  72   int           width,                  /* Width of field */
  73                 prec;                   /* Number of characters of precision */
  74   char          tformat[100],           /* Temporary format string for sprintf() */
  75                 *tptr,                  /* Pointer into temporary format */
  76                 temp[1024];             /* Buffer for formatted numbers */
  77   char          *s;                     /* Pointer to string */
  78   int           bytes;                  /* Total number of bytes needed */
  79
  80
  81   if (!buffer || bufsize < 2 || !format)
  82     return (-1);
  83
  84  /*
  85   * Loop through the format string, formatting as needed...
  86   */
  87
  88   bufptr = buffer;
  89   bufend = buffer + bufsize - 1;
  90   bytes  = 0;
  91
  92   while (*format)
  93   {
  94     if (*format == '%')
  95     {
  96       tptr = tformat;
  97       *tptr++ = *format++;
  98
  99       if (*format == '%')
 100       {
 101         if (bufptr < bufend)
 102           *bufptr++ = *format;
 103         bytes ++;
 104         format ++;
 105         continue;
 106       }
 107       else if (strchr(" -+#\'", *format))
 108         *tptr++ = *format++;
 109
 110       if (*format == '*')
 111       {
 112        /*
 113         * Get width from argument...
 114         */
 115
 116         format ++;
 117         width = va_arg(ap, int);
 118
 119         snprintf(tptr, sizeof(tformat) - (tptr - tformat), "%d", width);
 120         tptr += strlen(tptr);
 121       }
 122       else
 123       {
 124         width = 0;
 125
 126         while (isdigit(*format & 255))
 127         {
 128           if (tptr < (tformat + sizeof(tformat) - 1))
 129             *tptr++ = *format;
 130
 131           width = width * 10 + *format++ - '0';
 132         }
 133       }
 134
 135       if (*format == '.')
 136       {
 137         if (tptr < (tformat + sizeof(tformat) - 1))
 138           *tptr++ = *format;
 139
 140         format ++;
 141
 142         if (*format == '*')
 143         {
 144          /*
 145           * Get precision from argument...
 146           */
 147
 148           format ++;
 149           prec = va_arg(ap, int);
 150
 151           snprintf(tptr, sizeof(tformat) - (tptr - tformat), "%d", prec);
 152           tptr += strlen(tptr);
 153         }
 154         else
 155         {
 156           prec = 0;
 157
 158           while (isdigit(*format & 255))
 159           {
 160             if (tptr < (tformat + sizeof(tformat) - 1))
 161               *tptr++ = *format;
 162
 163             prec = prec * 10 + *format++ - '0';
 164           }
 165         }
 166       }
 167
 168       if (*format == 'l' && format[1] == 'l')
 169       {
 170         size = 'L';
 171
 172         if (tptr < (tformat + sizeof(tformat) - 2))
 173         {
 174           *tptr++ = 'l';
 175           *tptr++ = 'l';
 176         }
 177
 178         format += 2;
 179       }
 180       else if (*format == 'h' || *format == 'l' || *format == 'L')
 181       {
 182         if (tptr < (tformat + sizeof(tformat) - 1))
 183           *tptr++ = *format;
 184
 185         size = *format++;
 186       }
 187       else
 188         size = 0;
 189
 190       if (!*format)
 191         break;
 192
 193       if (tptr < (tformat + sizeof(tformat) - 1))
 194         *tptr++ = *format;
 195
 196       type  = *format++;
 197       *tptr = '\0';
 198
 199       switch (type)
 200       {
 201         case 'E' : /* Floating point formats */
 202         case 'G' :
 203         case 'e' :
 204         case 'f' :
 205         case 'g' :
 206             if ((width + 2) > sizeof(temp))
 207               break;
 208
 209             sprintf(temp, tformat, va_arg(ap, double));
 210
 211             bytes += (int)strlen(temp);
 212
 213             if (bufptr)
 214             {
 215               if ((bufptr + strlen(temp)) > bufend)
 216               {
 217                 strncpy(bufptr, temp, (size_t)(bufend - bufptr));
 218                 bufptr = bufend;
 219               }
 220               else
 221               {
 222                 strcpy(bufptr, temp);
 223                 bufptr += strlen(temp);
 224               }
 225             }
 226             break;
 227
 228         case 'B' : /* Integer formats */
 229         case 'X' :
 230         case 'b' :
 231         case 'd' :
 232         case 'i' :
 233         case 'o' :
 234         case 'u' :
 235         case 'x' :
 236             if ((width + 2) > sizeof(temp))
 237               break;
 238
 239 #ifdef HAVE_LONG_LONG
 240             if (size == 'L')
 241               sprintf(temp, tformat, va_arg(ap, long long));
 242             else
 243 #endif /* HAVE_LONG_LONG */
 244             if (size == 'l')
 245               sprintf(temp, tformat, va_arg(ap, long));
 246             else
 247               sprintf(temp, tformat, va_arg(ap, int));
 248
 249             bytes += (int)strlen(temp);
 250
 251             if (bufptr)
 252             {
 253               if ((bufptr + strlen(temp)) > bufend)
 254               {
 255                 strncpy(bufptr, temp, (size_t)(bufend - bufptr));
 256                 bufptr = bufend;
 257               }
 258               else
 259               {
 260                 strcpy(bufptr, temp);
 261                 bufptr += strlen(temp);
 262               }
 263             }
 264             break;
 265
 266         case 'p' : /* Pointer value */
 267             if ((width + 2) > sizeof(temp))
 268               break;
 269
 270             sprintf(temp, tformat, va_arg(ap, void *));
 271
 272             bytes += (int)strlen(temp);
 273
 274             if (bufptr)
 275             {
 276               if ((bufptr + strlen(temp)) > bufend)
 277               {
 278                 strncpy(bufptr, temp, (size_t)(bufend - bufptr));
 279                 bufptr = bufend;
 280               }
 281               else
 282               {
 283                 strcpy(bufptr, temp);
 284                 bufptr += strlen(temp);
 285               }
 286             }
 287             break;
 288
 289         case 'c' : /* Character or character array */
 290             bytes += width;
 291
 292             if (bufptr)
 293             {
 294               if (width <= 1)
 295                 *bufptr++ = va_arg(ap, int);
 296               else
 297               {
 298                 if ((bufptr + width) > bufend)
 299                   width = (int)(bufend - bufptr);
 300
 301                 memcpy(bufptr, va_arg(ap, char *), (size_t)width);
 302                 bufptr += width;
 303               }
 304             }
 305             break;
 306
 307         case 's' : /* String */
 308             if ((s = va_arg(ap, char *)) == NULL)
 309               s = "(null)";
 310
 311            /*
 312             * Copy the C string, replacing control chars and \ with
 313             * C character escapes...
 314             */
 315
 316             for (bufend --; *s && bufptr < bufend; s ++)
 317             {
 318               if (*s == '\n')
 319               {
 320                 *bufptr++ = '\\';
 321                 *bufptr++ = 'n';
 322               }
 323               else if (*s == '\r')
 324               {
 325                 *bufptr++ = '\\';
 326                 *bufptr++ = 'r';
 327               }
 328               else if (*s == '\t')
 329               {
 330                 *bufptr++ = '\\';
 331                 *bufptr++ = 't';
 332               }
 333               else if (*s == '\\')
 334               {
 335                 *bufptr++ = '\\';
 336                 *bufptr++ = '\\';
 337               }
 338               else if (*s == '\'')
 339               {
 340                 *bufptr++ = '\\';
 341                 *bufptr++ = '\'';
 342               }
 343               else if (*s == '\"')
 344               {
 345                 *bufptr++ = '\\';
 346                 *bufptr++ = '\"';
 347               }
 348               else if ((*s & 255) < ' ')
 349               {
 350                 *bufptr++ = '\\';
 351                 *bufptr++ = '0';
 352                 *bufptr++ = '0' + *s / 8;
 353                 *bufptr++ = '0' + (*s & 7);
 354               }
 355               else
 356                 *bufptr++ = *s;
 357             }
 358
 359             bufend ++;
 360             break;
 361
 362         case 'n' : /* Output number of chars so far */
 363             *(va_arg(ap, int *)) = bytes;
 364             break;
 365       }
 366     }
 367     else
 368     {
 369       bytes ++;
 370
 371       if (bufptr < bufend)
 372         *bufptr++ = *format;
 373
 374       format ++;
 375     }
 376   }
 377
 378  /*
 379   * Nul-terminate the string and return the number of characters needed.
 380   */
 381
 382   *bufptr = '\0';
 383
 384   return (bytes);
 385 }
 386
 387
 388 /*
 389  * '_cups_debug_printf()' - Write a formatted line to the log.
 390  */
 391
 392 void
 393 _cups_debug_printf(const char *format,  /* I - Printf-style format string */
 394                    ...)                 /* I - Additional arguments as needed */
 395 {
 396   va_list               ap;             /* Pointer to arguments */
 397   struct timeval        curtime;        /* Current time */
 398   char                  buffer[2048];   /* Output buffer */
 399   size_t                bytes;          /* Number of bytes in buffer */
 400   int                   level;          /* Log level in message */
 401   const char            *cups_debug_filter,
 402                                         /* CUPS_DEBUG_FILTER environment variable */
 403                         *cups_debug_level,
 404                                         /* CUPS_DEBUG_LEVEL environment variable */
 405                         *cups_debug_log;/* CUPS_DEBUG_LOG environment variable */
 406
 407
 408  /*
 409   * See if we need to do any logging...
 410   */
 411
 412   if (!debug_init)
 413   {
 414    /*
 415     * Get a lock on the debug initializer, then re-check in case another
 416     * thread already did it...
 417     */
 418
 419     pthread_mutex_lock(&debug_mutex);
 420
 421     if (!debug_init)
 422     {
 423       debug_init = 1;
 424
 425       if ((cups_debug_log = getenv("CUPS_DEBUG_LOG")) == NULL)
 426         _cups_debug_fd = -1;
 427       else if (!strcmp(cups_debug_log, "-"))
 428         _cups_debug_fd = 2;
 429       else
 430       {
 431         snprintf(buffer, sizeof(buffer), cups_debug_log, getpid());
 432         _cups_debug_fd = open(buffer, O_WRONLY | O_APPEND | O_CREAT, 0644);
 433       }
 434
 435       if ((cups_debug_level = getenv("CUPS_DEBUG_LEVEL")) != NULL)
 436         debug_level = atoi(cups_debug_level);
 437
 438       if ((cups_debug_filter = getenv("CUPS_DEBUG_FILTER")) != NULL)
 439       {
 440         if ((debug_filter = (regex_t *)calloc(1, sizeof(regex_t))) == NULL)
 441           fputs("Unable to allocate memory for CUPS_DEBUG_FILTER - results not "
 442                 "filtered!\n", stderr);
 443         else if (regcomp(debug_filter, cups_debug_filter, REG_EXTENDED))
 444         {
 445           fputs("Bad regular expression in CUPS_DEBUG_FILTER - results not "
 446                 "filtered!\n", stderr);
 447           free(debug_filter);
 448           debug_filter = NULL;
 449         }
 450       }
 451     }
 452
 453     pthread_mutex_unlock(&debug_mutex);
 454   }
 455
 456   if (_cups_debug_fd < 0)
 457     return;
 458
 459  /*
 460   * Filter as needed...
 461   */
 462
 463   if (isdigit(format[0]))
 464     level = *format++ - '0';
 465   else
 466     level = 0;
 467
 468   if (level > debug_level)
 469     return;
 470
 471   if (debug_filter)
 472   {
 473     int result;                         /* Filter result */
 474
 475     pthread_mutex_lock(&debug_mutex);
 476     result = regexec(debug_filter, format, 0, NULL, 0);
 477     pthread_mutex_unlock(&debug_mutex);
 478
 479     if (result)
 480       return;
 481   }
 482
 483  /*
 484   * Format the message...
 485   */
 486
 487   gettimeofday(&curtime, NULL);
 488   snprintf(buffer, sizeof(buffer), "%02d:%02d:%02d.%03d ",
 489            (int)((curtime.tv_sec / 3600) % 24),
 490            (int)((curtime.tv_sec / 60) % 60),
 491            (int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000));
 492
 493   va_start(ap, format);
 494   debug_vsnprintf(buffer + 13, sizeof(buffer) - 14, format, ap);
 495   va_end(ap);
 496
 497   bytes = strlen(buffer);
 498   if (buffer[bytes - 1] != '\n')
 499   {
 500     buffer[bytes] = '\n';
 501     bytes ++;
 502     buffer[bytes] = '\0';
 503   }
 504
 505  /*
 506   * Write it out...
 507   */
 508
 509   write(_cups_debug_fd, buffer, bytes);
 510 }
 511
 512
 513 /*
 514  * '_cups_debug_puts()' - Write a single line to the log.
 515  */
 516
 517 void
 518 _cups_debug_puts(const char *s)         /* I - String to output */
 519 {
 520   char  format[4];                      /* C%s */
 521
 522   format[0] = *s++;
 523   format[1] = '%';
 524   format[2] = 's';
 525   format[3] = '\0';
 526
 527   _cups_debug_printf(format, s);
 528 }
 529
 530
 531 #elif defined(__APPLE__)
 532 /* Mac OS X needs these stubbed since we reference them in the libcups.exp file */
 533 void    _cups_debug_printf(const char *format, ...) {}
 534 void    _cups_debug_puts(const char *s) {}
 535 #endif /* DEBUG */
 536
 537
 538 /*
 539  * End of "$Id$".
 540  */