2 * Debugging functions for CUPS.
4 * Copyright 2008-2015 by Apple Inc.
6 * These coded instructions, statements, and computer programs are the
7 * property of Apple Inc. and are protected by Federal copyright
8 * law. Distribution and use rights are outlined in the file "LICENSE.txt"
9 * which should have been included with this file. If this file is
10 * missing or damaged, see the license at "http://www.cups.org/".
12 * This file is subject to the Apple OS-Developed Software exception.
16 * Include necessary headers...
19 #include "cups-private.h"
20 #include "thread-private.h"
22 # include <sys/timeb.h>
25 # define getpid (int)GetCurrentProcessId
26 int /* O - 0 on success, -1 on failure */
27 _cups_gettimeofday(struct timeval *tv, /* I - Timeval struct */
28 void *tz) /* I - Timezone */
30 struct _timeb timebuffer; /* Time buffer struct */
32 tv->tv_sec = (long)timebuffer.time;
33 tv->tv_usec = timebuffer.millitm * 1000;
37 # include <sys/time.h>
48 int _cups_debug_fd = -1;
49 /* Debug log file descriptor */
50 int _cups_debug_level = 1;
51 /* Log level (0 to 9) */
59 static regex_t *debug_filter = NULL;
60 /* Filter expression for messages */
61 static int debug_init = 0; /* Did we initialize debugging? */
62 static _cups_mutex_t debug_init_mutex = _CUPS_MUTEX_INITIALIZER,
63 /* Mutex to control initialization */
64 debug_log_mutex = _CUPS_MUTEX_INITIALIZER;
65 /* Mutex to serialize log entries */
69 * 'debug_thread_id()' - Return an integer representing the current thread.
72 static int /* O - Local thread ID */
75 _cups_globals_t *cg = _cupsGlobals(); /* Global data */
78 return (cg->thread_id);
83 * '_cups_debug_printf()' - Write a formatted line to the log.
87 _cups_debug_printf(const char *format, /* I - Printf-style format string */
88 ...) /* I - Additional arguments as needed */
90 va_list ap; /* Pointer to arguments */
91 struct timeval curtime; /* Current time */
92 char buffer[2048]; /* Output buffer */
93 ssize_t bytes; /* Number of bytes in buffer */
94 int level; /* Log level in message */
98 * See if we need to do any logging...
102 _cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"),
103 getenv("CUPS_DEBUG_FILTER"), 0);
105 if (_cups_debug_fd < 0)
109 * Filter as needed...
112 if (isdigit(format[0]))
113 level = *format++ - '0';
117 if (level > _cups_debug_level)
122 int result; /* Filter result */
124 _cupsMutexLock(&debug_init_mutex);
125 result = regexec(debug_filter, format, 0, NULL, 0);
126 _cupsMutexUnlock(&debug_init_mutex);
133 * Format the message...
136 gettimeofday(&curtime, NULL);
137 snprintf(buffer, sizeof(buffer), "T%03d %02d:%02d:%02d.%03d ",
138 debug_thread_id(), (int)((curtime.tv_sec / 3600) % 24),
139 (int)((curtime.tv_sec / 60) % 60),
140 (int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000));
142 va_start(ap, format);
143 bytes = _cups_safe_vsnprintf(buffer + 19, sizeof(buffer) - 20, format, ap) + 19;
146 if ((size_t)bytes >= (sizeof(buffer) - 1))
148 buffer[sizeof(buffer) - 2] = '\n';
149 bytes = sizeof(buffer) - 1;
151 else if (buffer[bytes - 1] != '\n')
153 buffer[bytes++] = '\n';
154 buffer[bytes] = '\0';
161 _cupsMutexLock(&debug_log_mutex);
162 write(_cups_debug_fd, buffer, (size_t)bytes);
163 _cupsMutexUnlock(&debug_log_mutex);
168 * '_cups_debug_puts()' - Write a single line to the log.
172 _cups_debug_puts(const char *s) /* I - String to output */
174 struct timeval curtime; /* Current time */
175 char buffer[2048]; /* Output buffer */
176 ssize_t bytes; /* Number of bytes in buffer */
177 int level; /* Log level in message */
181 * See if we need to do any logging...
185 _cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"),
186 getenv("CUPS_DEBUG_FILTER"), 0);
188 if (_cups_debug_fd < 0)
192 * Filter as needed...
200 if (level > _cups_debug_level)
205 int result; /* Filter result */
207 _cupsMutexLock(&debug_init_mutex);
208 result = regexec(debug_filter, s, 0, NULL, 0);
209 _cupsMutexUnlock(&debug_init_mutex);
216 * Format the message...
219 gettimeofday(&curtime, NULL);
220 bytes = snprintf(buffer, sizeof(buffer), "T%03d %02d:%02d:%02d.%03d %s",
221 debug_thread_id(), (int)((curtime.tv_sec / 3600) % 24),
222 (int)((curtime.tv_sec / 60) % 60),
223 (int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000),
226 if ((size_t)bytes >= (sizeof(buffer) - 1))
228 buffer[sizeof(buffer) - 2] = '\n';
229 bytes = sizeof(buffer) - 1;
231 else if (buffer[bytes - 1] != '\n')
233 buffer[bytes++] = '\n';
234 buffer[bytes] = '\0';
241 _cupsMutexLock(&debug_log_mutex);
242 write(_cups_debug_fd, buffer, (size_t)bytes);
243 _cupsMutexUnlock(&debug_log_mutex);
248 * '_cups_debug_set()' - Enable or disable debug logging.
252 _cups_debug_set(const char *logfile, /* I - Log file or NULL */
253 const char *level, /* I - Log level or NULL */
254 const char *filter, /* I - Filter string or NULL */
255 int force) /* I - Force initialization */
257 _cupsMutexLock(&debug_init_mutex);
259 if (!debug_init || force)
262 * Restore debug settings to defaults...
265 if (_cups_debug_fd != -1)
267 close(_cups_debug_fd);
273 regfree((regex_t *)debug_filter);
277 _cups_debug_level = 1;
280 * Open logs, set log levels, etc.
285 else if (!strcmp(logfile, "-"))
289 char buffer[1024]; /* Filename buffer */
291 snprintf(buffer, sizeof(buffer), logfile, getpid());
293 if (buffer[0] == '+')
294 _cups_debug_fd = open(buffer + 1, O_WRONLY | O_APPEND | O_CREAT, 0644);
296 _cups_debug_fd = open(buffer, O_WRONLY | O_TRUNC | O_CREAT, 0644);
300 _cups_debug_level = atoi(level);
304 if ((debug_filter = (regex_t *)calloc(1, sizeof(regex_t))) == NULL)
305 fputs("Unable to allocate memory for CUPS_DEBUG_FILTER - results not "
306 "filtered!\n", stderr);
307 else if (regcomp(debug_filter, filter, REG_EXTENDED))
309 fputs("Bad regular expression in CUPS_DEBUG_FILTER - results not "
310 "filtered!\n", stderr);
319 _cupsMutexUnlock(&debug_init_mutex);
325 * '_cups_safe_vsnprintf()' - Format a string into a fixed size buffer,
326 * quoting special characters.
329 ssize_t /* O - Number of bytes formatted */
330 _cups_safe_vsnprintf(
331 char *buffer, /* O - Output buffer */
332 size_t bufsize, /* O - Size of output buffer */
333 const char *format, /* I - printf-style format string */
334 va_list ap) /* I - Pointer to additional arguments */
336 char *bufptr, /* Pointer to position in buffer */
337 *bufend, /* Pointer to end of buffer */
338 size, /* Size character (h, l, L) */
339 type; /* Format type character */
340 int width, /* Width of field */
341 prec; /* Number of characters of precision */
342 char tformat[100], /* Temporary format string for snprintf() */
343 *tptr, /* Pointer into temporary format */
344 temp[1024]; /* Buffer for formatted numbers */
345 char *s; /* Pointer to string */
346 ssize_t bytes; /* Total number of bytes needed */
349 if (!buffer || bufsize < 2 || !format)
353 * Loop through the format string, formatting as needed...
357 bufend = buffer + bufsize - 1;
375 else if (strchr(" -+#\'", *format))
381 * Get width from argument...
385 width = va_arg(ap, int);
387 snprintf(tptr, sizeof(tformat) - (size_t)(tptr - tformat), "%d", width);
388 tptr += strlen(tptr);
394 while (isdigit(*format & 255))
396 if (tptr < (tformat + sizeof(tformat) - 1))
399 width = width * 10 + *format++ - '0';
405 if (tptr < (tformat + sizeof(tformat) - 1))
413 * Get precision from argument...
417 prec = va_arg(ap, int);
419 snprintf(tptr, sizeof(tformat) - (size_t)(tptr - tformat), "%d", prec);
420 tptr += strlen(tptr);
426 while (isdigit(*format & 255))
428 if (tptr < (tformat + sizeof(tformat) - 1))
431 prec = prec * 10 + *format++ - '0';
436 if (*format == 'l' && format[1] == 'l')
440 if (tptr < (tformat + sizeof(tformat) - 2))
448 else if (*format == 'h' || *format == 'l' || *format == 'L')
450 if (tptr < (tformat + sizeof(tformat) - 1))
461 if (tptr < (tformat + sizeof(tformat) - 1))
469 case 'E' : /* Floating point formats */
474 if ((size_t)(width + 2) > sizeof(temp))
477 snprintf(temp, sizeof(temp), tformat, va_arg(ap, double));
479 bytes += (int)strlen(temp);
483 strlcpy(bufptr, temp, (size_t)(bufend - bufptr));
484 bufptr += strlen(bufptr);
488 case 'B' : /* Integer formats */
496 if ((size_t)(width + 2) > sizeof(temp))
499 # ifdef HAVE_LONG_LONG
501 snprintf(temp, sizeof(temp), tformat, va_arg(ap, long long));
503 # endif /* HAVE_LONG_LONG */
505 snprintf(temp, sizeof(temp), tformat, va_arg(ap, long));
507 snprintf(temp, sizeof(temp), tformat, va_arg(ap, int));
509 bytes += (int)strlen(temp);
513 strlcpy(bufptr, temp, (size_t)(bufend - bufptr));
514 bufptr += strlen(bufptr);
518 case 'p' : /* Pointer value */
519 if ((size_t)(width + 2) > sizeof(temp))
522 snprintf(temp, sizeof(temp), tformat, va_arg(ap, void *));
524 bytes += (int)strlen(temp);
528 strlcpy(bufptr, temp, (size_t)(bufend - bufptr));
529 bufptr += strlen(bufptr);
533 case 'c' : /* Character or character array */
539 *bufptr++ = (char)va_arg(ap, int);
542 if ((bufptr + width) > bufend)
543 width = (int)(bufend - bufptr);
545 memcpy(bufptr, va_arg(ap, char *), (size_t)width);
551 case 's' : /* String */
552 if ((s = va_arg(ap, char *)) == NULL)
556 * Copy the C string, replacing control chars and \ with
557 * C character escapes...
560 for (bufend --; *s && bufptr < bufend; s ++)
598 else if ((*s & 255) < ' ')
600 if ((bufptr + 2) >= bufend)
605 *bufptr++ = '0' + *s / 8;
606 *bufptr++ = '0' + (*s & 7);
619 case 'n' : /* Output number of chars so far */
620 *(va_arg(ap, int *)) = (int)bytes;
636 * Nul-terminate the string and return the number of characters needed.