]>
Commit | Line | Data |
---|---|---|
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 |
35 | int /* 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 | ||
57 | int _cups_debug_fd = -1; | |
58 | /* Debug log file descriptor */ | |
f11a948a MS |
59 | int _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 |
68 | static regex_t *debug_filter = NULL; |
69 | /* Filter expression for messages */ | |
f11a948a | 70 | static int debug_init = 0; /* Did we initialize debugging? */ |
6d2f911b | 71 | static _cups_mutex_t debug_mutex = _CUPS_MUTEX_INITIALIZER; |
4509bb49 | 72 | /* Mutex to control initialization */ |
4509bb49 MS |
73 | |
74 | ||
ae71f5de MS |
75 | /* |
76 | * 'debug_vsnprintf()' - Format a string into a fixed size buffer. | |
77 | */ | |
78 | ||
f8b3a85b | 79 | static int /* O - Number of bytes formatted */ |
ae71f5de MS |
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 */ | |
ae71f5de MS |
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 | ||
1f0275e3 MS |
98 | if (!buffer || bufsize < 2 || !format) |
99 | return (-1); | |
100 | ||
ae71f5de MS |
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 | { | |
1f0275e3 MS |
118 | if (bufptr < bufend) |
119 | *bufptr++ = *format; | |
ae71f5de MS |
120 | bytes ++; |
121 | format ++; | |
122 | continue; | |
123 | } | |
124 | else if (strchr(" -+#\'", *format)) | |
1f0275e3 | 125 | *tptr++ = *format++; |
ae71f5de MS |
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 | } | |
ae71f5de MS |
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 | } | |
1f0275e3 MS |
204 | else |
205 | size = 0; | |
ae71f5de MS |
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 | { | |
5a9febac MS |
232 | strlcpy(bufptr, temp, (size_t)(bufend - bufptr)); |
233 | bufptr += strlen(bufptr); | |
ae71f5de MS |
234 | } |
235 | break; | |
236 | ||
237 | case 'B' : /* Integer formats */ | |
238 | case 'X' : | |
239 | case 'b' : | |
240 | case 'd' : | |
241 | case 'i' : | |
242 | case 'o' : | |
243 | case 'u' : | |
244 | case 'x' : | |
245 | if ((width + 2) > sizeof(temp)) | |
246 | break; | |
247 | ||
6d2f911b | 248 | # ifdef HAVE_LONG_LONG |
ae71f5de MS |
249 | if (size == 'L') |
250 | sprintf(temp, tformat, va_arg(ap, long long)); | |
251 | else | |
6d2f911b | 252 | # endif /* HAVE_LONG_LONG */ |
ae71f5de MS |
253 | if (size == 'l') |
254 | sprintf(temp, tformat, va_arg(ap, long)); | |
255 | else | |
256 | sprintf(temp, tformat, va_arg(ap, int)); | |
257 | ||
258 | bytes += (int)strlen(temp); | |
259 | ||
260 | if (bufptr) | |
261 | { | |
5a9febac MS |
262 | strlcpy(bufptr, temp, (size_t)(bufend - bufptr)); |
263 | bufptr += strlen(bufptr); | |
ae71f5de MS |
264 | } |
265 | break; | |
266 | ||
267 | case 'p' : /* Pointer value */ | |
268 | if ((width + 2) > sizeof(temp)) | |
269 | break; | |
270 | ||
271 | sprintf(temp, tformat, va_arg(ap, void *)); | |
272 | ||
273 | bytes += (int)strlen(temp); | |
274 | ||
275 | if (bufptr) | |
276 | { | |
5a9febac MS |
277 | strlcpy(bufptr, temp, (size_t)(bufend - bufptr)); |
278 | bufptr += strlen(bufptr); | |
ae71f5de MS |
279 | } |
280 | break; | |
281 | ||
282 | case 'c' : /* Character or character array */ | |
283 | bytes += width; | |
284 | ||
285 | if (bufptr) | |
286 | { | |
287 | if (width <= 1) | |
288 | *bufptr++ = va_arg(ap, int); | |
289 | else | |
290 | { | |
291 | if ((bufptr + width) > bufend) | |
292 | width = (int)(bufend - bufptr); | |
293 | ||
294 | memcpy(bufptr, va_arg(ap, char *), (size_t)width); | |
295 | bufptr += width; | |
296 | } | |
297 | } | |
298 | break; | |
299 | ||
300 | case 's' : /* String */ | |
301 | if ((s = va_arg(ap, char *)) == NULL) | |
302 | s = "(null)"; | |
303 | ||
304 | /* | |
305 | * Copy the C string, replacing control chars and \ with | |
306 | * C character escapes... | |
307 | */ | |
308 | ||
309 | for (bufend --; *s && bufptr < bufend; s ++) | |
310 | { | |
311 | if (*s == '\n') | |
312 | { | |
313 | *bufptr++ = '\\'; | |
314 | *bufptr++ = 'n'; | |
12f89d24 | 315 | bytes += 2; |
ae71f5de MS |
316 | } |
317 | else if (*s == '\r') | |
318 | { | |
319 | *bufptr++ = '\\'; | |
320 | *bufptr++ = 'r'; | |
12f89d24 | 321 | bytes += 2; |
ae71f5de MS |
322 | } |
323 | else if (*s == '\t') | |
324 | { | |
325 | *bufptr++ = '\\'; | |
326 | *bufptr++ = 't'; | |
12f89d24 | 327 | bytes += 2; |
ae71f5de MS |
328 | } |
329 | else if (*s == '\\') | |
330 | { | |
331 | *bufptr++ = '\\'; | |
332 | *bufptr++ = '\\'; | |
12f89d24 | 333 | bytes += 2; |
ae71f5de MS |
334 | } |
335 | else if (*s == '\'') | |
336 | { | |
337 | *bufptr++ = '\\'; | |
338 | *bufptr++ = '\''; | |
12f89d24 | 339 | bytes += 2; |
ae71f5de MS |
340 | } |
341 | else if (*s == '\"') | |
342 | { | |
343 | *bufptr++ = '\\'; | |
344 | *bufptr++ = '\"'; | |
12f89d24 | 345 | bytes += 2; |
ae71f5de MS |
346 | } |
347 | else if ((*s & 255) < ' ') | |
348 | { | |
12f89d24 MS |
349 | if ((bufptr + 2) >= bufend) |
350 | break; | |
351 | ||
ae71f5de MS |
352 | *bufptr++ = '\\'; |
353 | *bufptr++ = '0'; | |
354 | *bufptr++ = '0' + *s / 8; | |
355 | *bufptr++ = '0' + (*s & 7); | |
12f89d24 | 356 | bytes += 4; |
ae71f5de MS |
357 | } |
358 | else | |
12f89d24 | 359 | { |
ae71f5de | 360 | *bufptr++ = *s; |
12f89d24 MS |
361 | bytes ++; |
362 | } | |
ae71f5de MS |
363 | } |
364 | ||
365 | bufend ++; | |
366 | break; | |
367 | ||
368 | case 'n' : /* Output number of chars so far */ | |
369 | *(va_arg(ap, int *)) = bytes; | |
370 | break; | |
371 | } | |
372 | } | |
373 | else | |
374 | { | |
375 | bytes ++; | |
376 | ||
1f0275e3 | 377 | if (bufptr < bufend) |
ae71f5de MS |
378 | *bufptr++ = *format; |
379 | ||
380 | format ++; | |
381 | } | |
382 | } | |
383 | ||
384 | /* | |
385 | * Nul-terminate the string and return the number of characters needed. | |
386 | */ | |
387 | ||
388 | *bufptr = '\0'; | |
389 | ||
390 | return (bytes); | |
391 | } | |
392 | ||
393 | ||
394 | /* | |
395 | * '_cups_debug_printf()' - Write a formatted line to the log. | |
396 | */ | |
397 | ||
7cf5915e | 398 | void DLLExport |
ae71f5de MS |
399 | _cups_debug_printf(const char *format, /* I - Printf-style format string */ |
400 | ...) /* I - Additional arguments as needed */ | |
401 | { | |
402 | va_list ap; /* Pointer to arguments */ | |
403 | struct timeval curtime; /* Current time */ | |
404 | char buffer[2048]; /* Output buffer */ | |
405 | size_t bytes; /* Number of bytes in buffer */ | |
e07d4801 | 406 | int level; /* Log level in message */ |
6d2f911b | 407 | |
ae71f5de MS |
408 | |
409 | /* | |
410 | * See if we need to do any logging... | |
411 | */ | |
412 | ||
4509bb49 | 413 | if (!debug_init) |
7cf5915e MS |
414 | _cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"), |
415 | getenv("CUPS_DEBUG_FILTER"), 0); | |
ae71f5de | 416 | |
4509bb49 | 417 | if (_cups_debug_fd < 0) |
ae71f5de MS |
418 | return; |
419 | ||
e07d4801 MS |
420 | /* |
421 | * Filter as needed... | |
422 | */ | |
423 | ||
424 | if (isdigit(format[0])) | |
425 | level = *format++ - '0'; | |
426 | else | |
427 | level = 0; | |
428 | ||
f11a948a | 429 | if (level > _cups_debug_level) |
e07d4801 MS |
430 | return; |
431 | ||
432 | if (debug_filter) | |
433 | { | |
434 | int result; /* Filter result */ | |
435 | ||
6d2f911b | 436 | _cupsMutexLock(&debug_mutex); |
e07d4801 | 437 | result = regexec(debug_filter, format, 0, NULL, 0); |
6d2f911b | 438 | _cupsMutexUnlock(&debug_mutex); |
e07d4801 MS |
439 | |
440 | if (result) | |
441 | return; | |
442 | } | |
443 | ||
ae71f5de MS |
444 | /* |
445 | * Format the message... | |
446 | */ | |
447 | ||
448 | gettimeofday(&curtime, NULL); | |
449 | snprintf(buffer, sizeof(buffer), "%02d:%02d:%02d.%03d ", | |
450 | (int)((curtime.tv_sec / 3600) % 24), | |
451 | (int)((curtime.tv_sec / 60) % 60), | |
452 | (int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000)); | |
453 | ||
454 | va_start(ap, format); | |
12f89d24 | 455 | bytes = debug_vsnprintf(buffer + 13, sizeof(buffer) - 14, format, ap) + 13; |
ae71f5de MS |
456 | va_end(ap); |
457 | ||
12f89d24 MS |
458 | if (bytes >= (sizeof(buffer) - 1)) |
459 | { | |
460 | buffer[sizeof(buffer) - 2] = '\n'; | |
461 | bytes = sizeof(buffer) - 1; | |
462 | } | |
463 | else if (buffer[bytes - 1] != '\n') | |
ae71f5de | 464 | { |
12f89d24 MS |
465 | buffer[bytes++] = '\n'; |
466 | buffer[bytes] = '\0'; | |
ae71f5de MS |
467 | } |
468 | ||
469 | /* | |
470 | * Write it out... | |
471 | */ | |
472 | ||
4509bb49 | 473 | write(_cups_debug_fd, buffer, bytes); |
ae71f5de MS |
474 | } |
475 | ||
476 | ||
477 | /* | |
478 | * '_cups_debug_puts()' - Write a single line to the log. | |
479 | */ | |
480 | ||
7cf5915e | 481 | void DLLExport |
ae71f5de MS |
482 | _cups_debug_puts(const char *s) /* I - String to output */ |
483 | { | |
12f89d24 MS |
484 | struct timeval curtime; /* Current time */ |
485 | char buffer[2048]; /* Output buffer */ | |
486 | size_t bytes; /* Number of bytes in buffer */ | |
487 | int level; /* Log level in message */ | |
488 | ||
489 | ||
490 | /* | |
491 | * See if we need to do any logging... | |
492 | */ | |
e07d4801 | 493 | |
12f89d24 MS |
494 | if (!debug_init) |
495 | _cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"), | |
496 | getenv("CUPS_DEBUG_FILTER"), 0); | |
7cf5915e | 497 | |
12f89d24 MS |
498 | if (_cups_debug_fd < 0) |
499 | return; | |
e07d4801 | 500 | |
12f89d24 MS |
501 | /* |
502 | * Filter as needed... | |
503 | */ | |
504 | ||
505 | if (isdigit(s[0])) | |
506 | level = *s++ - '0'; | |
507 | else | |
508 | level = 0; | |
509 | ||
510 | if (level > _cups_debug_level) | |
511 | return; | |
512 | ||
513 | if (debug_filter) | |
514 | { | |
515 | int result; /* Filter result */ | |
516 | ||
517 | _cupsMutexLock(&debug_mutex); | |
518 | result = regexec(debug_filter, s, 0, NULL, 0); | |
519 | _cupsMutexUnlock(&debug_mutex); | |
520 | ||
521 | if (result) | |
522 | return; | |
523 | } | |
524 | ||
525 | /* | |
526 | * Format the message... | |
527 | */ | |
528 | ||
529 | gettimeofday(&curtime, NULL); | |
530 | bytes = snprintf(buffer, sizeof(buffer), "%02d:%02d:%02d.%03d %s", | |
531 | (int)((curtime.tv_sec / 3600) % 24), | |
532 | (int)((curtime.tv_sec / 60) % 60), | |
533 | (int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000), | |
534 | s); | |
535 | ||
536 | if (bytes >= (sizeof(buffer) - 1)) | |
537 | { | |
538 | buffer[sizeof(buffer) - 2] = '\n'; | |
539 | bytes = sizeof(buffer) - 1; | |
540 | } | |
541 | else if (buffer[bytes - 1] != '\n') | |
542 | { | |
543 | buffer[bytes++] = '\n'; | |
544 | buffer[bytes] = '\0'; | |
545 | } | |
546 | ||
547 | /* | |
548 | * Write it out... | |
549 | */ | |
550 | ||
551 | write(_cups_debug_fd, buffer, bytes); | |
ae71f5de | 552 | } |
7cf5915e MS |
553 | |
554 | ||
555 | /* | |
556 | * '_cups_debug_set()' - Enable or disable debug logging. | |
557 | */ | |
558 | ||
559 | void DLLExport | |
560 | _cups_debug_set(const char *logfile, /* I - Log file or NULL */ | |
561 | const char *level, /* I - Log level or NULL */ | |
562 | const char *filter, /* I - Filter string or NULL */ | |
563 | int force) /* I - Force initialization */ | |
564 | { | |
565 | _cupsMutexLock(&debug_mutex); | |
566 | ||
567 | if (!debug_init || force) | |
568 | { | |
569 | /* | |
570 | * Restore debug settings to defaults... | |
571 | */ | |
572 | ||
573 | if (_cups_debug_fd != -1) | |
574 | { | |
575 | close(_cups_debug_fd); | |
576 | _cups_debug_fd = -1; | |
577 | } | |
578 | ||
579 | if (debug_filter) | |
580 | { | |
581 | regfree((regex_t *)debug_filter); | |
582 | debug_filter = NULL; | |
583 | } | |
584 | ||
585 | _cups_debug_level = 1; | |
586 | ||
587 | /* | |
588 | * Open logs, set log levels, etc. | |
589 | */ | |
590 | ||
591 | if (!logfile) | |
592 | _cups_debug_fd = -1; | |
593 | else if (!strcmp(logfile, "-")) | |
594 | _cups_debug_fd = 2; | |
595 | else | |
596 | { | |
597 | char buffer[1024]; /* Filename buffer */ | |
598 | ||
599 | snprintf(buffer, sizeof(buffer), logfile, getpid()); | |
600 | ||
601 | if (buffer[0] == '+') | |
602 | _cups_debug_fd = open(buffer + 1, O_WRONLY | O_APPEND | O_CREAT, 0644); | |
603 | else | |
604 | _cups_debug_fd = open(buffer, O_WRONLY | O_TRUNC | O_CREAT, 0644); | |
605 | } | |
606 | ||
607 | if (level) | |
608 | _cups_debug_level = atoi(level); | |
609 | ||
610 | if (filter) | |
611 | { | |
612 | if ((debug_filter = (regex_t *)calloc(1, sizeof(regex_t))) == NULL) | |
613 | fputs("Unable to allocate memory for CUPS_DEBUG_FILTER - results not " | |
614 | "filtered!\n", stderr); | |
615 | else if (regcomp(debug_filter, filter, REG_EXTENDED)) | |
616 | { | |
617 | fputs("Bad regular expression in CUPS_DEBUG_FILTER - results not " | |
618 | "filtered!\n", stderr); | |
619 | free(debug_filter); | |
620 | debug_filter = NULL; | |
621 | } | |
622 | } | |
623 | ||
624 | debug_init = 1; | |
625 | } | |
626 | ||
627 | _cupsMutexUnlock(&debug_mutex); | |
628 | } | |
ae71f5de MS |
629 | #endif /* DEBUG */ |
630 | ||
631 | ||
632 | /* | |
633 | * End of "$Id$". | |
634 | */ |