]>
Commit | Line | Data |
---|---|---|
ef416fc2 | 1 | /* |
2e4ff8af | 2 | * "$Id: log.c 6875 2007-08-27 23:25:06Z mike $" |
ef416fc2 | 3 | * |
4 | * Log file routines for the Common UNIX Printing System (CUPS). | |
5 | * | |
91c84a35 | 6 | * Copyright 2007-2008 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 | * | |
f7deaa1a | 17 | * cupsdGetDateTime() - Returns a pointer to a date/time string. |
18 | * cupsdLogGSSMessage() - Log a GSSAPI error... | |
19 | * cupsdLogMessage() - Log a message to the error log file. | |
20 | * cupsdLogPage() - Log a page to the page log file. | |
21 | * cupsdLogRequest() - Log an HTTP request in Common Log Format. | |
22 | * check_log_file() - Open/rotate a log file if it needs it. | |
ef416fc2 | 23 | */ |
24 | ||
25 | /* | |
26 | * Include necessary headers... | |
27 | */ | |
28 | ||
29 | #include "cupsd.h" | |
30 | #include <stdarg.h> | |
b423cd4c | 31 | #include <syslog.h> |
ef416fc2 | 32 | |
33 | ||
34 | /* | |
35 | * Local functions... | |
36 | */ | |
37 | ||
38 | static int check_log_file(cups_file_t **, const char *); | |
39 | ||
40 | ||
41 | /* | |
42 | * 'cupsdGetDateTime()' - Returns a pointer to a date/time string. | |
43 | */ | |
44 | ||
45 | char * /* O - Date/time string */ | |
46 | cupsdGetDateTime(time_t t) /* I - Time value */ | |
47 | { | |
48 | struct tm *date; /* Date/time value */ | |
49 | static time_t last_time = -1; /* Last time value */ | |
50 | static char s[1024]; /* Date/time string */ | |
51 | static const char * const months[12] =/* Months */ | |
52 | { | |
53 | "Jan", | |
54 | "Feb", | |
55 | "Mar", | |
56 | "Apr", | |
57 | "May", | |
58 | "Jun", | |
59 | "Jul", | |
60 | "Aug", | |
61 | "Sep", | |
62 | "Oct", | |
63 | "Nov", | |
64 | "Dec" | |
65 | }; | |
66 | ||
67 | ||
839a51c8 MS |
68 | /* |
69 | * Make sure we have a valid time... | |
70 | */ | |
71 | ||
72 | if (!t) | |
73 | t = time(NULL); | |
74 | ||
ef416fc2 | 75 | if (t != last_time) |
76 | { | |
77 | last_time = t; | |
78 | ||
79 | /* | |
80 | * Get the date and time from the UNIX time value, and then format it | |
81 | * into a string. Note that we *can't* use the strftime() function since | |
82 | * it is localized and will seriously confuse automatic programs if the | |
83 | * month names are in the wrong language! | |
84 | * | |
85 | * Also, we use the "timezone" variable that contains the current timezone | |
86 | * offset from GMT in seconds so that we are reporting local time in the | |
87 | * log files. If you want GMT, set the TZ environment variable accordingly | |
88 | * before starting the scheduler. | |
89 | * | |
90 | * (*BSD and Darwin store the timezone offset in the tm structure) | |
91 | */ | |
92 | ||
93 | date = localtime(&t); | |
94 | ||
95 | snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d %+03ld%02ld]", | |
96 | date->tm_mday, months[date->tm_mon], 1900 + date->tm_year, | |
97 | date->tm_hour, date->tm_min, date->tm_sec, | |
98 | #ifdef HAVE_TM_GMTOFF | |
99 | date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60); | |
100 | #else | |
101 | timezone / 3600, (timezone / 60) % 60); | |
102 | #endif /* HAVE_TM_GMTOFF */ | |
103 | } | |
104 | ||
105 | return (s); | |
106 | } | |
107 | ||
108 | ||
f7deaa1a | 109 | #ifdef HAVE_GSSAPI |
110 | /* | |
111 | * 'cupsdLogGSSMessage()' - Log a GSSAPI error... | |
112 | */ | |
113 | ||
114 | int /* O - 1 on success, 0 on error */ | |
115 | cupsdLogGSSMessage( | |
116 | int level, /* I - Log level */ | |
117 | int major_status, /* I - Major GSSAPI status */ | |
118 | int minor_status, /* I - Minor GSSAPI status */ | |
119 | const char *message, /* I - printf-style message string */ | |
120 | ...) /* I - Additional args as needed */ | |
121 | { | |
122 | OM_uint32 err_major_status, /* Major status code for display */ | |
123 | err_minor_status; /* Minor status code for display */ | |
124 | OM_uint32 msg_ctx; /* Message context */ | |
125 | gss_buffer_desc major_status_string = GSS_C_EMPTY_BUFFER, | |
126 | /* Major status message */ | |
127 | minor_status_string = GSS_C_EMPTY_BUFFER; | |
128 | /* Minor status message */ | |
129 | int ret; /* Return value */ | |
130 | ||
131 | ||
132 | msg_ctx = 0; | |
133 | err_major_status = gss_display_status(&err_minor_status, | |
134 | major_status, | |
135 | GSS_C_GSS_CODE, | |
136 | GSS_C_NO_OID, | |
137 | &msg_ctx, | |
138 | &major_status_string); | |
139 | ||
140 | if (!GSS_ERROR(err_major_status)) | |
141 | err_major_status = gss_display_status(&err_minor_status, | |
142 | minor_status, | |
143 | GSS_C_MECH_CODE, | |
144 | GSS_C_NULL_OID, | |
145 | &msg_ctx, | |
146 | &minor_status_string); | |
147 | ||
148 | ret = cupsdLogMessage(level, "%s: %s, %s", message, | |
149 | (char *)major_status_string.value, | |
150 | (char *)minor_status_string.value); | |
151 | gss_release_buffer(&err_minor_status, &major_status_string); | |
152 | gss_release_buffer(&err_minor_status, &minor_status_string); | |
153 | ||
154 | return (ret); | |
155 | } | |
156 | #endif /* HAVE_GSSAPI */ | |
157 | ||
158 | ||
ef416fc2 | 159 | /* |
160 | * 'cupsdLogMessage()' - Log a message to the error log file. | |
161 | */ | |
162 | ||
163 | int /* O - 1 on success, 0 on error */ | |
164 | cupsdLogMessage(int level, /* I - Log level */ | |
165 | const char *message, /* I - printf-style message string */ | |
166 | ...) /* I - Additional args as needed */ | |
167 | { | |
168 | int len; /* Length of message */ | |
169 | va_list ap; /* Argument pointer */ | |
170 | static const char levels[] = /* Log levels... */ | |
171 | { | |
172 | ' ', | |
173 | 'X', | |
174 | 'A', | |
175 | 'C', | |
176 | 'E', | |
177 | 'W', | |
178 | 'N', | |
179 | 'I', | |
180 | 'D', | |
181 | 'd' | |
182 | }; | |
183 | #ifdef HAVE_VSYSLOG | |
839a51c8 | 184 | static const int syslevels[] = /* SYSLOG levels... */ |
ef416fc2 | 185 | { |
186 | 0, | |
187 | LOG_EMERG, | |
188 | LOG_ALERT, | |
189 | LOG_CRIT, | |
190 | LOG_ERR, | |
191 | LOG_WARNING, | |
192 | LOG_NOTICE, | |
193 | LOG_INFO, | |
194 | LOG_DEBUG, | |
195 | LOG_DEBUG | |
196 | }; | |
197 | #endif /* HAVE_VSYSLOG */ | |
839a51c8 MS |
198 | static int linesize = 0; /* Size of line for output file */ |
199 | static char *line = NULL; /* Line for output file */ | |
ef416fc2 | 200 | |
201 | ||
202 | /* | |
203 | * See if we want to log this message... | |
204 | */ | |
205 | ||
2e4ff8af MS |
206 | if (TestConfigFile) |
207 | { | |
208 | if (level <= CUPSD_LOG_WARN) | |
209 | { | |
210 | va_start(ap, message); | |
211 | vfprintf(stderr, message, ap); | |
212 | putc('\n', stderr); | |
213 | va_end(ap); | |
214 | } | |
215 | ||
216 | return (1); | |
217 | } | |
218 | ||
ef416fc2 | 219 | if (level > LogLevel || !ErrorLog) |
220 | return (1); | |
221 | ||
222 | #ifdef HAVE_VSYSLOG | |
223 | /* | |
224 | * See if we are logging errors via syslog... | |
225 | */ | |
226 | ||
227 | if (!strcmp(ErrorLog, "syslog")) | |
228 | { | |
229 | va_start(ap, message); | |
230 | vsyslog(syslevels[level], message, ap); | |
231 | va_end(ap); | |
232 | ||
233 | return (1); | |
234 | } | |
235 | #endif /* HAVE_VSYSLOG */ | |
236 | ||
237 | /* | |
238 | * Not using syslog; check the log file... | |
239 | */ | |
240 | ||
241 | if (!check_log_file(&ErrorFile, ErrorLog)) | |
242 | return (0); | |
243 | ||
244 | /* | |
245 | * Print the log level and date/time... | |
246 | */ | |
247 | ||
248 | cupsFilePrintf(ErrorFile, "%c %s ", levels[level], cupsdGetDateTime(time(NULL))); | |
249 | ||
250 | /* | |
251 | * Allocate the line buffer as needed... | |
252 | */ | |
253 | ||
254 | if (!linesize) | |
255 | { | |
256 | linesize = 8192; | |
257 | line = malloc(linesize); | |
258 | ||
259 | if (!line) | |
260 | { | |
261 | cupsFilePrintf(ErrorFile, | |
262 | "ERROR: Unable to allocate memory for line - %s\n", | |
263 | strerror(errno)); | |
264 | cupsFileFlush(ErrorFile); | |
265 | ||
266 | return (0); | |
267 | } | |
268 | } | |
269 | ||
270 | /* | |
271 | * Format the log message... | |
272 | */ | |
273 | ||
274 | va_start(ap, message); | |
275 | len = vsnprintf(line, linesize, message, ap); | |
276 | va_end(ap); | |
277 | ||
278 | /* | |
279 | * Resize the buffer as needed... | |
280 | */ | |
281 | ||
282 | if (len >= linesize) | |
283 | { | |
91c84a35 MS |
284 | char *temp; /* Temporary string pointer */ |
285 | ||
286 | ||
ef416fc2 | 287 | len ++; |
288 | ||
289 | if (len < 8192) | |
290 | len = 8192; | |
291 | else if (len > 65536) | |
292 | len = 65536; | |
293 | ||
91c84a35 | 294 | temp = realloc(line, len); |
ef416fc2 | 295 | |
91c84a35 | 296 | if (temp) |
ef416fc2 | 297 | { |
91c84a35 MS |
298 | line = temp; |
299 | linesize = len; | |
ef416fc2 | 300 | } |
301 | ||
302 | va_start(ap, message); | |
303 | len = vsnprintf(line, linesize, message, ap); | |
304 | va_end(ap); | |
305 | } | |
306 | ||
307 | if (len >= linesize) | |
308 | len = linesize - 1; | |
309 | ||
310 | /* | |
311 | * Then the log message... | |
312 | */ | |
313 | ||
314 | cupsFilePuts(ErrorFile, line); | |
315 | ||
316 | /* | |
317 | * Then a newline... | |
318 | */ | |
319 | ||
320 | if (len > 0 && line[len - 1] != '\n') | |
321 | cupsFilePutChar(ErrorFile, '\n'); | |
322 | ||
323 | /* | |
324 | * Flush the line to the file and return... | |
325 | */ | |
326 | ||
327 | cupsFileFlush(ErrorFile); | |
328 | ||
329 | return (1); | |
330 | } | |
331 | ||
332 | ||
333 | /* | |
334 | * 'cupsdLogPage()' - Log a page to the page log file. | |
335 | */ | |
336 | ||
337 | int /* O - 1 on success, 0 on error */ | |
338 | cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ | |
339 | const char *page) /* I - Page being printed */ | |
340 | { | |
341 | ipp_attribute_t *billing, /* job-billing attribute */ | |
342 | *hostname; /* job-originating-host-name attribute */ | |
343 | ||
344 | ||
345 | billing = ippFindAttribute(job->attrs, "job-billing", IPP_TAG_ZERO); | |
346 | hostname = ippFindAttribute(job->attrs, "job-originating-host-name", | |
347 | IPP_TAG_ZERO); | |
348 | ||
349 | #ifdef HAVE_VSYSLOG | |
350 | /* | |
351 | * See if we are logging pages via syslog... | |
352 | */ | |
353 | ||
354 | if (!strcmp(PageLog, "syslog")) | |
355 | { | |
356 | syslog(LOG_INFO, "PAGE %s %s %d %s %s %s", job->printer->name, | |
357 | job->username ? job->username : "-", | |
358 | job->id, page, billing ? billing->values[0].string.text : "-", | |
359 | hostname->values[0].string.text); | |
360 | ||
361 | return (1); | |
362 | } | |
363 | #endif /* HAVE_VSYSLOG */ | |
364 | ||
365 | /* | |
366 | * Not using syslog; check the log file... | |
367 | */ | |
368 | ||
369 | if (!check_log_file(&PageFile, PageLog)) | |
370 | return (0); | |
371 | ||
372 | /* | |
373 | * Print a page log entry of the form: | |
374 | * | |
ac884b6a | 375 | * printer user job-id [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \ |
ef416fc2 | 376 | * billing hostname |
377 | */ | |
378 | ||
379 | cupsFilePrintf(PageFile, "%s %s %d %s %s %s %s\n", job->printer->name, | |
380 | job->username ? job->username : "-", | |
381 | job->id, cupsdGetDateTime(time(NULL)), page, | |
382 | billing ? billing->values[0].string.text : "-", | |
383 | hostname->values[0].string.text); | |
384 | cupsFileFlush(PageFile); | |
385 | ||
386 | return (1); | |
387 | } | |
388 | ||
389 | ||
390 | /* | |
391 | * 'cupsdLogRequest()' - Log an HTTP request in Common Log Format. | |
392 | */ | |
393 | ||
394 | int /* O - 1 on success, 0 on error */ | |
395 | cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ | |
396 | http_status_t code) /* I - Response code */ | |
397 | { | |
839a51c8 | 398 | char temp[2048]; /* Temporary string for URI */ |
ef416fc2 | 399 | static const char * const states[] = /* HTTP client states... */ |
400 | { | |
401 | "WAITING", | |
402 | "OPTIONS", | |
403 | "GET", | |
404 | "GET", | |
405 | "HEAD", | |
406 | "POST", | |
407 | "POST", | |
408 | "POST", | |
409 | "PUT", | |
410 | "PUT", | |
411 | "DELETE", | |
412 | "TRACE", | |
413 | "CLOSE", | |
414 | "STATUS" | |
415 | }; | |
416 | ||
417 | ||
418 | #ifdef HAVE_VSYSLOG | |
419 | /* | |
420 | * See if we are logging accesses via syslog... | |
421 | */ | |
422 | ||
423 | if (!strcmp(AccessLog, "syslog")) | |
424 | { | |
2abf387c | 425 | syslog(LOG_INFO, |
426 | "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n", | |
ef416fc2 | 427 | con->http.hostname, con->username[0] != '\0' ? con->username : "-", |
839a51c8 | 428 | states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)), |
ef416fc2 | 429 | con->http.version / 100, con->http.version % 100, |
2abf387c | 430 | code, CUPS_LLCAST con->bytes, |
431 | con->request ? | |
432 | ippOpString(con->request->request.op.operation_id) : "-", | |
433 | con->response ? | |
434 | ippErrorString(con->response->request.status.status_code) : "-"); | |
ef416fc2 | 435 | |
436 | return (1); | |
437 | } | |
438 | #endif /* HAVE_VSYSLOG */ | |
439 | ||
440 | /* | |
441 | * Not using syslog; check the log file... | |
442 | */ | |
443 | ||
444 | if (!check_log_file(&AccessFile, AccessLog)) | |
445 | return (0); | |
446 | ||
447 | /* | |
448 | * Write a log of the request in "common log format"... | |
449 | */ | |
450 | ||
451 | cupsFilePrintf(AccessFile, | |
452 | "%s - %s %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n", | |
453 | con->http.hostname, con->username[0] != '\0' ? con->username : "-", | |
839a51c8 MS |
454 | cupsdGetDateTime(con->start), states[con->operation], |
455 | _httpEncodeURI(temp, con->uri, sizeof(temp)), | |
ef416fc2 | 456 | con->http.version / 100, con->http.version % 100, |
457 | code, CUPS_LLCAST con->bytes, | |
458 | con->request ? | |
459 | ippOpString(con->request->request.op.operation_id) : "-", | |
460 | con->response ? | |
461 | ippErrorString(con->response->request.status.status_code) : | |
462 | "-"); | |
463 | ||
464 | cupsFileFlush(AccessFile); | |
465 | ||
466 | return (1); | |
467 | } | |
468 | ||
469 | ||
470 | /* | |
471 | * 'check_log_file()' - Open/rotate a log file if it needs it. | |
472 | */ | |
473 | ||
474 | static int /* O - 1 if log file open */ | |
475 | check_log_file(cups_file_t **lf, /* IO - Log file */ | |
476 | const char *logname) /* I - Log filename */ | |
477 | { | |
f7deaa1a | 478 | char backname[1024], /* Backup log filename */ |
479 | filename[1024], /* Formatted log filename */ | |
480 | *ptr; /* Pointer into filename */ | |
481 | const char *logptr; /* Pointer into log filename */ | |
ef416fc2 | 482 | |
483 | ||
484 | /* | |
485 | * See if we have a log file to check... | |
486 | */ | |
487 | ||
488 | if (!lf || !logname || !logname[0]) | |
489 | return (1); | |
490 | ||
491 | /* | |
492 | * Format the filename as needed... | |
493 | */ | |
494 | ||
a74454a7 | 495 | if (!*lf || |
496 | (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize && | |
497 | MaxLogSize > 0)) | |
ef416fc2 | 498 | { |
499 | /* | |
500 | * Handle format strings... | |
501 | */ | |
502 | ||
503 | filename[sizeof(filename) - 1] = '\0'; | |
504 | ||
505 | if (logname[0] != '/') | |
506 | { | |
507 | strlcpy(filename, ServerRoot, sizeof(filename)); | |
508 | strlcat(filename, "/", sizeof(filename)); | |
509 | } | |
510 | else | |
511 | filename[0] = '\0'; | |
512 | ||
f7deaa1a | 513 | for (logptr = logname, ptr = filename + strlen(filename); |
514 | *logptr && ptr < (filename + sizeof(filename) - 1); | |
515 | logptr ++) | |
516 | if (*logptr == '%') | |
ef416fc2 | 517 | { |
518 | /* | |
519 | * Format spec... | |
520 | */ | |
521 | ||
f7deaa1a | 522 | logptr ++; |
523 | if (*logptr == 's') | |
ef416fc2 | 524 | { |
525 | /* | |
526 | * Insert the server name... | |
527 | */ | |
528 | ||
529 | strlcpy(ptr, ServerName, sizeof(filename) - (ptr - filename)); | |
530 | ptr += strlen(ptr); | |
531 | } | |
532 | else | |
533 | { | |
534 | /* | |
535 | * Otherwise just insert the character... | |
536 | */ | |
537 | ||
f7deaa1a | 538 | *ptr++ = *logptr; |
ef416fc2 | 539 | } |
540 | } | |
541 | else | |
f7deaa1a | 542 | *ptr++ = *logptr; |
ef416fc2 | 543 | |
544 | *ptr = '\0'; | |
545 | } | |
546 | ||
547 | /* | |
548 | * See if the log file is open... | |
549 | */ | |
550 | ||
551 | if (!*lf) | |
552 | { | |
553 | /* | |
554 | * Nope, open the log file... | |
555 | */ | |
556 | ||
557 | if ((*lf = cupsFileOpen(filename, "a")) == NULL) | |
558 | { | |
b94498cf | 559 | /* |
560 | * If the file is in CUPS_LOGDIR then try to create a missing directory... | |
561 | */ | |
ef416fc2 | 562 | |
b94498cf | 563 | if (!strncmp(filename, CUPS_LOGDIR, strlen(CUPS_LOGDIR))) |
564 | { | |
565 | cupsdCheckPermissions(CUPS_LOGDIR, NULL, 0755, RunUser, Group, 1, -1); | |
566 | ||
567 | *lf = cupsFileOpen(filename, "a"); | |
568 | } | |
569 | ||
570 | if (*lf == NULL) | |
571 | { | |
572 | syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, | |
573 | strerror(errno)); | |
574 | return (0); | |
575 | } | |
ef416fc2 | 576 | } |
577 | ||
578 | if (strncmp(filename, "/dev/", 5)) | |
579 | { | |
580 | /* | |
581 | * Change ownership and permissions of non-device logs... | |
582 | */ | |
583 | ||
584 | fchown(cupsFileNumber(*lf), RunUser, Group); | |
585 | fchmod(cupsFileNumber(*lf), LogFilePerm); | |
586 | } | |
587 | } | |
588 | ||
589 | /* | |
590 | * Do we need to rotate the log? | |
591 | */ | |
592 | ||
a74454a7 | 593 | if (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize && |
594 | MaxLogSize > 0) | |
ef416fc2 | 595 | { |
596 | /* | |
597 | * Rotate log file... | |
598 | */ | |
599 | ||
600 | cupsFileClose(*lf); | |
601 | ||
602 | strcpy(backname, filename); | |
603 | strlcat(backname, ".O", sizeof(backname)); | |
604 | ||
605 | unlink(backname); | |
606 | rename(filename, backname); | |
607 | ||
608 | if ((*lf = cupsFileOpen(filename, "a")) == NULL) | |
609 | { | |
610 | syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, | |
611 | strerror(errno)); | |
612 | ||
613 | return (0); | |
614 | } | |
615 | ||
a74454a7 | 616 | /* |
617 | * Change ownership and permissions of non-device logs... | |
618 | */ | |
ef416fc2 | 619 | |
a74454a7 | 620 | fchown(cupsFileNumber(*lf), RunUser, Group); |
621 | fchmod(cupsFileNumber(*lf), LogFilePerm); | |
ef416fc2 | 622 | } |
623 | ||
624 | return (1); | |
625 | } | |
626 | ||
627 | ||
628 | /* | |
2e4ff8af | 629 | * End of "$Id: log.c 6875 2007-08-27 23:25:06Z mike $". |
ef416fc2 | 630 | */ |