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