]>
Commit | Line | Data |
---|---|---|
1 | /* | |
2 | * "$Id$" | |
3 | * | |
4 | * Log file routines for the CUPS scheduler. | |
5 | * | |
6 | * Copyright 2007-2013 by Apple Inc. | |
7 | * Copyright 1997-2007 by Easy Software Products, all rights reserved. | |
8 | * | |
9 | * These coded instructions, statements, and computer programs are the | |
10 | * property of Apple Inc. and are protected by Federal copyright | |
11 | * law. Distribution and use rights are outlined in the file "LICENSE.txt" | |
12 | * which should have been included with this file. If this file is | |
13 | * file is missing or damaged, see the license at "http://www.cups.org/". | |
14 | */ | |
15 | ||
16 | /* | |
17 | * Include necessary headers... | |
18 | */ | |
19 | ||
20 | #include "cupsd.h" | |
21 | #include <stdarg.h> | |
22 | #include <syslog.h> | |
23 | ||
24 | ||
25 | /* | |
26 | * Local globals... | |
27 | */ | |
28 | ||
29 | static _cups_mutex_t log_mutex = _CUPS_MUTEX_INITIALIZER; | |
30 | /* Mutex for logging */ | |
31 | static int log_linesize = 0; /* Size of line for output file */ | |
32 | static char *log_line = NULL; /* Line for output file */ | |
33 | ||
34 | #ifdef HAVE_VSYSLOG | |
35 | static const int syslevels[] = /* SYSLOG levels... */ | |
36 | { | |
37 | 0, | |
38 | LOG_EMERG, | |
39 | LOG_ALERT, | |
40 | LOG_CRIT, | |
41 | LOG_ERR, | |
42 | LOG_WARNING, | |
43 | LOG_NOTICE, | |
44 | LOG_INFO, | |
45 | LOG_DEBUG, | |
46 | LOG_DEBUG | |
47 | }; | |
48 | #endif /* HAVE_VSYSLOG */ | |
49 | ||
50 | ||
51 | /* | |
52 | * Local functions... | |
53 | */ | |
54 | ||
55 | static int format_log_line(const char *message, va_list ap); | |
56 | ||
57 | ||
58 | /* | |
59 | * 'cupsdCheckLogFile()' - Open/rotate a log file if it needs it. | |
60 | */ | |
61 | ||
62 | int /* O - 1 if log file open */ | |
63 | cupsdCheckLogFile(cups_file_t **lf, /* IO - Log file */ | |
64 | const char *logname) /* I - Log filename */ | |
65 | { | |
66 | char backname[1024], /* Backup log filename */ | |
67 | filename[1024], /* Formatted log filename */ | |
68 | *ptr; /* Pointer into filename */ | |
69 | const char *logptr; /* Pointer into log filename */ | |
70 | ||
71 | ||
72 | /* | |
73 | * See if we have a log file to check... | |
74 | */ | |
75 | ||
76 | if (!lf || !logname || !logname[0]) | |
77 | return (1); | |
78 | ||
79 | /* | |
80 | * Format the filename as needed... | |
81 | */ | |
82 | ||
83 | if (!*lf || | |
84 | (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize && | |
85 | MaxLogSize > 0)) | |
86 | { | |
87 | /* | |
88 | * Handle format strings... | |
89 | */ | |
90 | ||
91 | filename[sizeof(filename) - 1] = '\0'; | |
92 | ||
93 | if (logname[0] != '/') | |
94 | { | |
95 | strlcpy(filename, ServerRoot, sizeof(filename)); | |
96 | strlcat(filename, "/", sizeof(filename)); | |
97 | } | |
98 | else | |
99 | filename[0] = '\0'; | |
100 | ||
101 | for (logptr = logname, ptr = filename + strlen(filename); | |
102 | *logptr && ptr < (filename + sizeof(filename) - 1); | |
103 | logptr ++) | |
104 | if (*logptr == '%') | |
105 | { | |
106 | /* | |
107 | * Format spec... | |
108 | */ | |
109 | ||
110 | logptr ++; | |
111 | if (*logptr == 's') | |
112 | { | |
113 | /* | |
114 | * Insert the server name... | |
115 | */ | |
116 | ||
117 | strlcpy(ptr, ServerName, sizeof(filename) - (ptr - filename)); | |
118 | ptr += strlen(ptr); | |
119 | } | |
120 | else | |
121 | { | |
122 | /* | |
123 | * Otherwise just insert the character... | |
124 | */ | |
125 | ||
126 | *ptr++ = *logptr; | |
127 | } | |
128 | } | |
129 | else | |
130 | *ptr++ = *logptr; | |
131 | ||
132 | *ptr = '\0'; | |
133 | } | |
134 | ||
135 | /* | |
136 | * See if the log file is open... | |
137 | */ | |
138 | ||
139 | if (!*lf) | |
140 | { | |
141 | /* | |
142 | * Nope, open the log file... | |
143 | */ | |
144 | ||
145 | if ((*lf = cupsFileOpen(filename, "a")) == NULL) | |
146 | { | |
147 | /* | |
148 | * If the file is in CUPS_LOGDIR then try to create a missing directory... | |
149 | */ | |
150 | ||
151 | if (!strncmp(filename, CUPS_LOGDIR, strlen(CUPS_LOGDIR))) | |
152 | { | |
153 | /* | |
154 | * Try updating the permissions of the containing log directory, using | |
155 | * the log file permissions as a basis... | |
156 | */ | |
157 | ||
158 | int log_dir_perm = 0300 | LogFilePerm; | |
159 | /* LogFilePerm + owner write/search */ | |
160 | if (log_dir_perm & 0040) | |
161 | log_dir_perm |= 0010; /* Add group search */ | |
162 | if (log_dir_perm & 0004) | |
163 | log_dir_perm |= 0001; /* Add other search */ | |
164 | ||
165 | cupsdCheckPermissions(CUPS_LOGDIR, NULL, log_dir_perm, RunUser, Group, | |
166 | 1, -1); | |
167 | ||
168 | *lf = cupsFileOpen(filename, "a"); | |
169 | } | |
170 | ||
171 | if (*lf == NULL) | |
172 | { | |
173 | syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, | |
174 | strerror(errno)); | |
175 | ||
176 | if (FatalErrors & CUPSD_FATAL_LOG) | |
177 | cupsdEndProcess(getpid(), 0); | |
178 | ||
179 | return (0); | |
180 | } | |
181 | } | |
182 | ||
183 | if (strncmp(filename, "/dev/", 5)) | |
184 | { | |
185 | /* | |
186 | * Change ownership and permissions of non-device logs... | |
187 | */ | |
188 | ||
189 | fchown(cupsFileNumber(*lf), RunUser, Group); | |
190 | fchmod(cupsFileNumber(*lf), LogFilePerm); | |
191 | } | |
192 | } | |
193 | ||
194 | /* | |
195 | * Do we need to rotate the log? | |
196 | */ | |
197 | ||
198 | if (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize && | |
199 | MaxLogSize > 0) | |
200 | { | |
201 | /* | |
202 | * Rotate log file... | |
203 | */ | |
204 | ||
205 | cupsFileClose(*lf); | |
206 | ||
207 | strlcpy(backname, filename, sizeof(backname)); | |
208 | strlcat(backname, ".O", sizeof(backname)); | |
209 | ||
210 | unlink(backname); | |
211 | rename(filename, backname); | |
212 | ||
213 | if ((*lf = cupsFileOpen(filename, "a")) == NULL) | |
214 | { | |
215 | syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, | |
216 | strerror(errno)); | |
217 | ||
218 | if (FatalErrors & CUPSD_FATAL_LOG) | |
219 | cupsdEndProcess(getpid(), 0); | |
220 | ||
221 | return (0); | |
222 | } | |
223 | ||
224 | /* | |
225 | * Change ownership and permissions of non-device logs... | |
226 | */ | |
227 | ||
228 | fchown(cupsFileNumber(*lf), RunUser, Group); | |
229 | fchmod(cupsFileNumber(*lf), LogFilePerm); | |
230 | } | |
231 | ||
232 | return (1); | |
233 | } | |
234 | ||
235 | ||
236 | /* | |
237 | * 'cupsdGetDateTime()' - Returns a pointer to a date/time string. | |
238 | */ | |
239 | ||
240 | char * /* O - Date/time string */ | |
241 | cupsdGetDateTime(struct timeval *t, /* I - Time value or NULL for current */ | |
242 | cupsd_time_t format) /* I - Format to use */ | |
243 | { | |
244 | struct timeval curtime; /* Current time value */ | |
245 | struct tm *date; /* Date/time value */ | |
246 | static struct timeval last_time = { 0, 0 }; | |
247 | /* Last time we formatted */ | |
248 | static char s[1024]; /* Date/time string */ | |
249 | static const char * const months[12] =/* Months */ | |
250 | { | |
251 | "Jan", | |
252 | "Feb", | |
253 | "Mar", | |
254 | "Apr", | |
255 | "May", | |
256 | "Jun", | |
257 | "Jul", | |
258 | "Aug", | |
259 | "Sep", | |
260 | "Oct", | |
261 | "Nov", | |
262 | "Dec" | |
263 | }; | |
264 | ||
265 | ||
266 | /* | |
267 | * Make sure we have a valid time... | |
268 | */ | |
269 | ||
270 | if (!t) | |
271 | { | |
272 | gettimeofday(&curtime, NULL); | |
273 | t = &curtime; | |
274 | } | |
275 | ||
276 | if (t->tv_sec != last_time.tv_sec || | |
277 | (LogTimeFormat == CUPSD_TIME_USECS && t->tv_usec != last_time.tv_usec)) | |
278 | { | |
279 | last_time = *t; | |
280 | ||
281 | /* | |
282 | * Get the date and time from the UNIX time value, and then format it | |
283 | * into a string. Note that we *can't* use the strftime() function since | |
284 | * it is localized and will seriously confuse automatic programs if the | |
285 | * month names are in the wrong language! | |
286 | * | |
287 | * Also, we use the "timezone" variable that contains the current timezone | |
288 | * offset from GMT in seconds so that we are reporting local time in the | |
289 | * log files. If you want GMT, set the TZ environment variable accordingly | |
290 | * before starting the scheduler. | |
291 | * | |
292 | * (*BSD and Darwin store the timezone offset in the tm structure) | |
293 | */ | |
294 | ||
295 | date = localtime(&(t->tv_sec)); | |
296 | ||
297 | if (format == CUPSD_TIME_STANDARD) | |
298 | snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d %+03ld%02ld]", | |
299 | date->tm_mday, months[date->tm_mon], 1900 + date->tm_year, | |
300 | date->tm_hour, date->tm_min, date->tm_sec, | |
301 | #ifdef HAVE_TM_GMTOFF | |
302 | date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60); | |
303 | #else | |
304 | timezone / 3600, (timezone / 60) % 60); | |
305 | #endif /* HAVE_TM_GMTOFF */ | |
306 | else | |
307 | snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d.%06d %+03ld%02ld]", | |
308 | date->tm_mday, months[date->tm_mon], 1900 + date->tm_year, | |
309 | date->tm_hour, date->tm_min, date->tm_sec, (int)t->tv_usec, | |
310 | #ifdef HAVE_TM_GMTOFF | |
311 | date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60); | |
312 | #else | |
313 | timezone / 3600, (timezone / 60) % 60); | |
314 | #endif /* HAVE_TM_GMTOFF */ | |
315 | } | |
316 | ||
317 | return (s); | |
318 | } | |
319 | ||
320 | ||
321 | /* | |
322 | * 'cupsdLogFCMessage()' - Log a file checking message. | |
323 | */ | |
324 | ||
325 | void | |
326 | cupsdLogFCMessage( | |
327 | void *context, /* I - Printer (if any) */ | |
328 | _cups_fc_result_t result, /* I - Check result */ | |
329 | const char *message) /* I - Message to log */ | |
330 | { | |
331 | cupsd_printer_t *p = (cupsd_printer_t *)context; | |
332 | /* Printer */ | |
333 | cupsd_loglevel_t level; /* Log level */ | |
334 | ||
335 | ||
336 | if (result == _CUPS_FILE_CHECK_OK) | |
337 | level = CUPSD_LOG_DEBUG2; | |
338 | else | |
339 | level = CUPSD_LOG_ERROR; | |
340 | ||
341 | if (p) | |
342 | { | |
343 | cupsdLogMessage(level, "%s: %s", p->name, message); | |
344 | ||
345 | if (result == _CUPS_FILE_CHECK_MISSING || | |
346 | result == _CUPS_FILE_CHECK_WRONG_TYPE) | |
347 | { | |
348 | strlcpy(p->state_message, message, sizeof(p->state_message)); | |
349 | ||
350 | if (cupsdSetPrinterReasons(p, "+cups-missing-filter-warning")) | |
351 | cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, p, NULL, "%s", message); | |
352 | } | |
353 | else if (result == _CUPS_FILE_CHECK_PERMISSIONS || | |
354 | result == _CUPS_FILE_CHECK_RELATIVE_PATH) | |
355 | { | |
356 | strlcpy(p->state_message, message, sizeof(p->state_message)); | |
357 | ||
358 | if (cupsdSetPrinterReasons(p, "+cups-insecure-filter-warning")) | |
359 | cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, p, NULL, "%s", message); | |
360 | } | |
361 | } | |
362 | else | |
363 | cupsdLogMessage(level, "%s", message); | |
364 | } | |
365 | ||
366 | ||
367 | #ifdef HAVE_GSSAPI | |
368 | /* | |
369 | * 'cupsdLogGSSMessage()' - Log a GSSAPI error... | |
370 | */ | |
371 | ||
372 | int /* O - 1 on success, 0 on error */ | |
373 | cupsdLogGSSMessage( | |
374 | int level, /* I - Log level */ | |
375 | int major_status, /* I - Major GSSAPI status */ | |
376 | int minor_status, /* I - Minor GSSAPI status */ | |
377 | const char *message, /* I - printf-style message string */ | |
378 | ...) /* I - Additional args as needed */ | |
379 | { | |
380 | OM_uint32 err_major_status, /* Major status code for display */ | |
381 | err_minor_status; /* Minor status code for display */ | |
382 | OM_uint32 msg_ctx; /* Message context */ | |
383 | gss_buffer_desc major_status_string = GSS_C_EMPTY_BUFFER, | |
384 | /* Major status message */ | |
385 | minor_status_string = GSS_C_EMPTY_BUFFER; | |
386 | /* Minor status message */ | |
387 | int ret; /* Return value */ | |
388 | char buffer[8192]; /* Buffer for vsnprintf */ | |
389 | ||
390 | ||
391 | if (strchr(message, '%')) | |
392 | { | |
393 | /* | |
394 | * Format the message string... | |
395 | */ | |
396 | ||
397 | va_list ap; /* Pointer to arguments */ | |
398 | ||
399 | va_start(ap, message); | |
400 | vsnprintf(buffer, sizeof(buffer), message, ap); | |
401 | va_end(ap); | |
402 | ||
403 | message = buffer; | |
404 | } | |
405 | ||
406 | msg_ctx = 0; | |
407 | err_major_status = gss_display_status(&err_minor_status, | |
408 | major_status, | |
409 | GSS_C_GSS_CODE, | |
410 | GSS_C_NO_OID, | |
411 | &msg_ctx, | |
412 | &major_status_string); | |
413 | ||
414 | if (!GSS_ERROR(err_major_status)) | |
415 | gss_display_status(&err_minor_status, minor_status, GSS_C_MECH_CODE, | |
416 | GSS_C_NULL_OID, &msg_ctx, &minor_status_string); | |
417 | ||
418 | ret = cupsdLogMessage(level, "%s: %s, %s", message, | |
419 | (char *)major_status_string.value, | |
420 | (char *)minor_status_string.value); | |
421 | gss_release_buffer(&err_minor_status, &major_status_string); | |
422 | gss_release_buffer(&err_minor_status, &minor_status_string); | |
423 | ||
424 | return (ret); | |
425 | } | |
426 | #endif /* HAVE_GSSAPI */ | |
427 | ||
428 | ||
429 | /* | |
430 | * 'cupsdLogClient()' - Log a client message. | |
431 | */ | |
432 | ||
433 | int /* O - 1 on success, 0 on error */ | |
434 | cupsdLogClient(cupsd_client_t *con, /* I - Client connection */ | |
435 | int level, /* I - Log level */ | |
436 | const char *message, /* I - Printf-style message string */ | |
437 | ...) /* I - Additional arguments as needed */ | |
438 | { | |
439 | va_list ap, ap2; /* Argument pointers */ | |
440 | char clientmsg[1024];/* Format string for client message */ | |
441 | int status; /* Formatting status */ | |
442 | ||
443 | ||
444 | /* | |
445 | * See if we want to log this message... | |
446 | */ | |
447 | ||
448 | if (TestConfigFile || !ErrorLog) | |
449 | return (1); | |
450 | ||
451 | if (level > LogLevel) | |
452 | return (1); | |
453 | ||
454 | /* | |
455 | * Format and write the log message... | |
456 | */ | |
457 | ||
458 | if (con) | |
459 | snprintf(clientmsg, sizeof(clientmsg), "[Client %d] %s", con->number, | |
460 | message); | |
461 | else | |
462 | strlcpy(clientmsg, message, sizeof(clientmsg)); | |
463 | ||
464 | va_start(ap, message); | |
465 | ||
466 | do | |
467 | { | |
468 | va_copy(ap2, ap); | |
469 | status = format_log_line(clientmsg, ap2); | |
470 | va_end(ap2); | |
471 | } | |
472 | while (status == 0); | |
473 | ||
474 | va_end(ap); | |
475 | ||
476 | if (status > 0) | |
477 | return (cupsdWriteErrorLog(level, log_line)); | |
478 | else | |
479 | return (cupsdWriteErrorLog(CUPSD_LOG_ERROR, | |
480 | "Unable to allocate memory for log line.")); | |
481 | } | |
482 | ||
483 | ||
484 | /* | |
485 | * 'cupsdLogJob()' - Log a job message. | |
486 | */ | |
487 | ||
488 | int /* O - 1 on success, 0 on error */ | |
489 | cupsdLogJob(cupsd_job_t *job, /* I - Job */ | |
490 | int level, /* I - Log level */ | |
491 | const char *message, /* I - Printf-style message string */ | |
492 | ...) /* I - Additional arguments as needed */ | |
493 | { | |
494 | va_list ap, ap2; /* Argument pointers */ | |
495 | char jobmsg[1024]; /* Format string for job message */ | |
496 | int status; /* Formatting status */ | |
497 | ||
498 | ||
499 | /* | |
500 | * See if we want to log this message... | |
501 | */ | |
502 | ||
503 | if (TestConfigFile || !ErrorLog) | |
504 | return (1); | |
505 | ||
506 | if ((level > LogLevel || | |
507 | (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) && | |
508 | LogDebugHistory <= 0) | |
509 | return (1); | |
510 | ||
511 | /* | |
512 | * Format and write the log message... | |
513 | */ | |
514 | ||
515 | if (job) | |
516 | snprintf(jobmsg, sizeof(jobmsg), "[Job %d] %s", job->id, message); | |
517 | else | |
518 | strlcpy(jobmsg, message, sizeof(jobmsg)); | |
519 | ||
520 | va_start(ap, message); | |
521 | ||
522 | do | |
523 | { | |
524 | va_copy(ap2, ap); | |
525 | status = format_log_line(jobmsg, ap2); | |
526 | va_end(ap2); | |
527 | } | |
528 | while (status == 0); | |
529 | ||
530 | va_end(ap); | |
531 | ||
532 | if (status > 0) | |
533 | { | |
534 | if (job && | |
535 | (level > LogLevel || | |
536 | (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) && | |
537 | LogDebugHistory > 0) | |
538 | { | |
539 | /* | |
540 | * Add message to the job history... | |
541 | */ | |
542 | ||
543 | cupsd_joblog_t *temp; /* Copy of log message */ | |
544 | ||
545 | ||
546 | if ((temp = malloc(sizeof(cupsd_joblog_t) + strlen(log_line))) != NULL) | |
547 | { | |
548 | temp->time = time(NULL); | |
549 | strlcpy(temp->message, log_line, sizeof(temp->message)); | |
550 | } | |
551 | ||
552 | if (!job->history) | |
553 | job->history = cupsArrayNew(NULL, NULL); | |
554 | ||
555 | if (job->history && temp) | |
556 | { | |
557 | cupsArrayAdd(job->history, temp); | |
558 | ||
559 | if (cupsArrayCount(job->history) > LogDebugHistory) | |
560 | { | |
561 | /* | |
562 | * Remove excess messages... | |
563 | */ | |
564 | ||
565 | temp = cupsArrayFirst(job->history); | |
566 | cupsArrayRemove(job->history, temp); | |
567 | free(temp); | |
568 | } | |
569 | } | |
570 | else if (temp) | |
571 | free(temp); | |
572 | ||
573 | return (1); | |
574 | } | |
575 | else if (level <= LogLevel && | |
576 | (level != CUPSD_LOG_INFO || LogLevel >= CUPSD_LOG_DEBUG)) | |
577 | return (cupsdWriteErrorLog(level, log_line)); | |
578 | else | |
579 | return (1); | |
580 | } | |
581 | else | |
582 | return (cupsdWriteErrorLog(CUPSD_LOG_ERROR, | |
583 | "Unable to allocate memory for log line.")); | |
584 | } | |
585 | ||
586 | ||
587 | /* | |
588 | * 'cupsdLogMessage()' - Log a message to the error log file. | |
589 | */ | |
590 | ||
591 | int /* O - 1 on success, 0 on error */ | |
592 | cupsdLogMessage(int level, /* I - Log level */ | |
593 | const char *message, /* I - printf-style message string */ | |
594 | ...) /* I - Additional args as needed */ | |
595 | { | |
596 | va_list ap, ap2; /* Argument pointers */ | |
597 | int status; /* Formatting status */ | |
598 | ||
599 | ||
600 | /* | |
601 | * See if we want to log this message... | |
602 | */ | |
603 | ||
604 | if ((TestConfigFile || !ErrorLog) && level <= CUPSD_LOG_WARN) | |
605 | { | |
606 | va_start(ap, message); | |
607 | #ifdef HAVE_VSYSLOG | |
608 | vsyslog(LOG_LPR | syslevels[level], message, ap); | |
609 | #else | |
610 | vfprintf(stderr, message, ap); | |
611 | putc('\n', stderr); | |
612 | #endif /* HAVE_VSYSLOG */ | |
613 | va_end(ap); | |
614 | ||
615 | return (1); | |
616 | } | |
617 | ||
618 | if (level > LogLevel || !ErrorLog) | |
619 | return (1); | |
620 | ||
621 | /* | |
622 | * Format and write the log message... | |
623 | */ | |
624 | ||
625 | va_start(ap, message); | |
626 | ||
627 | do | |
628 | { | |
629 | va_copy(ap2, ap); | |
630 | status = format_log_line(message, ap2); | |
631 | va_end(ap2); | |
632 | } | |
633 | while (status == 0); | |
634 | ||
635 | va_end(ap); | |
636 | ||
637 | if (status > 0) | |
638 | return (cupsdWriteErrorLog(level, log_line)); | |
639 | else | |
640 | return (cupsdWriteErrorLog(CUPSD_LOG_ERROR, | |
641 | "Unable to allocate memory for log line!")); | |
642 | } | |
643 | ||
644 | ||
645 | /* | |
646 | * 'cupsdLogPage()' - Log a page to the page log file. | |
647 | */ | |
648 | ||
649 | int /* O - 1 on success, 0 on error */ | |
650 | cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ | |
651 | const char *page) /* I - Page being printed */ | |
652 | { | |
653 | int i; /* Looping var */ | |
654 | char buffer[2048], /* Buffer for page log */ | |
655 | *bufptr, /* Pointer into buffer */ | |
656 | name[256]; /* Attribute name */ | |
657 | const char *format, /* Pointer into PageLogFormat */ | |
658 | *nameend; /* End of attribute name */ | |
659 | ipp_attribute_t *attr; /* Current attribute */ | |
660 | char number[256]; /* Page number */ | |
661 | int copies; /* Number of copies */ | |
662 | ||
663 | ||
664 | /* | |
665 | * Format the line going into the page log... | |
666 | */ | |
667 | ||
668 | if (!PageLogFormat) | |
669 | return (1); | |
670 | ||
671 | strlcpy(number, "1", sizeof(number)); | |
672 | copies = 1; | |
673 | sscanf(page, "%255s%d", number, &copies); | |
674 | ||
675 | for (format = PageLogFormat, bufptr = buffer; *format; format ++) | |
676 | { | |
677 | if (*format == '%') | |
678 | { | |
679 | format ++; | |
680 | ||
681 | switch (*format) | |
682 | { | |
683 | case '%' : /* Literal % */ | |
684 | if (bufptr < (buffer + sizeof(buffer) - 1)) | |
685 | *bufptr++ = '%'; | |
686 | break; | |
687 | ||
688 | case 'p' : /* Printer name */ | |
689 | strlcpy(bufptr, job->printer->name, | |
690 | sizeof(buffer) - (bufptr - buffer)); | |
691 | bufptr += strlen(bufptr); | |
692 | break; | |
693 | ||
694 | case 'j' : /* Job ID */ | |
695 | snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), "%d", job->id); | |
696 | bufptr += strlen(bufptr); | |
697 | break; | |
698 | ||
699 | case 'u' : /* Username */ | |
700 | strlcpy(bufptr, job->username ? job->username : "-", | |
701 | sizeof(buffer) - (bufptr - buffer)); | |
702 | bufptr += strlen(bufptr); | |
703 | break; | |
704 | ||
705 | case 'T' : /* Date and time */ | |
706 | strlcpy(bufptr, cupsdGetDateTime(NULL, LogTimeFormat), | |
707 | sizeof(buffer) - (bufptr - buffer)); | |
708 | bufptr += strlen(bufptr); | |
709 | break; | |
710 | ||
711 | case 'P' : /* Page number */ | |
712 | strlcpy(bufptr, number, sizeof(buffer) - (bufptr - buffer)); | |
713 | bufptr += strlen(bufptr); | |
714 | break; | |
715 | ||
716 | case 'C' : /* Number of copies */ | |
717 | snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), "%d", copies); | |
718 | bufptr += strlen(bufptr); | |
719 | break; | |
720 | ||
721 | case '{' : /* {attribute} */ | |
722 | if ((nameend = strchr(format, '}')) != NULL && | |
723 | (nameend - format - 2) < (sizeof(name) - 1)) | |
724 | { | |
725 | /* | |
726 | * Pull the name from inside the brackets... | |
727 | */ | |
728 | ||
729 | memcpy(name, format + 1, nameend - format - 1); | |
730 | name[nameend - format - 1] = '\0'; | |
731 | ||
732 | format = nameend; | |
733 | ||
734 | if ((attr = ippFindAttribute(job->attrs, name, | |
735 | IPP_TAG_ZERO)) != NULL) | |
736 | { | |
737 | /* | |
738 | * Add the attribute value... | |
739 | */ | |
740 | ||
741 | for (i = 0; | |
742 | i < attr->num_values && | |
743 | bufptr < (buffer + sizeof(buffer) - 1); | |
744 | i ++) | |
745 | { | |
746 | if (i) | |
747 | *bufptr++ = ','; | |
748 | ||
749 | switch (attr->value_tag) | |
750 | { | |
751 | case IPP_TAG_INTEGER : | |
752 | case IPP_TAG_ENUM : | |
753 | snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), | |
754 | "%d", attr->values[i].integer); | |
755 | bufptr += strlen(bufptr); | |
756 | break; | |
757 | ||
758 | case IPP_TAG_BOOLEAN : | |
759 | snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), | |
760 | "%d", attr->values[i].boolean); | |
761 | bufptr += strlen(bufptr); | |
762 | break; | |
763 | ||
764 | case IPP_TAG_TEXTLANG : | |
765 | case IPP_TAG_NAMELANG : | |
766 | case IPP_TAG_TEXT : | |
767 | case IPP_TAG_NAME : | |
768 | case IPP_TAG_KEYWORD : | |
769 | case IPP_TAG_URI : | |
770 | case IPP_TAG_URISCHEME : | |
771 | case IPP_TAG_CHARSET : | |
772 | case IPP_TAG_LANGUAGE : | |
773 | case IPP_TAG_MIMETYPE : | |
774 | strlcpy(bufptr, attr->values[i].string.text, | |
775 | sizeof(buffer) - (bufptr - buffer)); | |
776 | bufptr += strlen(bufptr); | |
777 | break; | |
778 | ||
779 | default : | |
780 | strlcpy(bufptr, "???", | |
781 | sizeof(buffer) - (bufptr - buffer)); | |
782 | bufptr += strlen(bufptr); | |
783 | break; | |
784 | } | |
785 | } | |
786 | } | |
787 | else if (bufptr < (buffer + sizeof(buffer) - 1)) | |
788 | *bufptr++ = '-'; | |
789 | break; | |
790 | } | |
791 | ||
792 | default : | |
793 | if (bufptr < (buffer + sizeof(buffer) - 2)) | |
794 | { | |
795 | *bufptr++ = '%'; | |
796 | *bufptr++ = *format; | |
797 | } | |
798 | break; | |
799 | } | |
800 | } | |
801 | else if (bufptr < (buffer + sizeof(buffer) - 1)) | |
802 | *bufptr++ = *format; | |
803 | } | |
804 | ||
805 | *bufptr = '\0'; | |
806 | ||
807 | #ifdef HAVE_VSYSLOG | |
808 | /* | |
809 | * See if we are logging pages via syslog... | |
810 | */ | |
811 | ||
812 | if (!strcmp(PageLog, "syslog")) | |
813 | { | |
814 | syslog(LOG_INFO, "%s", buffer); | |
815 | ||
816 | return (1); | |
817 | } | |
818 | #endif /* HAVE_VSYSLOG */ | |
819 | ||
820 | /* | |
821 | * Not using syslog; check the log file... | |
822 | */ | |
823 | ||
824 | if (!cupsdCheckLogFile(&PageFile, PageLog)) | |
825 | return (0); | |
826 | ||
827 | /* | |
828 | * Print a page log entry of the form: | |
829 | * | |
830 | * printer user job-id [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \ | |
831 | * billing hostname | |
832 | */ | |
833 | ||
834 | cupsFilePrintf(PageFile, "%s\n", buffer); | |
835 | cupsFileFlush(PageFile); | |
836 | ||
837 | return (1); | |
838 | } | |
839 | ||
840 | ||
841 | /* | |
842 | * 'cupsdLogRequest()' - Log an HTTP request in Common Log Format. | |
843 | */ | |
844 | ||
845 | int /* O - 1 on success, 0 on error */ | |
846 | cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ | |
847 | http_status_t code) /* I - Response code */ | |
848 | { | |
849 | char temp[2048]; /* Temporary string for URI */ | |
850 | static const char * const states[] = /* HTTP client states... */ | |
851 | { | |
852 | "WAITING", | |
853 | "OPTIONS", | |
854 | "GET", | |
855 | "GET", | |
856 | "HEAD", | |
857 | "POST", | |
858 | "POST", | |
859 | "POST", | |
860 | "PUT", | |
861 | "PUT", | |
862 | "DELETE", | |
863 | "TRACE", | |
864 | "CLOSE", | |
865 | "STATUS" | |
866 | }; | |
867 | ||
868 | ||
869 | /* | |
870 | * Filter requests as needed... | |
871 | */ | |
872 | ||
873 | if (AccessLogLevel < CUPSD_ACCESSLOG_ALL) | |
874 | { | |
875 | /* | |
876 | * Eliminate simple GET, POST, and PUT requests... | |
877 | */ | |
878 | ||
879 | if ((con->operation == HTTP_GET && | |
880 | strncmp(con->uri, "/admin/conf", 11) && | |
881 | strncmp(con->uri, "/admin/log", 10)) || | |
882 | (con->operation == HTTP_POST && !con->request && | |
883 | strncmp(con->uri, "/admin", 6)) || | |
884 | (con->operation != HTTP_GET && con->operation != HTTP_POST && | |
885 | con->operation != HTTP_PUT)) | |
886 | return (1); | |
887 | ||
888 | if (con->request && con->response && | |
889 | (con->response->request.status.status_code < IPP_REDIRECTION_OTHER_SITE || | |
890 | con->response->request.status.status_code == IPP_NOT_FOUND)) | |
891 | { | |
892 | /* | |
893 | * Check successful requests... | |
894 | */ | |
895 | ||
896 | ipp_op_t op = con->request->request.op.operation_id; | |
897 | static cupsd_accesslog_t standard_ops[] = | |
898 | { | |
899 | CUPSD_ACCESSLOG_ALL, /* reserved */ | |
900 | CUPSD_ACCESSLOG_ALL, /* reserved */ | |
901 | CUPSD_ACCESSLOG_ACTIONS,/* Print-Job */ | |
902 | CUPSD_ACCESSLOG_ACTIONS,/* Print-URI */ | |
903 | CUPSD_ACCESSLOG_ACTIONS,/* Validate-Job */ | |
904 | CUPSD_ACCESSLOG_ACTIONS,/* Create-Job */ | |
905 | CUPSD_ACCESSLOG_ACTIONS,/* Send-Document */ | |
906 | CUPSD_ACCESSLOG_ACTIONS,/* Send-URI */ | |
907 | CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Job */ | |
908 | CUPSD_ACCESSLOG_ALL, /* Get-Job-Attributes */ | |
909 | CUPSD_ACCESSLOG_ALL, /* Get-Jobs */ | |
910 | CUPSD_ACCESSLOG_ALL, /* Get-Printer-Attributes */ | |
911 | CUPSD_ACCESSLOG_ACTIONS,/* Hold-Job */ | |
912 | CUPSD_ACCESSLOG_ACTIONS,/* Release-Job */ | |
913 | CUPSD_ACCESSLOG_ACTIONS,/* Restart-Job */ | |
914 | CUPSD_ACCESSLOG_ALL, /* reserved */ | |
915 | CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer */ | |
916 | CUPSD_ACCESSLOG_CONFIG, /* Resume-Printer */ | |
917 | CUPSD_ACCESSLOG_CONFIG, /* Purge-Jobs */ | |
918 | CUPSD_ACCESSLOG_CONFIG, /* Set-Printer-Attributes */ | |
919 | CUPSD_ACCESSLOG_ACTIONS,/* Set-Job-Attributes */ | |
920 | CUPSD_ACCESSLOG_CONFIG, /* Get-Printer-Supported-Values */ | |
921 | CUPSD_ACCESSLOG_ACTIONS,/* Create-Printer-Subscription */ | |
922 | CUPSD_ACCESSLOG_ACTIONS,/* Create-Job-Subscription */ | |
923 | CUPSD_ACCESSLOG_ALL, /* Get-Subscription-Attributes */ | |
924 | CUPSD_ACCESSLOG_ALL, /* Get-Subscriptions */ | |
925 | CUPSD_ACCESSLOG_ACTIONS,/* Renew-Subscription */ | |
926 | CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Subscription */ | |
927 | CUPSD_ACCESSLOG_ALL, /* Get-Notifications */ | |
928 | CUPSD_ACCESSLOG_ACTIONS,/* Send-Notifications */ | |
929 | CUPSD_ACCESSLOG_ALL, /* reserved */ | |
930 | CUPSD_ACCESSLOG_ALL, /* reserved */ | |
931 | CUPSD_ACCESSLOG_ALL, /* reserved */ | |
932 | CUPSD_ACCESSLOG_ALL, /* Get-Print-Support-Files */ | |
933 | CUPSD_ACCESSLOG_CONFIG, /* Enable-Printer */ | |
934 | CUPSD_ACCESSLOG_CONFIG, /* Disable-Printer */ | |
935 | CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer-After-Current-Job */ | |
936 | CUPSD_ACCESSLOG_ACTIONS,/* Hold-New-Jobs */ | |
937 | CUPSD_ACCESSLOG_ACTIONS,/* Release-Held-New-Jobs */ | |
938 | CUPSD_ACCESSLOG_CONFIG, /* Deactivate-Printer */ | |
939 | CUPSD_ACCESSLOG_CONFIG, /* Activate-Printer */ | |
940 | CUPSD_ACCESSLOG_CONFIG, /* Restart-Printer */ | |
941 | CUPSD_ACCESSLOG_CONFIG, /* Shutdown-Printer */ | |
942 | CUPSD_ACCESSLOG_CONFIG, /* Startup-Printer */ | |
943 | CUPSD_ACCESSLOG_ACTIONS,/* Reprocess-Job */ | |
944 | CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Current-Job */ | |
945 | CUPSD_ACCESSLOG_ACTIONS,/* Suspend-Current-Job */ | |
946 | CUPSD_ACCESSLOG_ACTIONS,/* Resume-Job */ | |
947 | CUPSD_ACCESSLOG_ACTIONS,/* Promote-Job */ | |
948 | CUPSD_ACCESSLOG_ACTIONS /* Schedule-Job-After */ | |
949 | }; | |
950 | static cupsd_accesslog_t cups_ops[] = | |
951 | { | |
952 | CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Default */ | |
953 | CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Printers */ | |
954 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Printer */ | |
955 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Printer */ | |
956 | CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Classes */ | |
957 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Class */ | |
958 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Class */ | |
959 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Accept-Jobs */ | |
960 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Reject-Jobs */ | |
961 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Set-Default */ | |
962 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-Devices */ | |
963 | CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-PPDs */ | |
964 | CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Move-Job */ | |
965 | CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Authenticate-Job */ | |
966 | CUPSD_ACCESSLOG_ALL /* CUPS-Get-PPD */ | |
967 | }; | |
968 | ||
969 | ||
970 | if ((op <= IPP_SCHEDULE_JOB_AFTER && standard_ops[op] > AccessLogLevel) || | |
971 | (op >= CUPS_GET_DEFAULT && op <= CUPS_GET_PPD && | |
972 | cups_ops[op - CUPS_GET_DEFAULT] > AccessLogLevel)) | |
973 | return (1); | |
974 | } | |
975 | } | |
976 | ||
977 | #ifdef HAVE_VSYSLOG | |
978 | /* | |
979 | * See if we are logging accesses via syslog... | |
980 | */ | |
981 | ||
982 | if (!strcmp(AccessLog, "syslog")) | |
983 | { | |
984 | syslog(LOG_INFO, | |
985 | "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n", | |
986 | con->http->hostname, con->username[0] != '\0' ? con->username : "-", | |
987 | states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)), | |
988 | con->http->version / 100, con->http->version % 100, | |
989 | code, CUPS_LLCAST con->bytes, | |
990 | con->request ? | |
991 | ippOpString(con->request->request.op.operation_id) : "-", | |
992 | con->response ? | |
993 | ippErrorString(con->response->request.status.status_code) : "-"); | |
994 | ||
995 | return (1); | |
996 | } | |
997 | #endif /* HAVE_VSYSLOG */ | |
998 | ||
999 | /* | |
1000 | * Not using syslog; check the log file... | |
1001 | */ | |
1002 | ||
1003 | if (!cupsdCheckLogFile(&AccessFile, AccessLog)) | |
1004 | return (0); | |
1005 | ||
1006 | /* | |
1007 | * Write a log of the request in "common log format"... | |
1008 | */ | |
1009 | ||
1010 | cupsFilePrintf(AccessFile, | |
1011 | "%s - %s %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n", | |
1012 | con->http->hostname, | |
1013 | con->username[0] != '\0' ? con->username : "-", | |
1014 | cupsdGetDateTime(&(con->start), LogTimeFormat), | |
1015 | states[con->operation], | |
1016 | _httpEncodeURI(temp, con->uri, sizeof(temp)), | |
1017 | con->http->version / 100, con->http->version % 100, | |
1018 | code, CUPS_LLCAST con->bytes, | |
1019 | con->request ? | |
1020 | ippOpString(con->request->request.op.operation_id) : "-", | |
1021 | con->response ? | |
1022 | ippErrorString(con->response->request.status.status_code) : | |
1023 | "-"); | |
1024 | ||
1025 | cupsFileFlush(AccessFile); | |
1026 | ||
1027 | return (1); | |
1028 | } | |
1029 | ||
1030 | ||
1031 | /* | |
1032 | * 'cupsdWriteErrorLog()' - Write a line to the ErrorLog. | |
1033 | */ | |
1034 | ||
1035 | int /* O - 1 on success, 0 on failure */ | |
1036 | cupsdWriteErrorLog(int level, /* I - Log level */ | |
1037 | const char *message) /* I - Message string */ | |
1038 | { | |
1039 | int ret = 1; /* Return value */ | |
1040 | static const char levels[] = /* Log levels... */ | |
1041 | { | |
1042 | ' ', | |
1043 | 'X', | |
1044 | 'A', | |
1045 | 'C', | |
1046 | 'E', | |
1047 | 'W', | |
1048 | 'N', | |
1049 | 'I', | |
1050 | 'D', | |
1051 | 'd' | |
1052 | }; | |
1053 | ||
1054 | ||
1055 | #ifdef HAVE_VSYSLOG | |
1056 | /* | |
1057 | * See if we are logging errors via syslog... | |
1058 | */ | |
1059 | ||
1060 | if (!strcmp(ErrorLog, "syslog")) | |
1061 | { | |
1062 | syslog(syslevels[level], "%s", message); | |
1063 | return (1); | |
1064 | } | |
1065 | #endif /* HAVE_VSYSLOG */ | |
1066 | ||
1067 | /* | |
1068 | * Not using syslog; check the log file... | |
1069 | */ | |
1070 | ||
1071 | _cupsMutexLock(&log_mutex); | |
1072 | ||
1073 | if (!cupsdCheckLogFile(&ErrorFile, ErrorLog)) | |
1074 | { | |
1075 | ret = 0; | |
1076 | } | |
1077 | else | |
1078 | { | |
1079 | /* | |
1080 | * Write the log message... | |
1081 | */ | |
1082 | ||
1083 | cupsFilePrintf(ErrorFile, "%c %s %s\n", levels[level], | |
1084 | cupsdGetDateTime(NULL, LogTimeFormat), message); | |
1085 | cupsFileFlush(ErrorFile); | |
1086 | } | |
1087 | ||
1088 | _cupsMutexUnlock(&log_mutex); | |
1089 | ||
1090 | return (ret); | |
1091 | } | |
1092 | ||
1093 | ||
1094 | /* | |
1095 | * 'format_log_line()' - Format a line for a log file. | |
1096 | * | |
1097 | * This function resizes a global string buffer as needed. Each call returns | |
1098 | * a pointer to this buffer, so the contents are only good until the next call | |
1099 | * to format_log_line()... | |
1100 | */ | |
1101 | ||
1102 | static int /* O - -1 for fatal, 0 for retry, 1 for success */ | |
1103 | format_log_line(const char *message, /* I - Printf-style format string */ | |
1104 | va_list ap) /* I - Argument list */ | |
1105 | { | |
1106 | int len; /* Length of formatted line */ | |
1107 | ||
1108 | ||
1109 | /* | |
1110 | * Allocate the line buffer as needed... | |
1111 | */ | |
1112 | ||
1113 | if (!log_linesize) | |
1114 | { | |
1115 | log_linesize = 8192; | |
1116 | log_line = malloc(log_linesize); | |
1117 | ||
1118 | if (!log_line) | |
1119 | return (-1); | |
1120 | } | |
1121 | ||
1122 | /* | |
1123 | * Format the log message... | |
1124 | */ | |
1125 | ||
1126 | len = vsnprintf(log_line, log_linesize, message, ap); | |
1127 | ||
1128 | /* | |
1129 | * Resize the buffer as needed... | |
1130 | */ | |
1131 | ||
1132 | if (len >= log_linesize && log_linesize < 65536) | |
1133 | { | |
1134 | char *temp; /* Temporary string pointer */ | |
1135 | ||
1136 | ||
1137 | len ++; | |
1138 | ||
1139 | if (len < 8192) | |
1140 | len = 8192; | |
1141 | else if (len > 65536) | |
1142 | len = 65536; | |
1143 | ||
1144 | temp = realloc(log_line, len); | |
1145 | ||
1146 | if (temp) | |
1147 | { | |
1148 | log_line = temp; | |
1149 | log_linesize = len; | |
1150 | ||
1151 | return (0); | |
1152 | } | |
1153 | } | |
1154 | ||
1155 | return (1); | |
1156 | } | |
1157 | ||
1158 | ||
1159 | /* | |
1160 | * End of "$Id$". | |
1161 | */ |