/*
- * "$Id: log.c 7697 2008-06-27 15:56:00Z mike $"
+ * Log file routines for the CUPS scheduler.
*
- * Log file routines for the Common UNIX Printing System (CUPS).
+ * Copyright 2007-2017 by Apple Inc.
+ * Copyright 1997-2007 by Easy Software Products, all rights reserved.
*
- * Copyright 2007-2008 by Apple Inc.
- * Copyright 1997-2007 by Easy Software Products, all rights reserved.
- *
- * These coded instructions, statements, and computer programs are the
- * property of Apple Inc. and are protected by Federal copyright
- * law. Distribution and use rights are outlined in the file "LICENSE.txt"
- * which should have been included with this file. If this file is
- * file is missing or damaged, see the license at "http://www.cups.org/".
- *
- * Contents:
- *
- * cupsdGetDateTime() - Returns a pointer to a date/time string.
- * cupsdLogGSSMessage() - Log a GSSAPI error...
- * cupsdLogJob() - Log a job message.
- * cupsdLogMessage() - Log a message to the error log file.
- * cupsdLogPage() - Log a page to the page log file.
- * cupsdLogRequest() - Log an HTTP request in Common Log Format.
- * cupsdWriteErrorLog() - Write a line to the ErrorLog.
- * check_log_file() - Open/rotate a log file if it needs it.
- * format_log_line() - Format a line for a log file.
+ * Licensed under Apache License v2.0. See the file "LICENSE" for more information.
*/
/*
#include "cupsd.h"
#include <stdarg.h>
+#ifdef HAVE_ASL_H
+# include <asl.h>
+#elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
+# define SD_JOURNAL_SUPPRESS_LOCATION
+# include <systemd/sd-journal.h>
+#endif /* HAVE_ASL_H */
#include <syslog.h>
+/*
+ * Constants for log keys from PWG 5110.3 (PWG Common Log Format)...
+ */
+
+#define PWG_DeviceUUID "DUU"
+#define PWG_Event "E"
+#define PWG_LogNaturalLanguage "NL"
+#define PWG_Status "S"
+#define PWG_ServiceURI "URI"
+#define PWG_UserHost "UH"
+#define PWG_UserName "UN"
+#define PWG_UserURI "UU"
+#define PWG_ServiceIsAcceptingJobs "IAJ"
+#define PWG_ServiceState "ST"
+#define PWG_ServiceStateReasons "SR"
+#define PWG_ServiceUUID "SUU"
+#define PWG_JobID "JID"
+#define PWG_JobUUID "JUU"
+#define PWG_JobImagesCompleted "JIM"
+#define PWG_JobImpressionsCompleted "JIC"
+#define PWG_JobDestinationURI "JD"
+#define PWG_JobState "JS"
+#define PWG_JobStateReasons "JR"
+#define PWG_JobAccountingID "JA"
+#define PWG_JobAcountingUserName "JAUN"
+#define PWG_JobAccountingUserURI "JAUU"
+
+
/*
* Local globals...
*/
-static int log_linesize = 0; /* Size of line for output file */
+static _cups_mutex_t log_mutex = _CUPS_MUTEX_INITIALIZER;
+ /* Mutex for logging */
+static size_t log_linesize = 0; /* Size of line for output file */
static char *log_line = NULL; /* Line for output file */
+#ifdef HAVE_ASL_H
+static const int log_levels[] = /* ASL levels... */
+ {
+ ASL_LEVEL_EMERG,
+ ASL_LEVEL_EMERG,
+ ASL_LEVEL_ALERT,
+ ASL_LEVEL_CRIT,
+ ASL_LEVEL_ERR,
+ ASL_LEVEL_WARNING,
+ ASL_LEVEL_NOTICE,
+ ASL_LEVEL_INFO,
+ ASL_LEVEL_DEBUG,
+ ASL_LEVEL_DEBUG
+ };
+#elif defined(HAVE_VSYSLOG) || defined(HAVE_SYSTEMD_SD_JOURNAL_H)
+static const int log_levels[] = /* SYSLOG levels... */
+ {
+ 0,
+ LOG_EMERG,
+ LOG_ALERT,
+ LOG_CRIT,
+ LOG_ERR,
+ LOG_WARNING,
+ LOG_NOTICE,
+ LOG_INFO,
+ LOG_DEBUG,
+ LOG_DEBUG
+ };
+#endif /* HAVE_ASL_H */
+
/*
* Local functions...
*/
-static int check_log_file(cups_file_t **lf, const char *logname);
-static char *format_log_line(const char *message, va_list ap);
+static int format_log_line(const char *message, va_list ap);
+
+
+/*
+ * 'cupsdCheckLogFile()' - Open/rotate a log file if it needs it.
+ */
+
+int /* O - 1 if log file open */
+cupsdCheckLogFile(cups_file_t **lf, /* IO - Log file */
+ const char *logname) /* I - Log filename */
+{
+ char backname[1024], /* Backup log filename */
+ filename[1024], /* Formatted log filename */
+ *ptr; /* Pointer into filename */
+ const char *logptr; /* Pointer into log filename */
+
+
+ /*
+ * See if we have a log file to check...
+ */
+
+ if (!lf || !logname || !logname[0])
+ return (1);
+
+ /*
+ * Handle logging to stderr...
+ */
+
+ if (!strcmp(logname, "stderr"))
+ {
+ *lf = LogStderr;
+ return (1);
+ }
+
+ /*
+ * Format the filename as needed...
+ */
+
+ if (!*lf ||
+ (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize &&
+ MaxLogSize > 0))
+ {
+ /*
+ * Handle format strings...
+ */
+
+ filename[sizeof(filename) - 1] = '\0';
+
+ if (logname[0] != '/')
+ {
+ strlcpy(filename, ServerRoot, sizeof(filename));
+ strlcat(filename, "/", sizeof(filename));
+ }
+ else
+ filename[0] = '\0';
+
+ for (logptr = logname, ptr = filename + strlen(filename);
+ *logptr && ptr < (filename + sizeof(filename) - 1);
+ logptr ++)
+ if (*logptr == '%')
+ {
+ /*
+ * Format spec...
+ */
+
+ logptr ++;
+ if (*logptr == 's')
+ {
+ /*
+ * Insert the server name...
+ */
+
+ strlcpy(ptr, ServerName, sizeof(filename) - (size_t)(ptr - filename));
+ ptr += strlen(ptr);
+ }
+ else
+ {
+ /*
+ * Otherwise just insert the character...
+ */
+
+ *ptr++ = *logptr;
+ }
+ }
+ else
+ *ptr++ = *logptr;
+
+ *ptr = '\0';
+ }
+
+ /*
+ * See if the log file is open...
+ */
+
+ if (!*lf)
+ {
+ /*
+ * Nope, open the log file...
+ */
+
+ if ((*lf = cupsFileOpen(filename, "a")) == NULL)
+ {
+ /*
+ * If the file is in CUPS_LOGDIR then try to create a missing directory...
+ */
+
+ if (!strncmp(filename, CUPS_LOGDIR, strlen(CUPS_LOGDIR)))
+ {
+ /*
+ * Try updating the permissions of the containing log directory, using
+ * the log file permissions as a basis...
+ */
+
+ mode_t log_dir_perm = (mode_t)(0300 | LogFilePerm);
+ /* LogFilePerm + owner write/search */
+ if (log_dir_perm & 0040)
+ log_dir_perm |= 0010; /* Add group search */
+ if (log_dir_perm & 0004)
+ log_dir_perm |= 0001; /* Add other search */
+
+ cupsdCheckPermissions(CUPS_LOGDIR, NULL, log_dir_perm, RunUser, Group, 1, -1);
+
+ *lf = cupsFileOpen(filename, "a");
+ }
+
+ if (*lf == NULL)
+ {
+#ifdef HAVE_SYSTEMD_SD_JOURNAL_H
+ sd_journal_print(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
+#else
+ syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
+#endif /* HAVE_SYSTEMD_SD_JOURNAL_H */
+
+ if (FatalErrors & CUPSD_FATAL_LOG)
+ cupsdEndProcess(getpid(), 0);
+
+ return (0);
+ }
+ }
+
+ if (strncmp(filename, "/dev/", 5))
+ {
+ /*
+ * Change ownership and permissions of non-device logs...
+ */
+
+ fchown(cupsFileNumber(*lf), RunUser, Group);
+ fchmod(cupsFileNumber(*lf), LogFilePerm);
+ }
+ }
+
+ /*
+ * Do we need to rotate the log?
+ */
+
+ if (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize &&
+ MaxLogSize > 0)
+ {
+ /*
+ * Rotate log file...
+ */
+
+ cupsFileClose(*lf);
+
+ strlcpy(backname, filename, sizeof(backname));
+ strlcat(backname, ".O", sizeof(backname));
+
+ unlink(backname);
+ rename(filename, backname);
+
+ if ((*lf = cupsFileOpen(filename, "a")) == NULL)
+ {
+#ifdef HAVE_SYSTEMD_SD_JOURNAL_H
+ sd_journal_print(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
+
+#else
+ syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
+#endif /* HAVE_SYSTEMD_SD_JOURNAL_H */
+
+ if (FatalErrors & CUPSD_FATAL_LOG)
+ cupsdEndProcess(getpid(), 0);
+
+ return (0);
+ }
+
+ /*
+ * Change ownership and permissions of non-device logs...
+ */
+
+ fchown(cupsFileNumber(*lf), RunUser, Group);
+ fchmod(cupsFileNumber(*lf), LogFilePerm);
+ }
+
+ return (1);
+}
/*
*/
char * /* O - Date/time string */
-cupsdGetDateTime(time_t t) /* I - Time value */
+cupsdGetDateTime(struct timeval *t, /* I - Time value or NULL for current */
+ cupsd_time_t format) /* I - Format to use */
{
- struct tm *date; /* Date/time value */
- static time_t last_time = -1; /* Last time value */
- static char s[1024]; /* Date/time string */
+ struct timeval curtime; /* Current time value */
+ struct tm *date; /* Date/time value */
+ static struct timeval last_time = { 0, 0 };
+ /* Last time we formatted */
+ static char s[1024]; /* Date/time string */
static const char * const months[12] =/* Months */
{
"Jan",
*/
if (!t)
- t = time(NULL);
+ {
+ gettimeofday(&curtime, NULL);
+ t = &curtime;
+ }
- if (t != last_time)
+ if (t->tv_sec != last_time.tv_sec ||
+ (LogTimeFormat == CUPSD_TIME_USECS && t->tv_usec != last_time.tv_usec))
{
- last_time = t;
+ last_time = *t;
/*
* Get the date and time from the UNIX time value, and then format it
* (*BSD and Darwin store the timezone offset in the tm structure)
*/
- date = localtime(&t);
+ date = localtime(&(t->tv_sec));
- snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d %+03ld%02ld]",
- date->tm_mday, months[date->tm_mon], 1900 + date->tm_year,
- date->tm_hour, date->tm_min, date->tm_sec,
+ if (format == CUPSD_TIME_STANDARD)
+ snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d %+03ld%02ld]",
+ date->tm_mday, months[date->tm_mon], 1900 + date->tm_year,
+ date->tm_hour, date->tm_min, date->tm_sec,
#ifdef HAVE_TM_GMTOFF
- date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60);
+ date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60);
#else
- timezone / 3600, (timezone / 60) % 60);
+ timezone / 3600, (timezone / 60) % 60);
+#endif /* HAVE_TM_GMTOFF */
+ else
+ snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d.%06d %+03ld%02ld]",
+ date->tm_mday, months[date->tm_mon], 1900 + date->tm_year,
+ date->tm_hour, date->tm_min, date->tm_sec, (int)t->tv_usec,
+#ifdef HAVE_TM_GMTOFF
+ date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60);
+#else
+ timezone / 3600, (timezone / 60) % 60);
#endif /* HAVE_TM_GMTOFF */
}
}
+/*
+ * 'cupsdLogFCMessage()' - Log a file checking message.
+ */
+
+void
+cupsdLogFCMessage(
+ void *context, /* I - Printer (if any) */
+ _cups_fc_result_t result, /* I - Check result */
+ const char *message) /* I - Message to log */
+{
+ cupsd_printer_t *p = (cupsd_printer_t *)context;
+ /* Printer */
+ cupsd_loglevel_t level; /* Log level */
+
+
+ if (result == _CUPS_FILE_CHECK_OK)
+ level = CUPSD_LOG_DEBUG2;
+ else
+ level = CUPSD_LOG_ERROR;
+
+ if (p)
+ {
+ cupsdLogMessage(level, "%s: %s", p->name, message);
+
+ if (result == _CUPS_FILE_CHECK_MISSING ||
+ result == _CUPS_FILE_CHECK_WRONG_TYPE)
+ {
+ strlcpy(p->state_message, message, sizeof(p->state_message));
+
+ if (cupsdSetPrinterReasons(p, "+cups-missing-filter-warning"))
+ cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, p, NULL, "%s", message);
+ }
+ else if (result == _CUPS_FILE_CHECK_PERMISSIONS ||
+ result == _CUPS_FILE_CHECK_RELATIVE_PATH)
+ {
+ strlcpy(p->state_message, message, sizeof(p->state_message));
+
+ if (cupsdSetPrinterReasons(p, "+cups-insecure-filter-warning"))
+ cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, p, NULL, "%s", message);
+ }
+ }
+ else
+ cupsdLogMessage(level, "%s", message);
+}
+
+
#ifdef HAVE_GSSAPI
/*
* 'cupsdLogGSSMessage()' - Log a GSSAPI error...
int /* O - 1 on success, 0 on error */
cupsdLogGSSMessage(
int level, /* I - Log level */
- int major_status, /* I - Major GSSAPI status */
- int minor_status, /* I - Minor GSSAPI status */
+ OM_uint32 major_status, /* I - Major GSSAPI status */
+ OM_uint32 minor_status, /* I - Minor GSSAPI status */
const char *message, /* I - printf-style message string */
...) /* I - Additional args as needed */
{
minor_status_string = GSS_C_EMPTY_BUFFER;
/* Minor status message */
int ret; /* Return value */
+ char buffer[8192]; /* Buffer for vsnprintf */
+
+
+ if (strchr(message, '%'))
+ {
+ /*
+ * Format the message string...
+ */
+ va_list ap; /* Pointer to arguments */
+
+ va_start(ap, message);
+ vsnprintf(buffer, sizeof(buffer), message, ap);
+ va_end(ap);
+
+ message = buffer;
+ }
msg_ctx = 0;
err_major_status = gss_display_status(&err_minor_status,
&major_status_string);
if (!GSS_ERROR(err_major_status))
- err_major_status = gss_display_status(&err_minor_status,
- minor_status,
- GSS_C_MECH_CODE,
- GSS_C_NULL_OID,
- &msg_ctx,
- &minor_status_string);
+ gss_display_status(&err_minor_status, minor_status, GSS_C_MECH_CODE,
+ GSS_C_NULL_OID, &msg_ctx, &minor_status_string);
ret = cupsdLogMessage(level, "%s: %s, %s", message,
(char *)major_status_string.value,
#endif /* HAVE_GSSAPI */
+/*
+ * 'cupsdLogClient()' - Log a client message.
+ */
+
+int /* O - 1 on success, 0 on error */
+cupsdLogClient(cupsd_client_t *con, /* I - Client connection */
+ int level, /* I - Log level */
+ const char *message, /* I - Printf-style message string */
+ ...) /* I - Additional arguments as needed */
+{
+ va_list ap, ap2; /* Argument pointers */
+ char clientmsg[1024];/* Format string for client message */
+ int status; /* Formatting status */
+
+
+ /*
+ * See if we want to log this message...
+ */
+
+ if (TestConfigFile || !ErrorLog)
+ return (1);
+
+ if (level > LogLevel)
+ return (1);
+
+ /*
+ * Format and write the log message...
+ */
+
+ if (con)
+ snprintf(clientmsg, sizeof(clientmsg), "[Client %d] %s", con->number,
+ message);
+ else
+ strlcpy(clientmsg, message, sizeof(clientmsg));
+
+ va_start(ap, message);
+
+ do
+ {
+ va_copy(ap2, ap);
+ status = format_log_line(clientmsg, ap2);
+ va_end(ap2);
+ }
+ while (status == 0);
+
+ va_end(ap);
+
+ if (status > 0)
+ return (cupsdWriteErrorLog(level, log_line));
+ else
+ return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
+ "Unable to allocate memory for log line."));
+}
+
+
/*
* 'cupsdLogJob()' - Log a job message.
*/
const char *message, /* I - Printf-style message string */
...) /* I - Additional arguments as needed */
{
- va_list ap; /* Argument pointer */
- char jobmsg[1024], /* Format string for job message */
- *line; /* Message line */
+ va_list ap, ap2; /* Argument pointers */
+ char jobmsg[1024]; /* Format string for job message */
+ int status; /* Formatting status */
+
+
+ /*
+ * See if we want to log this message...
+ */
+
+ if (TestConfigFile || !ErrorLog)
+ return (1);
+
+ if (level > LogLevel && LogDebugHistory <= 0)
+ return (1);
+
+#ifdef HAVE_SYSTEMD_SD_JOURNAL_H
+ if (!strcmp(ErrorLog, "syslog"))
+ {
+ cupsd_printer_t *printer = job ? (job->printer ? job->printer : (job->dest ? cupsdFindDest(job->dest) : NULL)) : NULL;
+ static const char * const job_states[] =
+ { /* job-state strings */
+ "Pending",
+ "PendingHeld",
+ "Processing",
+ "ProcessingStopped",
+ "Canceled",
+ "Aborted",
+ "Completed"
+ };
+
+ va_start(ap, message);
+
+ do
+ {
+ va_copy(ap2, ap);
+ status = format_log_line(message, ap2);
+ va_end(ap2);
+ }
+ while (status == 0);
+
+ va_end(ap);
+
+ if (job)
+ sd_journal_send("MESSAGE=%s", log_line,
+ "PRIORITY=%i", log_levels[level],
+ PWG_Event"=JobStateChanged",
+ PWG_ServiceURI"=%s", printer ? printer->uri : "",
+ PWG_JobID"=%d", job->id,
+ PWG_JobState"=%s", job->state_value < IPP_JSTATE_PENDING ? "" : job_states[job->state_value - IPP_JSTATE_PENDING],
+ PWG_JobImpressionsCompleted"=%d", ippGetInteger(job->impressions, 0),
+ NULL);
+ else
+ sd_journal_send("MESSAGE=%s", log_line,
+ "PRIORITY=%i", log_levels[level],
+ NULL);
+ return (1);
+ }
+#endif /* HAVE_SYSTEMD_SD_JOURNAL_H */
+
+ /*
+ * Format and write the log message...
+ */
+
+ if (job)
+ snprintf(jobmsg, sizeof(jobmsg), "[Job %d] %s", job->id, message);
+ else
+ strlcpy(jobmsg, message, sizeof(jobmsg));
+
+ va_start(ap, message);
+
+ do
+ {
+ va_copy(ap2, ap);
+ status = format_log_line(jobmsg, ap2);
+ va_end(ap2);
+ }
+ while (status == 0);
+
+ va_end(ap);
+
+ if (status > 0)
+ {
+ if (job && level > LogLevel && LogDebugHistory > 0)
+ {
+ /*
+ * Add message to the job history...
+ */
- /*
- * See if we want to log this message...
- */
+ cupsd_joblog_t *temp; /* Copy of log message */
+ size_t log_len = strlen(log_line);
+ /* Length of log message */
- if (TestConfigFile || level > LogLevel || !ErrorLog)
- return (1);
+ if ((temp = malloc(sizeof(cupsd_joblog_t) + log_len)) != NULL)
+ {
+ temp->time = time(NULL);
+ memcpy(temp->message, log_line, log_len + 1);
+ }
- if (level > LogLevel || !ErrorLog)
- return (1);
+ if (!job->history)
+ job->history = cupsArrayNew(NULL, NULL);
- /*
- * Format and write the log message...
- */
+ if (job->history && temp)
+ {
+ cupsArrayAdd(job->history, temp);
- snprintf(jobmsg, sizeof(jobmsg), "[Job %d] %s", job->id, message);
+ if (cupsArrayCount(job->history) > LogDebugHistory)
+ {
+ /*
+ * Remove excess messages...
+ */
- va_start(ap, message);
- line = format_log_line(jobmsg, ap);
- va_end(ap);
+ temp = cupsArrayFirst(job->history);
+ cupsArrayRemove(job->history, temp);
+ free(temp);
+ }
+ }
+ else if (temp)
+ free(temp);
- if (line)
- return (cupsdWriteErrorLog(level, line));
+ return (1);
+ }
+ else if (level <= LogLevel)
+ return (cupsdWriteErrorLog(level, log_line));
+ else
+ return (1);
+ }
else
return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
- "Unable to allocate memory for log line!"));
+ "Unable to allocate memory for log line."));
}
const char *message, /* I - printf-style message string */
...) /* I - Additional args as needed */
{
- va_list ap; /* Argument pointer */
- char *line; /* Message line */
+ va_list ap, ap2; /* Argument pointers */
+ int status; /* Formatting status */
/*
* See if we want to log this message...
*/
- if (TestConfigFile)
+ if (TestConfigFile && level <= CUPSD_LOG_WARN)
{
- if (level <= CUPSD_LOG_WARN)
- {
- va_start(ap, message);
- vfprintf(stderr, message, ap);
- putc('\n', stderr);
- va_end(ap);
- }
+ va_start(ap, message);
+
+ vfprintf(stderr, message, ap);
+ putc('\n', stderr);
+
+ va_end(ap);
+
+ return (1);
+ }
+ else if (!ErrorLog && level <= CUPSD_LOG_WARN)
+ {
+ va_start(ap, message);
+
+#ifdef HAVE_SYSTEMD_SD_JOURNAL_H
+ sd_journal_printv(log_levels[level], message, ap);
+
+#elif defined(HAVE_VSYSLOG)
+ vsyslog(LOG_LPR | log_levels[level], message, ap);
+
+#else
+ vfprintf(stderr, message, ap);
+ putc('\n', stderr);
+#endif /* HAVE_SYSTEMD_SD_JOURNAL_H */
+
+ va_end(ap);
return (1);
}
+ else if (level > LogLevel || !ErrorLog)
+ return (1);
- if (level > LogLevel || !ErrorLog)
+#ifdef HAVE_SYSTEMD_SD_JOURNAL_H
+ else if (!strcmp(ErrorLog, "syslog"))
+ {
+ va_start(ap, message);
+ sd_journal_printv(log_levels[level], message, ap);
+ va_end(ap);
return (1);
+ }
+#endif /* HAVE_SYSTEMD_SD_JOURNAL_H */
/*
* Format and write the log message...
*/
va_start(ap, message);
- line = format_log_line(message, ap);
+
+ do
+ {
+ va_copy(ap2, ap);
+ status = format_log_line(message, ap2);
+ va_end(ap2);
+ }
+ while (status == 0);
+
va_end(ap);
- if (line)
- return (cupsdWriteErrorLog(level, line));
+ if (status > 0)
+ return (cupsdWriteErrorLog(level, log_line));
else
return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
"Unable to allocate memory for log line!"));
const char *format, /* Pointer into PageLogFormat */
*nameend; /* End of attribute name */
ipp_attribute_t *attr; /* Current attribute */
- int number; /* Page number */
- char copies[256]; /* Number of copies */
+ char number[256]; /* Page number */
+ int copies; /* Number of copies */
/*
if (!PageLogFormat)
return (1);
- number = 1;
- strcpy(copies, "1");
- sscanf(page, "%d%255s", &number, copies);
+ strlcpy(number, "1", sizeof(number));
+ copies = 1;
+ sscanf(page, "%255s%d", number, &copies);
for (format = PageLogFormat, bufptr = buffer; *format; format ++)
{
break;
case 'p' : /* Printer name */
- strlcpy(bufptr, job->printer->name,
- sizeof(buffer) - (bufptr - buffer));
+ strlcpy(bufptr, job->dest, sizeof(buffer) - (size_t)(bufptr - buffer));
bufptr += strlen(bufptr);
break;
case 'j' : /* Job ID */
- snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), "%d", job->id);
+ snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", job->id);
bufptr += strlen(bufptr);
break;
case 'u' : /* Username */
- strlcpy(bufptr, job->username ? job->username : "-",
- sizeof(buffer) - (bufptr - buffer));
+ strlcpy(bufptr, job->username ? job->username : "-", sizeof(buffer) - (size_t)(bufptr - buffer));
bufptr += strlen(bufptr);
break;
case 'T' : /* Date and time */
- strlcpy(bufptr, cupsdGetDateTime(time(NULL)),
- sizeof(buffer) - (bufptr - buffer));
+ strlcpy(bufptr, cupsdGetDateTime(NULL, LogTimeFormat), sizeof(buffer) - (size_t)(bufptr - buffer));
bufptr += strlen(bufptr);
break;
case 'P' : /* Page number */
- snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), "%d", number);
+ strlcpy(bufptr, number, sizeof(buffer) - (size_t)(bufptr - buffer));
bufptr += strlen(bufptr);
break;
case 'C' : /* Number of copies */
- strlcpy(bufptr, copies, sizeof(buffer) - (bufptr - buffer));
+ snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", copies);
bufptr += strlen(bufptr);
break;
case '{' : /* {attribute} */
- if ((nameend = strchr(format, '}')) != NULL &&
- (nameend - format - 2) < (sizeof(name) - 1))
+ if ((nameend = strchr(format, '}')) != NULL && (size_t)(nameend - format - 2) < (sizeof(name) - 1))
{
/*
* Pull the name from inside the brackets...
*/
- memcpy(name, format + 1, nameend - format - 1);
+ memcpy(name, format + 1, (size_t)(nameend - format - 1));
name[nameend - format - 1] = '\0';
format = nameend;
- if ((attr = ippFindAttribute(job->attrs, name,
- IPP_TAG_ZERO)) != NULL)
+ attr = ippFindAttribute(job->attrs, name, IPP_TAG_ZERO);
+ if (!attr && !strcmp(name, "job-billing"))
+ {
+ /*
+ * Handle alias "job-account-id" (which was standardized after
+ * "job-billing" was defined for CUPS...
+ */
+
+ attr = ippFindAttribute(job->attrs, "job-account-id", IPP_TAG_ZERO);
+ }
+ else if (!attr && !strcmp(name, "media"))
+ {
+ /*
+ * Handle alias "media-col" which uses dimensions instead of
+ * names...
+ */
+
+ attr = ippFindAttribute(job->attrs, "media-col/media-size", IPP_TAG_BEGIN_COLLECTION);
+ }
+
+ if (attr)
{
/*
* Add the attribute value...
{
case IPP_TAG_INTEGER :
case IPP_TAG_ENUM :
- snprintf(bufptr, sizeof(buffer) - (bufptr - buffer),
- "%d", attr->values[i].integer);
+ snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", attr->values[i].integer);
bufptr += strlen(bufptr);
break;
case IPP_TAG_BOOLEAN :
- snprintf(bufptr, sizeof(buffer) - (bufptr - buffer),
- "%d", attr->values[i].boolean);
+ snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", attr->values[i].boolean);
bufptr += strlen(bufptr);
break;
case IPP_TAG_CHARSET :
case IPP_TAG_LANGUAGE :
case IPP_TAG_MIMETYPE :
- strlcpy(bufptr, attr->values[i].string.text,
- sizeof(buffer) - (bufptr - buffer));
+ strlcpy(bufptr, attr->values[i].string.text, sizeof(buffer) - (size_t)(bufptr - buffer));
bufptr += strlen(bufptr);
break;
+ case IPP_TAG_BEGIN_COLLECTION :
+ if (!strcmp(attr->name, "media-size"))
+ {
+ ipp_attribute_t *x_dimension = ippFindAttribute(ippGetCollection(attr, 0), "x-dimension", IPP_TAG_INTEGER);
+ ipp_attribute_t *y_dimension = ippFindAttribute(ippGetCollection(attr, 0), "y-dimension", IPP_TAG_INTEGER);
+ /* Media dimensions */
+
+ if (x_dimension && y_dimension)
+ {
+ pwg_media_t *pwg = pwgMediaForSize(ippGetInteger(x_dimension, 0), ippGetInteger(y_dimension, 0));
+ /* PWG media name */
+ strlcpy(bufptr, pwg->pwg, sizeof(buffer) - (size_t)(bufptr - buffer));
+ break;
+ }
+ }
+
default :
- strlcpy(bufptr, "???",
- sizeof(buffer) - (bufptr - buffer));
+ strlcpy(bufptr, "???", sizeof(buffer) - (size_t)(bufptr - buffer));
bufptr += strlen(bufptr);
break;
}
}
*bufptr = '\0';
-
-#ifdef HAVE_VSYSLOG
+
+#ifdef HAVE_SYSTEMD_SD_JOURNAL_H
+ if (!strcmp(ErrorLog, "syslog"))
+ {
+ static const char * const job_states[] =
+ { /* job-state strings */
+ "Pending",
+ "PendingHeld",
+ "Processing",
+ "ProcessingStopped",
+ "Canceled",
+ "Aborted",
+ "Completed"
+ };
+
+ sd_journal_send("MESSAGE=%s", buffer,
+ "PRIORITY=%i", LOG_INFO,
+ PWG_Event"=JobStateChanged",
+ PWG_ServiceURI"=%s", job->printer->uri,
+ PWG_JobID"=%d", job->id,
+ PWG_JobState"=%s", job_states[job->state_value - IPP_JSTATE_PENDING],
+ PWG_JobImpressionsCompleted"=%d", ippGetInteger(job->impressions, 0),
+ NULL);
+ return (1);
+ }
+
+#elif defined(HAVE_VSYSLOG)
/*
* See if we are logging pages via syslog...
*/
return (1);
}
-#endif /* HAVE_VSYSLOG */
+#endif /* HAVE_SYSTEMD_SD_JOURNAL_H */
/*
* Not using syslog; check the log file...
*/
- if (!check_log_file(&PageFile, PageLog))
+ if (!cupsdCheckLogFile(&PageFile, PageLog))
return (0);
/*
};
-#ifdef HAVE_VSYSLOG
+ /*
+ * Filter requests as needed...
+ */
+
+ if (AccessLogLevel == CUPSD_ACCESSLOG_NONE)
+ return (1);
+ else if (AccessLogLevel < CUPSD_ACCESSLOG_ALL)
+ {
+ /*
+ * Eliminate simple GET, POST, and PUT requests...
+ */
+
+ if ((con->operation == HTTP_GET &&
+ strncmp(con->uri, "/admin/conf", 11) &&
+ strncmp(con->uri, "/admin/log", 10)) ||
+ (con->operation == HTTP_POST && !con->request &&
+ strncmp(con->uri, "/admin", 6)) ||
+ (con->operation != HTTP_GET && con->operation != HTTP_POST &&
+ con->operation != HTTP_PUT))
+ return (1);
+
+ if (con->request && con->response &&
+ (con->response->request.status.status_code < IPP_REDIRECTION_OTHER_SITE ||
+ con->response->request.status.status_code == IPP_NOT_FOUND))
+ {
+ /*
+ * Check successful requests...
+ */
+
+ ipp_op_t op = con->request->request.op.operation_id;
+ static cupsd_accesslog_t standard_ops[] =
+ {
+ CUPSD_ACCESSLOG_ALL, /* reserved */
+ CUPSD_ACCESSLOG_ALL, /* reserved */
+ CUPSD_ACCESSLOG_ACTIONS,/* Print-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Print-URI */
+ CUPSD_ACCESSLOG_ACTIONS,/* Validate-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Create-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Send-Document */
+ CUPSD_ACCESSLOG_ACTIONS,/* Send-URI */
+ CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Job */
+ CUPSD_ACCESSLOG_ALL, /* Get-Job-Attributes */
+ CUPSD_ACCESSLOG_ALL, /* Get-Jobs */
+ CUPSD_ACCESSLOG_ALL, /* Get-Printer-Attributes */
+ CUPSD_ACCESSLOG_ACTIONS,/* Hold-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Release-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Restart-Job */
+ CUPSD_ACCESSLOG_ALL, /* reserved */
+ CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* Resume-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* Purge-Jobs */
+ CUPSD_ACCESSLOG_CONFIG, /* Set-Printer-Attributes */
+ CUPSD_ACCESSLOG_ACTIONS,/* Set-Job-Attributes */
+ CUPSD_ACCESSLOG_CONFIG, /* Get-Printer-Supported-Values */
+ CUPSD_ACCESSLOG_ACTIONS,/* Create-Printer-Subscription */
+ CUPSD_ACCESSLOG_ACTIONS,/* Create-Job-Subscription */
+ CUPSD_ACCESSLOG_ALL, /* Get-Subscription-Attributes */
+ CUPSD_ACCESSLOG_ALL, /* Get-Subscriptions */
+ CUPSD_ACCESSLOG_ACTIONS,/* Renew-Subscription */
+ CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Subscription */
+ CUPSD_ACCESSLOG_ALL, /* Get-Notifications */
+ CUPSD_ACCESSLOG_ACTIONS,/* Send-Notifications */
+ CUPSD_ACCESSLOG_ALL, /* reserved */
+ CUPSD_ACCESSLOG_ALL, /* reserved */
+ CUPSD_ACCESSLOG_ALL, /* reserved */
+ CUPSD_ACCESSLOG_ALL, /* Get-Print-Support-Files */
+ CUPSD_ACCESSLOG_CONFIG, /* Enable-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* Disable-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer-After-Current-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Hold-New-Jobs */
+ CUPSD_ACCESSLOG_ACTIONS,/* Release-Held-New-Jobs */
+ CUPSD_ACCESSLOG_CONFIG, /* Deactivate-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* Activate-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* Restart-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* Shutdown-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* Startup-Printer */
+ CUPSD_ACCESSLOG_ACTIONS,/* Reprocess-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Current-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Suspend-Current-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Resume-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* Promote-Job */
+ CUPSD_ACCESSLOG_ACTIONS /* Schedule-Job-After */
+ };
+ static cupsd_accesslog_t cups_ops[] =
+ {
+ CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Default */
+ CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Printers */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Printer */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Printer */
+ CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Classes */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Class */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Class */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Accept-Jobs */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Reject-Jobs */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Set-Default */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-Devices */
+ CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-PPDs */
+ CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Move-Job */
+ CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Authenticate-Job */
+ CUPSD_ACCESSLOG_ALL /* CUPS-Get-PPD */
+ };
+
+
+ if ((op <= IPP_SCHEDULE_JOB_AFTER && standard_ops[op] > AccessLogLevel) ||
+ (op >= CUPS_GET_DEFAULT && op <= CUPS_GET_PPD &&
+ cups_ops[op - CUPS_GET_DEFAULT] > AccessLogLevel))
+ return (1);
+ }
+ }
+
+#ifdef HAVE_SYSTEMD_SD_JOURNAL_H
+ if (!strcmp(ErrorLog, "syslog"))
+ {
+ 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) : "-");
+ return (1);
+ }
+
+#elif defined(HAVE_VSYSLOG)
/*
* See if we are logging accesses via syslog...
*/
{
syslog(LOG_INFO,
"REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
- con->http.hostname, con->username[0] != '\0' ? con->username : "-",
+ 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,
+ con->http->version / 100, con->http->version % 100,
code, CUPS_LLCAST con->bytes,
con->request ?
ippOpString(con->request->request.op.operation_id) : "-",
return (1);
}
-#endif /* HAVE_VSYSLOG */
+#endif /* HAVE_SYSTEMD_SD_JOURNAL_H */
/*
* Not using syslog; check the log file...
*/
- if (!check_log_file(&AccessFile, AccessLog))
+ if (!cupsdCheckLogFile(&AccessFile, AccessLog))
return (0);
/*
cupsFilePrintf(AccessFile,
"%s - %s %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
- con->http.hostname, con->username[0] != '\0' ? con->username : "-",
- cupsdGetDateTime(con->start), states[con->operation],
+ con->http->hostname,
+ con->username[0] != '\0' ? con->username : "-",
+ cupsdGetDateTime(&(con->start), LogTimeFormat),
+ states[con->operation],
_httpEncodeURI(temp, con->uri, sizeof(temp)),
- con->http.version / 100, con->http.version % 100,
+ con->http->version / 100, con->http->version % 100,
code, CUPS_LLCAST con->bytes,
con->request ?
ippOpString(con->request->request.op.operation_id) : "-",
cupsdWriteErrorLog(int level, /* I - Log level */
const char *message) /* I - Message string */
{
+ int ret = 1; /* Return value */
static const char levels[] = /* Log levels... */
{
' ',
'D',
'd'
};
-#ifdef HAVE_VSYSLOG
- static const int syslevels[] = /* SYSLOG levels... */
- {
- 0,
- LOG_EMERG,
- LOG_ALERT,
- LOG_CRIT,
- LOG_ERR,
- LOG_WARNING,
- LOG_NOTICE,
- LOG_INFO,
- LOG_DEBUG,
- LOG_DEBUG
- };
-#endif /* HAVE_VSYSLOG */
-#ifdef HAVE_VSYSLOG
+#ifdef HAVE_SYSTEMD_SD_JOURNAL_H
+ if (!strcmp(ErrorLog, "syslog"))
+ {
+ sd_journal_print(log_levels[level], "%s", message);
+ return (1);
+ }
+
+#elif defined(HAVE_VSYSLOG)
/*
* See if we are logging errors via syslog...
*/
if (!strcmp(ErrorLog, "syslog"))
{
- syslog(syslevels[level], "%s", message);
+ syslog(log_levels[level], "%s", message);
return (1);
}
-#endif /* HAVE_VSYSLOG */
+#endif /* HAVE_SYSTEMD_SD_JOURNAL_H */
/*
* Not using syslog; check the log file...
*/
- if (!check_log_file(&ErrorFile, ErrorLog))
- return (0);
-
- /*
- * Write the log message...
- */
-
- cupsFilePrintf(ErrorFile, "%c %s %s\n", levels[level],
- cupsdGetDateTime(time(NULL)), message);
- cupsFileFlush(ErrorFile);
-
- return (1);
-}
-
-
-/*
- * 'check_log_file()' - Open/rotate a log file if it needs it.
- */
-
-static int /* O - 1 if log file open */
-check_log_file(cups_file_t **lf, /* IO - Log file */
- const char *logname) /* I - Log filename */
-{
- char backname[1024], /* Backup log filename */
- filename[1024], /* Formatted log filename */
- *ptr; /* Pointer into filename */
- const char *logptr; /* Pointer into log filename */
-
-
- /*
- * See if we have a log file to check...
- */
-
- if (!lf || !logname || !logname[0])
- return (1);
-
- /*
- * Format the filename as needed...
- */
+ _cupsMutexLock(&log_mutex);
- if (!*lf ||
- (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize &&
- MaxLogSize > 0))
+ if (!cupsdCheckLogFile(&ErrorFile, ErrorLog))
{
- /*
- * Handle format strings...
- */
-
- filename[sizeof(filename) - 1] = '\0';
-
- if (logname[0] != '/')
- {
- strlcpy(filename, ServerRoot, sizeof(filename));
- strlcat(filename, "/", sizeof(filename));
- }
- else
- filename[0] = '\0';
-
- for (logptr = logname, ptr = filename + strlen(filename);
- *logptr && ptr < (filename + sizeof(filename) - 1);
- logptr ++)
- if (*logptr == '%')
- {
- /*
- * Format spec...
- */
-
- logptr ++;
- if (*logptr == 's')
- {
- /*
- * Insert the server name...
- */
-
- strlcpy(ptr, ServerName, sizeof(filename) - (ptr - filename));
- ptr += strlen(ptr);
- }
- else
- {
- /*
- * Otherwise just insert the character...
- */
-
- *ptr++ = *logptr;
- }
- }
- else
- *ptr++ = *logptr;
-
- *ptr = '\0';
+ ret = 0;
}
-
- /*
- * See if the log file is open...
- */
-
- if (!*lf)
+ else
{
/*
- * Nope, open the log file...
+ * Write the log message...
*/
- if ((*lf = cupsFileOpen(filename, "a")) == NULL)
- {
- /*
- * If the file is in CUPS_LOGDIR then try to create a missing directory...
- */
-
- if (!strncmp(filename, CUPS_LOGDIR, strlen(CUPS_LOGDIR)))
- {
- cupsdCheckPermissions(CUPS_LOGDIR, NULL, 0755, RunUser, Group, 1, -1);
-
- *lf = cupsFileOpen(filename, "a");
- }
-
- if (*lf == NULL)
- {
- syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename,
- strerror(errno));
- return (0);
- }
- }
-
- if (strncmp(filename, "/dev/", 5))
- {
- /*
- * Change ownership and permissions of non-device logs...
- */
-
- fchown(cupsFileNumber(*lf), RunUser, Group);
- fchmod(cupsFileNumber(*lf), LogFilePerm);
- }
+ cupsFilePrintf(ErrorFile, "%c %s %s\n", levels[level],
+ cupsdGetDateTime(NULL, LogTimeFormat), message);
+ cupsFileFlush(ErrorFile);
}
- /*
- * Do we need to rotate the log?
- */
-
- if (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize &&
- MaxLogSize > 0)
- {
- /*
- * Rotate log file...
- */
-
- cupsFileClose(*lf);
-
- strcpy(backname, filename);
- strlcat(backname, ".O", sizeof(backname));
-
- unlink(backname);
- rename(filename, backname);
-
- if ((*lf = cupsFileOpen(filename, "a")) == NULL)
- {
- syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename,
- strerror(errno));
-
- return (0);
- }
-
- /*
- * Change ownership and permissions of non-device logs...
- */
-
- fchown(cupsFileNumber(*lf), RunUser, Group);
- fchmod(cupsFileNumber(*lf), LogFilePerm);
- }
+ _cupsMutexUnlock(&log_mutex);
- return (1);
+ return (ret);
}
* to format_log_line()...
*/
-static char * /* O - Text or NULL on error */
+static int /* O - -1 for fatal, 0 for retry, 1 for success */
format_log_line(const char *message, /* I - Printf-style format string */
va_list ap) /* I - Argument list */
{
- int len; /* Length of formatted line */
+ ssize_t len; /* Length of formatted line */
/*
log_line = malloc(log_linesize);
if (!log_line)
- return (NULL);
+ return (-1);
}
/*
* Format the log message...
*/
- len = vsnprintf(log_line, log_linesize, message, ap);
+ len = _cups_safe_vsnprintf(log_line, log_linesize, message, ap);
/*
* Resize the buffer as needed...
*/
- if (len >= log_linesize)
+ if ((size_t)len >= log_linesize && log_linesize < 65536)
{
char *temp; /* Temporary string pointer */
-
len ++;
if (len < 8192)
else if (len > 65536)
len = 65536;
- temp = realloc(log_line, len);
+ temp = realloc(log_line, (size_t)len);
if (temp)
{
log_line = temp;
- log_linesize = len;
- }
+ log_linesize = (size_t)len;
- len = vsnprintf(log_line, log_linesize, message, ap);
+ return (0);
+ }
}
- return (log_line);
+ return (1);
}
-
-
-/*
- * End of "$Id: log.c 7697 2008-06-27 15:56:00Z mike $".
- */