X-Git-Url: http://git.ipfire.org/?a=blobdiff_plain;f=scheduler%2Flog.c;h=e606905296b84dc22784b7ea589d7936cb5ad788;hb=6922317779b71588d42494cd2393b2e64c0f1bec;hp=a6ac179aa680389490429fd16ebe4035612754f7;hpb=e07d4801f9846b9155d4c63872f51b18d8537d01;p=thirdparty%2Fcups.git diff --git a/scheduler/log.c b/scheduler/log.c index a6ac179aa..e60690529 100644 --- a/scheduler/log.c +++ b/scheduler/log.c @@ -1,28 +1,16 @@ /* - * "$Id: log.c 7918 2008-09-08 22:03:01Z mike $" + * "$Id$" * - * Log file routines for the Common UNIX Printing System (CUPS). + * Log file routines for the CUPS scheduler. * - * Copyright 2007-2009 by Apple Inc. - * Copyright 1997-2007 by Easy Software Products, all rights reserved. + * Copyright 2007-2015 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. + * 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/". */ /* @@ -31,25 +19,301 @@ #include "cupsd.h" #include +#ifdef HAVE_ASL_H +# include +#elif defined(HAVE_SYSTEMD_SD_JOURNAL_H) +# define SD_JOURNAL_SUPPRESS_LOCATION +# include +#endif /* HAVE_ASL_H */ #include +/* + * 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 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_ASL_H + asl_object_t m; /* Log message */ + + m = asl_new(ASL_TYPE_MSG); + asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd"); + asl_log(NULL, m, ASL_LEVEL_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno)); + asl_release(m); + +#elif defined(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_ASL_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_ASL_H + asl_object_t m; /* Log message */ + + m = asl_new(ASL_TYPE_MSG); + asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd"); + asl_log(NULL, m, ASL_LEVEL_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno)); + asl_release(m); + +#elif defined(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_ASL_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); +} + + /* * 'cupsdGetDateTime()' - Returns a pointer to a date/time string. */ @@ -135,6 +399,52 @@ cupsdGetDateTime(struct timeval *t, /* I - Time value or NULL for current */ } +/* + * '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... @@ -143,8 +453,8 @@ cupsdGetDateTime(struct timeval *t, /* I - Time value or NULL for current */ 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 */ { @@ -156,7 +466,23 @@ cupsdLogGSSMessage( 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, @@ -181,6 +507,61 @@ cupsdLogGSSMessage( #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. */ @@ -191,7 +572,7 @@ cupsdLogJob(cupsd_job_t *job, /* I - Job */ const char *message, /* I - Printf-style message string */ ...) /* I - Additional arguments as needed */ { - va_list ap; /* Argument pointer */ + va_list ap, ap2; /* Argument pointers */ char jobmsg[1024]; /* Format string for job message */ int status; /* Formatting status */ @@ -203,29 +584,175 @@ cupsdLogJob(cupsd_job_t *job, /* I - Job */ if (TestConfigFile || !ErrorLog) return (1); - if (level > LogLevel || - (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) + if ((level > LogLevel || + (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) && + LogDebugHistory <= 0) + return (1); + +#ifdef HAVE_ASL_H + if (!strcmp(ErrorLog, "syslog")) + { + asl_object_t m; /* Log message */ + char job_id[32], /* job-id string */ + completed[32]; /* job-impressions-completed string */ + 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" + }; + + m = asl_new(ASL_TYPE_MSG); + asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd"); + if (printer) + asl_set(m, PWG_ServiceURI, printer->uri); + if (job) + { + snprintf(job_id, sizeof(job_id), "%d", job->id); + + asl_set(m, PWG_Event, "JobStateChanged"); + asl_set(m, PWG_JobID, job_id); + asl_set(m, PWG_JobState, job->state_value < IPP_JSTATE_PENDING ? "" : job_states[job->state_value - IPP_JSTATE_PENDING]); + + if (job->impressions) + { + snprintf(completed, sizeof(completed), "%d", ippGetInteger(job->impressions, 0)); + asl_set(m, PWG_JobImpressionsCompleted, completed); + } + } + + va_start(ap, message); + asl_vlog(NULL, m, log_levels[level], message, ap); + va_end(ap); + + asl_release(m); + return (1); + } + +#elif defined(HAVE_SYSTEMD_SD_JOURNAL_H) + if (!strcmp(ErrorLog, "syslog")) + { + cupsd_printer_t *printer = job->printer ? job->printer : job->dest ? cupsdFindDest(job->dest) : 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_ASL_H */ /* * Format and write the log message... */ - snprintf(jobmsg, sizeof(jobmsg), "[Job %d] %s", job->id, 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_start(ap, message); - status = format_log_line(jobmsg, ap); - va_end(ap); + va_copy(ap2, ap); + status = format_log_line(jobmsg, ap2); + va_end(ap2); } while (status == 0); + va_end(ap); + if (status > 0) - return (cupsdWriteErrorLog(level, log_line)); + { + if (job && + (level > LogLevel || + (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) && + LogDebugHistory > 0) + { + /* + * Add message to the job history... + */ + + cupsd_joblog_t *temp; /* Copy of log message */ + size_t log_len = strlen(log_line); + /* Length of log message */ + + if ((temp = malloc(sizeof(cupsd_joblog_t) + log_len)) != NULL) + { + temp->time = time(NULL); + memcpy(temp->message, log_line, log_len + 1); + } + + if (!job->history) + job->history = cupsArrayNew(NULL, NULL); + + if (job->history && temp) + { + cupsArrayAdd(job->history, temp); + + if (cupsArrayCount(job->history) > LogDebugHistory) + { + /* + * Remove excess messages... + */ + + temp = cupsArrayFirst(job->history); + cupsArrayRemove(job->history, temp); + free(temp); + } + } + else if (temp) + free(temp); + + return (1); + } + else if (level <= LogLevel && + (level != CUPSD_LOG_INFO || LogLevel >= CUPSD_LOG_DEBUG)) + 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.")); } @@ -238,7 +765,7 @@ cupsdLogMessage(int level, /* I - Log level */ const char *message, /* I - printf-style message string */ ...) /* I - Additional args as needed */ { - va_list ap; /* Argument pointer */ + va_list ap, ap2; /* Argument pointers */ int status; /* Formatting status */ @@ -246,34 +773,79 @@ cupsdLogMessage(int level, /* I - Log level */ * See if we want to log this message... */ - if (TestConfigFile) + if ((TestConfigFile || !ErrorLog) && level <= CUPSD_LOG_WARN) + { + va_start(ap, message); + +#ifdef HAVE_ASL_H + asl_object_t m; /* Log message */ + + m = asl_new(ASL_TYPE_MSG); + asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd"); + asl_vlog(NULL, m, log_levels[level], message, ap); + asl_release(m); + +#elif defined(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_VSYSLOG */ + + va_end(ap); + + return (1); + } + + if (level > LogLevel || !ErrorLog) + return (1); + +#ifdef HAVE_ASL_H + if (!strcmp(ErrorLog, "syslog")) { - if (level <= CUPSD_LOG_WARN) - { - va_start(ap, message); - vfprintf(stderr, message, ap); - putc('\n', stderr); - va_end(ap); - } + asl_object_t m; /* Log message */ + + m = asl_new(ASL_TYPE_MSG); + asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd"); + + va_start(ap, message); + asl_vlog(NULL, m, log_levels[level], message, ap); + va_end(ap); + asl_release(m); return (1); } - if (level > LogLevel || !ErrorLog) +#elif defined(HAVE_SYSTEMD_SD_JOURNAL_H) + if (!strcmp(ErrorLog, "syslog")) + { + va_start(ap, message); + sd_journal_printv(log_levels[level], message, ap); + va_end(ap); return (1); + } +#endif /* HAVE_ASL_H */ /* * Format and write the log message... */ + va_start(ap, message); + do { - va_start(ap, message); - status = format_log_line(message, ap); - va_end(ap); + va_copy(ap2, ap); + status = format_log_line(message, ap2); + va_end(ap2); } while (status == 0); + va_end(ap); + if (status > 0) return (cupsdWriteErrorLog(level, log_line)); else @@ -297,8 +869,8 @@ cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ 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 */ /* @@ -308,9 +880,9 @@ cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ 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 ++) { @@ -326,53 +898,68 @@ cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ 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(NULL, LogTimeFormat), - 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... @@ -390,14 +977,12 @@ cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ { 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; @@ -411,14 +996,28 @@ cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ 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; } @@ -443,8 +1042,71 @@ cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ } *bufptr = '\0'; - -#ifdef HAVE_VSYSLOG + +#ifdef HAVE_ASL_H + if (!strcmp(ErrorLog, "syslog")) + { + asl_object_t m; /* Log message */ + char job_id[32], /* job-id string */ + completed[32]; /* job-impressions-completed string */ + static const char * const job_states[] = + { /* job-state strings */ + "Pending", + "PendingHeld", + "Processing", + "ProcessingStopped", + "Canceled", + "Aborted", + "Completed" + }; + + snprintf(job_id, sizeof(job_id), "%d", job->id); + + m = asl_new(ASL_TYPE_MSG); + asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd"); + asl_set(m, PWG_Event, "JobStateChanged"); + asl_set(m, PWG_ServiceURI, job->printer->uri); + asl_set(m, PWG_JobID, job_id); + asl_set(m, PWG_JobState, job_states[job->state_value - IPP_JSTATE_PENDING]); + + if (job->impressions) + { + snprintf(completed, sizeof(completed), "%d", ippGetInteger(job->impressions, 0)); + asl_set(m, PWG_JobImpressionsCompleted, completed); + } + + asl_log(NULL, m, ASL_LEVEL_INFO, "%s", buffer); + + asl_release(m); + return (1); + } + +#elif defined(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... */ @@ -455,13 +1117,13 @@ cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ return (1); } -#endif /* HAVE_VSYSLOG */ +#endif /* HAVE_ASL_H */ /* * Not using syslog; check the log file... */ - if (!check_log_file(&PageFile, PageLog)) + if (!cupsdCheckLogFile(&PageFile, PageLog)) return (0); /* @@ -510,10 +1172,12 @@ cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ * Filter requests as needed... */ - if (AccessLogLevel < CUPSD_ACCESSLOG_ALL) + if (AccessLogLevel == CUPSD_ACCESSLOG_NONE) + return (1); + else if (AccessLogLevel < CUPSD_ACCESSLOG_ALL) { /* - * Eliminate simple GET requests... + * Eliminate simple GET, POST, and PUT requests... */ if ((con->operation == HTTP_GET && @@ -521,7 +1185,8 @@ cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ strncmp(con->uri, "/admin/log", 10)) || (con->operation == HTTP_POST && !con->request && strncmp(con->uri, "/admin", 6)) || - (con->operation != HTTP_POST && con->operation != HTTP_PUT)) + (con->operation != HTTP_GET && con->operation != HTTP_POST && + con->operation != HTTP_PUT)) return (1); if (con->request && con->response && @@ -604,7 +1269,7 @@ cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ 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 && @@ -613,7 +1278,36 @@ cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ } } -#ifdef HAVE_VSYSLOG +#ifdef HAVE_ASL_H + if (!strcmp(ErrorLog, "syslog")) + { + asl_object_t m; /* Log message */ + + m = asl_new(ASL_TYPE_MSG); + asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd"); + + asl_log(NULL, m, ASL_LEVEL_INFO, "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n", + 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) : "-"); + + asl_release(m); + return (1); + } + +#elif defined(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... */ @@ -622,9 +1316,9 @@ cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ { 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) : "-", @@ -633,13 +1327,13 @@ cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ return (1); } -#endif /* HAVE_VSYSLOG */ +#endif /* HAVE_ASL_H */ /* * Not using syslog; check the log file... */ - if (!check_log_file(&AccessFile, AccessLog)) + if (!cupsdCheckLogFile(&AccessFile, AccessLog)) return (0); /* @@ -648,11 +1342,12 @@ cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ 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 : "-", + 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) : "-", @@ -674,6 +1369,7 @@ int /* O - 1 on success, 0 on failure */ cupsdWriteErrorLog(int level, /* I - Log level */ const char *message) /* I - Message string */ { + int ret = 1; /* Return value */ static const char levels[] = /* Log levels... */ { ' ', @@ -687,229 +1383,64 @@ cupsdWriteErrorLog(int level, /* I - Log level */ '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 - /* - * See if we are logging errors via syslog... - */ +#ifdef HAVE_ASL_H if (!strcmp(ErrorLog, "syslog")) { - syslog(syslevels[level], "%s", message); - return (1); - } -#endif /* HAVE_VSYSLOG */ - - /* - * 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(NULL, LogTimeFormat), 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 */ - + asl_object_t m; /* Log message */ - /* - * See if we have a log file to check... - */ + m = asl_new(ASL_TYPE_MSG); + asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd"); + asl_log(NULL, m, ASL_LEVEL_INFO, "%s", message); - if (!lf || !logname || !logname[0]) + asl_release(m); return (1); + } - /* - * Format the filename as needed... - */ - - if (!*lf || - (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize && - MaxLogSize > 0)) +#elif defined(HAVE_SYSTEMD_SD_JOURNAL_H) + if (!strcmp(ErrorLog, "syslog")) { - /* - * 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'; + sd_journal_print(log_levels[level], "%s", message); + return (1); } +#elif defined(HAVE_VSYSLOG) /* - * See if the log file is open... + * See if we are logging errors via syslog... */ - if (!*lf) + if (!strcmp(ErrorLog, "syslog")) { - /* - * 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... - */ - - int log_dir_perm = 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) - { - syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, - strerror(errno)); - - 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); - } + syslog(log_levels[level], "%s", message); + return (1); } +#endif /* HAVE_ASL_H */ /* - * Do we need to rotate the log? + * Not using syslog; check the log file... */ - 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)); - - if (FatalErrors & CUPSD_FATAL_LOG) - cupsdEndProcess(getpid(), 0); - - return (0); - } + _cupsMutexLock(&log_mutex); + if (!cupsdCheckLogFile(&ErrorFile, ErrorLog)) + { + ret = 0; + } + else + { /* - * Change ownership and permissions of non-device logs... + * Write the log message... */ - fchown(cupsFileNumber(*lf), RunUser, Group); - fchmod(cupsFileNumber(*lf), LogFilePerm); + cupsFilePrintf(ErrorFile, "%c %s %s\n", levels[level], + cupsdGetDateTime(NULL, LogTimeFormat), message); + cupsFileFlush(ErrorFile); } - return (1); + _cupsMutexUnlock(&log_mutex); + + return (ret); } @@ -925,7 +1456,7 @@ 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 */ /* @@ -951,7 +1482,7 @@ format_log_line(const char *message, /* I - Printf-style format string */ * Resize the buffer as needed... */ - if (len >= log_linesize && log_linesize < 65536) + if ((size_t)len >= log_linesize && log_linesize < 65536) { char *temp; /* Temporary string pointer */ @@ -963,12 +1494,12 @@ format_log_line(const char *message, /* I - Printf-style format string */ 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; return (0); } @@ -979,5 +1510,5 @@ format_log_line(const char *message, /* I - Printf-style format string */ /* - * End of "$Id: log.c 7918 2008-09-08 22:03:01Z mike $". + * End of "$Id$". */