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