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