2 * Debugging functions for CUPS.
4 * Copyright © 2008-2018 by Apple Inc.
6 * Licensed under Apache License v2.0. See the file "LICENSE" for more
11 * Include necessary headers...
14 #include "cups-private.h"
15 #include "debug-internal.h"
16 #include "thread-private.h"
18 # include <sys/timeb.h>
21 # define getpid (int)GetCurrentProcessId
22 int /* O - 0 on success, -1 on failure */
23 _cups_gettimeofday(struct timeval
*tv
, /* I - Timeval struct */
24 void *tz
) /* I - Timezone */
26 struct _timeb timebuffer
; /* Time buffer struct */
28 tv
->tv_sec
= (long)timebuffer
.time
;
29 tv
->tv_usec
= timebuffer
.millitm
* 1000;
33 # include <sys/time.h>
45 int _cups_debug_fd
= -1;
46 /* Debug log file descriptor */
47 int _cups_debug_level
= 1;
48 /* Log level (0 to 9) */
55 static regex_t
*debug_filter
= NULL
;
56 /* Filter expression for messages */
57 static int debug_init
= 0; /* Did we initialize debugging? */
58 static _cups_mutex_t debug_init_mutex
= _CUPS_MUTEX_INITIALIZER
,
59 /* Mutex to control initialization */
60 debug_log_mutex
= _CUPS_MUTEX_INITIALIZER
;
61 /* Mutex to serialize log entries */
65 * 'debug_thread_id()' - Return an integer representing the current thread.
68 static int /* O - Local thread ID */
71 _cups_globals_t
*cg
= _cupsGlobals(); /* Global data */
74 return (cg
->thread_id
);
79 * '_cups_debug_printf()' - Write a formatted line to the log.
83 _cups_debug_printf(const char *format
, /* I - Printf-style format string */
84 ...) /* I - Additional arguments as needed */
86 va_list ap
; /* Pointer to arguments */
87 struct timeval curtime
; /* Current time */
88 char buffer
[2048]; /* Output buffer */
89 ssize_t bytes
; /* Number of bytes in buffer */
90 int level
; /* Log level in message */
94 * See if we need to do any logging...
98 _cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"),
99 getenv("CUPS_DEBUG_FILTER"), 0);
101 if (_cups_debug_fd
< 0)
105 * Filter as needed...
108 if (isdigit(format
[0]))
109 level
= *format
++ - '0';
113 if (level
> _cups_debug_level
)
118 int result
; /* Filter result */
120 _cupsMutexLock(&debug_init_mutex
);
121 result
= regexec(debug_filter
, format
, 0, NULL
, 0);
122 _cupsMutexUnlock(&debug_init_mutex
);
129 * Format the message...
132 gettimeofday(&curtime
, NULL
);
133 snprintf(buffer
, sizeof(buffer
), "T%03d %02d:%02d:%02d.%03d ",
134 debug_thread_id(), (int)((curtime
.tv_sec
/ 3600) % 24),
135 (int)((curtime
.tv_sec
/ 60) % 60),
136 (int)(curtime
.tv_sec
% 60), (int)(curtime
.tv_usec
/ 1000));
138 va_start(ap
, format
);
139 bytes
= _cups_safe_vsnprintf(buffer
+ 19, sizeof(buffer
) - 20, format
, ap
) + 19;
142 if ((size_t)bytes
>= (sizeof(buffer
) - 1))
144 buffer
[sizeof(buffer
) - 2] = '\n';
145 bytes
= sizeof(buffer
) - 1;
147 else if (buffer
[bytes
- 1] != '\n')
149 buffer
[bytes
++] = '\n';
150 buffer
[bytes
] = '\0';
157 _cupsMutexLock(&debug_log_mutex
);
158 write(_cups_debug_fd
, buffer
, (size_t)bytes
);
159 _cupsMutexUnlock(&debug_log_mutex
);
164 * '_cups_debug_puts()' - Write a single line to the log.
168 _cups_debug_puts(const char *s
) /* I - String to output */
170 struct timeval curtime
; /* Current time */
171 char buffer
[2048]; /* Output buffer */
172 ssize_t bytes
; /* Number of bytes in buffer */
173 int level
; /* Log level in message */
177 * See if we need to do any logging...
181 _cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"),
182 getenv("CUPS_DEBUG_FILTER"), 0);
184 if (_cups_debug_fd
< 0)
188 * Filter as needed...
196 if (level
> _cups_debug_level
)
201 int result
; /* Filter result */
203 _cupsMutexLock(&debug_init_mutex
);
204 result
= regexec(debug_filter
, s
, 0, NULL
, 0);
205 _cupsMutexUnlock(&debug_init_mutex
);
212 * Format the message...
215 gettimeofday(&curtime
, NULL
);
216 bytes
= snprintf(buffer
, sizeof(buffer
), "T%03d %02d:%02d:%02d.%03d %s",
217 debug_thread_id(), (int)((curtime
.tv_sec
/ 3600) % 24),
218 (int)((curtime
.tv_sec
/ 60) % 60),
219 (int)(curtime
.tv_sec
% 60), (int)(curtime
.tv_usec
/ 1000),
222 if ((size_t)bytes
>= (sizeof(buffer
) - 1))
224 buffer
[sizeof(buffer
) - 2] = '\n';
225 bytes
= sizeof(buffer
) - 1;
227 else if (buffer
[bytes
- 1] != '\n')
229 buffer
[bytes
++] = '\n';
230 buffer
[bytes
] = '\0';
237 _cupsMutexLock(&debug_log_mutex
);
238 write(_cups_debug_fd
, buffer
, (size_t)bytes
);
239 _cupsMutexUnlock(&debug_log_mutex
);
244 * '_cups_debug_set()' - Enable or disable debug logging.
248 _cups_debug_set(const char *logfile
, /* I - Log file or NULL */
249 const char *level
, /* I - Log level or NULL */
250 const char *filter
, /* I - Filter string or NULL */
251 int force
) /* I - Force initialization */
253 _cupsMutexLock(&debug_init_mutex
);
255 if (!debug_init
|| force
)
258 * Restore debug settings to defaults...
261 if (_cups_debug_fd
!= -1)
263 close(_cups_debug_fd
);
269 regfree((regex_t
*)debug_filter
);
273 _cups_debug_level
= 1;
276 * Open logs, set log levels, etc.
281 else if (!strcmp(logfile
, "-"))
285 char buffer
[1024]; /* Filename buffer */
287 snprintf(buffer
, sizeof(buffer
), logfile
, getpid());
289 if (buffer
[0] == '+')
290 _cups_debug_fd
= open(buffer
+ 1, O_WRONLY
| O_APPEND
| O_CREAT
, 0644);
292 _cups_debug_fd
= open(buffer
, O_WRONLY
| O_TRUNC
| O_CREAT
, 0644);
296 _cups_debug_level
= atoi(level
);
300 if ((debug_filter
= (regex_t
*)calloc(1, sizeof(regex_t
))) == NULL
)
301 fputs("Unable to allocate memory for CUPS_DEBUG_FILTER - results not "
302 "filtered!\n", stderr
);
303 else if (regcomp(debug_filter
, filter
, REG_EXTENDED
))
305 fputs("Bad regular expression in CUPS_DEBUG_FILTER - results not "
306 "filtered!\n", stderr
);
315 _cupsMutexUnlock(&debug_init_mutex
);
321 * '_cups_debug_set()' - Enable or disable debug logging.
325 _cups_debug_set(const char *logfile
, /* I - Log file or NULL */
326 const char *level
, /* I - Log level or NULL */
327 const char *filter
, /* I - Filter string or NULL */
328 int force
) /* I - Force initialization */
339 * '_cups_safe_vsnprintf()' - Format a string into a fixed size buffer,
340 * quoting special characters.
343 ssize_t
/* O - Number of bytes formatted */
344 _cups_safe_vsnprintf(
345 char *buffer
, /* O - Output buffer */
346 size_t bufsize
, /* O - Size of output buffer */
347 const char *format
, /* I - printf-style format string */
348 va_list ap
) /* I - Pointer to additional arguments */
350 char *bufptr
, /* Pointer to position in buffer */
351 *bufend
, /* Pointer to end of buffer */
352 size
, /* Size character (h, l, L) */
353 type
; /* Format type character */
354 int width
, /* Width of field */
355 prec
; /* Number of characters of precision */
356 char tformat
[100], /* Temporary format string for snprintf() */
357 *tptr
, /* Pointer into temporary format */
358 temp
[1024]; /* Buffer for formatted numbers */
359 char *s
; /* Pointer to string */
360 ssize_t bytes
; /* Total number of bytes needed */
363 if (!buffer
|| bufsize
< 2 || !format
)
367 * Loop through the format string, formatting as needed...
371 bufend
= buffer
+ bufsize
- 1;
389 else if (strchr(" -+#\'", *format
))
395 * Get width from argument...
399 width
= va_arg(ap
, int);
401 snprintf(tptr
, sizeof(tformat
) - (size_t)(tptr
- tformat
), "%d", width
);
402 tptr
+= strlen(tptr
);
408 while (isdigit(*format
& 255))
410 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
413 width
= width
* 10 + *format
++ - '0';
419 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
427 * Get precision from argument...
431 prec
= va_arg(ap
, int);
433 snprintf(tptr
, sizeof(tformat
) - (size_t)(tptr
- tformat
), "%d", prec
);
434 tptr
+= strlen(tptr
);
440 while (isdigit(*format
& 255))
442 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
445 prec
= prec
* 10 + *format
++ - '0';
450 if (*format
== 'l' && format
[1] == 'l')
454 if (tptr
< (tformat
+ sizeof(tformat
) - 2))
462 else if (*format
== 'h' || *format
== 'l' || *format
== 'L')
464 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
475 if (tptr
< (tformat
+ sizeof(tformat
) - 1))
483 case 'E' : /* Floating point formats */
488 if ((size_t)(width
+ 2) > sizeof(temp
))
491 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, double));
493 bytes
+= (int)strlen(temp
);
497 strlcpy(bufptr
, temp
, (size_t)(bufend
- bufptr
));
498 bufptr
+= strlen(bufptr
);
502 case 'B' : /* Integer formats */
510 if ((size_t)(width
+ 2) > sizeof(temp
))
513 # ifdef HAVE_LONG_LONG
515 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, long long));
517 # endif /* HAVE_LONG_LONG */
519 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, long));
521 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, int));
523 bytes
+= (int)strlen(temp
);
527 strlcpy(bufptr
, temp
, (size_t)(bufend
- bufptr
));
528 bufptr
+= strlen(bufptr
);
532 case 'p' : /* Pointer value */
533 if ((size_t)(width
+ 2) > sizeof(temp
))
536 snprintf(temp
, sizeof(temp
), tformat
, va_arg(ap
, void *));
538 bytes
+= (int)strlen(temp
);
542 strlcpy(bufptr
, temp
, (size_t)(bufend
- bufptr
));
543 bufptr
+= strlen(bufptr
);
547 case 'c' : /* Character or character array */
553 *bufptr
++ = (char)va_arg(ap
, int);
556 if ((bufptr
+ width
) > bufend
)
557 width
= (int)(bufend
- bufptr
);
559 memcpy(bufptr
, va_arg(ap
, char *), (size_t)width
);
565 case 's' : /* String */
566 if ((s
= va_arg(ap
, char *)) == NULL
)
570 * Copy the C string, replacing control chars and \ with
571 * C character escapes...
574 for (bufend
--; *s
&& bufptr
< bufend
; s
++)
612 else if ((*s
& 255) < ' ')
614 if ((bufptr
+ 2) >= bufend
)
619 *bufptr
++ = '0' + *s
/ 8;
620 *bufptr
++ = '0' + (*s
& 7);
633 case 'n' : /* Output number of chars so far */
634 *(va_arg(ap
, int *)) = (int)bytes
;
650 * Nul-terminate the string and return the number of characters needed.