cups/debug.c

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