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