]> git.ipfire.org Git - thirdparty/cups.git/blob - scheduler/log.c
projects / thirdparty / cups.git / blob
? search:


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