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