4 * Debugging functions for CUPS.
6 * Copyright 2008-2014 by Apple Inc.
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/".
14 * This file is subject to the Apple OS-Developed Software exception.
18 * Include necessary headers...
21 #include "cups-private.h"
22 #include "thread-private.h"
24 # include <sys/timeb.h>
27 # define getpid (int)GetCurrentProcessId
28 int /* O - 0 on success, -1 on failure */
29 _cups_gettimeofday(struct timeval
*tv
, /* I - Timeval struct */
30 void *tz
) /* I - Timezone */
32 struct _timeb timebuffer
; /* Time buffer struct */
34 tv
->tv_sec
= (long)timebuffer
.time
;
35 tv
->tv_usec
= timebuffer
.millitm
* 1000;
39 # include <sys/time.h>
50 int _cups_debug_fd
= -1;
51 /* Debug log file descriptor */
52 int _cups_debug_level
= 1;
53 /* Log level (0 to 9) */
61 static regex_t
*debug_filter
= NULL
;
62 /* Filter expression for messages */
63 static int debug_init
= 0; /* Did we initialize debugging? */
64 static _cups_mutex_t debug_init_mutex
= _CUPS_MUTEX_INITIALIZER
,
65 /* Mutex to control initialization */
66 debug_log_mutex
= _CUPS_MUTEX_INITIALIZER
;
67 /* Mutex to serialize log entries */
71 * 'debug_thread_id()' - Return an integer representing the current thread.
74 static int /* O - Local thread ID */
77 _cups_globals_t
*cg
= _cupsGlobals(); /* Global data */
80 return (cg
->thread_id
);
85 * 'debug_vsnprintf()' - Format a string into a fixed size buffer.
88 static ssize_t
/* O - Number of bytes formatted */
89 debug_vsnprintf(char *buffer
, /* O - Output buffer */
90 size_t bufsize
, /* O - Size of output buffer */
91 const char *format
, /* I - printf-style format string */
92 va_list ap
) /* I - Pointer to additional arguments */
94 char *bufptr
, /* Pointer to position in buffer */
95 *bufend
, /* Pointer to end of buffer */
96 size
, /* Size character (h, l, L) */
97 type
; /* Format type character */
98 int width
, /* Width of field */
99 prec
; /* Number of characters of precision */
100 char tformat
[100], /* Temporary format string for snprintf() */
101 *tptr
, /* Pointer into temporary format */
102 temp
[1024]; /* Buffer for formatted numbers */
103 char *s
; /* Pointer to string */
104 ssize_t bytes
; /* Total number of bytes needed */
107 if (!buffer
|| bufsize
< 2 || !format
)
111 * Loop through the format string, formatting as needed...
115 bufend
= buffer
+ bufsize
- 1;
133 else if (strchr(" -+#\'", *format
))
139 * Get width from argument...
143 width
= va_arg(ap
, int);
145 snprintf(tptr
, sizeof(tformat
) - (size_t)(tptr
- tformat
), "%d", width
);
146 tptr
+= strlen(tptr
);
152 while (isdigit(*format
& 255))
154 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
157 width
= width
* 10 + *format
++ - '0';
163 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
171 * Get precision from argument...
175 prec
= va_arg(ap
, int);
177 snprintf(tptr
, sizeof(tformat
) - (size_t)(tptr
- tformat
), "%d", prec
);
178 tptr
+= strlen(tptr
);
184 while (isdigit(*format
& 255))
186 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
189 prec
= prec
* 10 + *format
++ - '0';
194 if (*format
== 'l' && format
[1] == 'l')
198 if (tptr
< (tformat
+ sizeof(tformat
) - 2))
206 else if (*format
== 'h' || *format
== 'l' || *format
== 'L')
208 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
219 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
227 case 'E' : /* Floating point formats */
232 if ((size_t)(width
+ 2) > sizeof(temp
))
235 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, double));
237 bytes
+= (int)strlen(temp
);
241 strlcpy(bufptr
, temp
, (size_t)(bufend
- bufptr
));
242 bufptr
+= strlen(bufptr
);
246 case 'B' : /* Integer formats */
254 if ((size_t)(width
+ 2) > sizeof(temp
))
257 # ifdef HAVE_LONG_LONG
259 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, long long));
261 # endif /* HAVE_LONG_LONG */
263 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, long));
265 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, int));
267 bytes
+= (int)strlen(temp
);
271 strlcpy(bufptr
, temp
, (size_t)(bufend
- bufptr
));
272 bufptr
+= strlen(bufptr
);
276 case 'p' : /* Pointer value */
277 if ((size_t)(width
+ 2) > sizeof(temp
))
280 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, void *));
282 bytes
+= (int)strlen(temp
);
286 strlcpy(bufptr
, temp
, (size_t)(bufend
- bufptr
));
287 bufptr
+= strlen(bufptr
);
291 case 'c' : /* Character or character array */
297 *bufptr
++ = (char)va_arg(ap
, int);
300 if ((bufptr
+ width
) > bufend
)
301 width
= (int)(bufend
- bufptr
);
303 memcpy(bufptr
, va_arg(ap
, char *), (size_t)width
);
309 case 's' : /* String */
310 if ((s
= va_arg(ap
, char *)) == NULL
)
314 * Copy the C string, replacing control chars and \ with
315 * C character escapes...
318 for (bufend
--; *s
&& bufptr
< bufend
; s
++)
356 else if ((*s
& 255) < ' ')
358 if ((bufptr
+ 2) >= bufend
)
363 *bufptr
++ = '0' + *s
/ 8;
364 *bufptr
++ = '0' + (*s
& 7);
377 case 'n' : /* Output number of chars so far */
378 *(va_arg(ap
, int *)) = (int)bytes
;
394 * Nul-terminate the string and return the number of characters needed.
404 * '_cups_debug_printf()' - Write a formatted line to the log.
408 _cups_debug_printf(const char *format
, /* I - Printf-style format string */
409 ...) /* I - Additional arguments as needed */
411 va_list ap
; /* Pointer to arguments */
412 struct timeval curtime
; /* Current time */
413 char buffer
[2048]; /* Output buffer */
414 ssize_t bytes
; /* Number of bytes in buffer */
415 int level
; /* Log level in message */
419 * See if we need to do any logging...
423 _cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"),
424 getenv("CUPS_DEBUG_FILTER"), 0);
426 if (_cups_debug_fd
< 0)
430 * Filter as needed...
433 if (isdigit(format
[0]))
434 level
= *format
++ - '0';
438 if (level
> _cups_debug_level
)
443 int result
; /* Filter result */
445 _cupsMutexLock(&debug_init_mutex
);
446 result
= regexec(debug_filter
, format
, 0, NULL
, 0);
447 _cupsMutexUnlock(&debug_init_mutex
);
454 * Format the message...
457 gettimeofday(&curtime
, NULL
);
458 snprintf(buffer
, sizeof(buffer
), "T%03d %02d:%02d:%02d.%03d ",
459 debug_thread_id(), (int)((curtime
.tv_sec
/ 3600) % 24),
460 (int)((curtime
.tv_sec
/ 60) % 60),
461 (int)(curtime
.tv_sec
% 60), (int)(curtime
.tv_usec
/ 1000));
463 va_start(ap
, format
);
464 bytes
= debug_vsnprintf(buffer
+ 19, sizeof(buffer
) - 20, format
, ap
) + 19;
467 if ((size_t)bytes
>= (sizeof(buffer
) - 1))
469 buffer
[sizeof(buffer
) - 2] = '\n';
470 bytes
= sizeof(buffer
) - 1;
472 else if (buffer
[bytes
- 1] != '\n')
474 buffer
[bytes
++] = '\n';
475 buffer
[bytes
] = '\0';
482 _cupsMutexLock(&debug_log_mutex
);
483 write(_cups_debug_fd
, buffer
, (size_t)bytes
);
484 _cupsMutexUnlock(&debug_log_mutex
);
489 * '_cups_debug_puts()' - Write a single line to the log.
493 _cups_debug_puts(const char *s
) /* I - String to output */
495 struct timeval curtime
; /* Current time */
496 char buffer
[2048]; /* Output buffer */
497 ssize_t bytes
; /* Number of bytes in buffer */
498 int level
; /* Log level in message */
502 * See if we need to do any logging...
506 _cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"),
507 getenv("CUPS_DEBUG_FILTER"), 0);
509 if (_cups_debug_fd
< 0)
513 * Filter as needed...
521 if (level
> _cups_debug_level
)
526 int result
; /* Filter result */
528 _cupsMutexLock(&debug_init_mutex
);
529 result
= regexec(debug_filter
, s
, 0, NULL
, 0);
530 _cupsMutexUnlock(&debug_init_mutex
);
537 * Format the message...
540 gettimeofday(&curtime
, NULL
);
541 bytes
= snprintf(buffer
, sizeof(buffer
), "T%03d %02d:%02d:%02d.%03d %s",
542 debug_thread_id(), (int)((curtime
.tv_sec
/ 3600) % 24),
543 (int)((curtime
.tv_sec
/ 60) % 60),
544 (int)(curtime
.tv_sec
% 60), (int)(curtime
.tv_usec
/ 1000),
547 if ((size_t)bytes
>= (sizeof(buffer
) - 1))
549 buffer
[sizeof(buffer
) - 2] = '\n';
550 bytes
= sizeof(buffer
) - 1;
552 else if (buffer
[bytes
- 1] != '\n')
554 buffer
[bytes
++] = '\n';
555 buffer
[bytes
] = '\0';
562 _cupsMutexLock(&debug_log_mutex
);
563 write(_cups_debug_fd
, buffer
, (size_t)bytes
);
564 _cupsMutexUnlock(&debug_log_mutex
);
569 * '_cups_debug_set()' - Enable or disable debug logging.
573 _cups_debug_set(const char *logfile
, /* I - Log file or NULL */
574 const char *level
, /* I - Log level or NULL */
575 const char *filter
, /* I - Filter string or NULL */
576 int force
) /* I - Force initialization */
578 _cupsMutexLock(&debug_init_mutex
);
580 if (!debug_init
|| force
)
583 * Restore debug settings to defaults...
586 if (_cups_debug_fd
!= -1)
588 close(_cups_debug_fd
);
594 regfree((regex_t
*)debug_filter
);
598 _cups_debug_level
= 1;
601 * Open logs, set log levels, etc.
606 else if (!strcmp(logfile
, "-"))
610 char buffer
[1024]; /* Filename buffer */
612 snprintf(buffer
, sizeof(buffer
), logfile
, getpid());
614 if (buffer
[0] == '+')
615 _cups_debug_fd
= open(buffer
+ 1, O_WRONLY
| O_APPEND
| O_CREAT
, 0644);
617 _cups_debug_fd
= open(buffer
, O_WRONLY
| O_TRUNC
| O_CREAT
, 0644);
621 _cups_debug_level
= atoi(level
);
625 if ((debug_filter
= (regex_t
*)calloc(1, sizeof(regex_t
))) == NULL
)
626 fputs("Unable to allocate memory for CUPS_DEBUG_FILTER - results not "
627 "filtered!\n", stderr
);
628 else if (regcomp(debug_filter
, filter
, REG_EXTENDED
))
630 fputs("Bad regular expression in CUPS_DEBUG_FILTER - results not "
631 "filtered!\n", stderr
);
640 _cupsMutexUnlock(&debug_init_mutex
);