]> git.ipfire.org Git - thirdparty/cups.git/blobdiff - scheduler/log.c
Merge changes from CUPS 1.4svn-r7696.
[thirdparty/cups.git] / scheduler / log.c
index 11c3cbcfe1a9d0134e369c115ff6b3520400a8df..fde21215e59f1e527e1e5f23a44fa12d2883a2fb 100644 (file)
@@ -1,34 +1,28 @@
 /*
- * "$Id: log.c 6328 2007-03-12 14:45:42Z mike $"
+ * "$Id: log.c 7697 2008-06-27 15:56:00Z mike $"
  *
  *   Log file routines for the Common UNIX Printing System (CUPS).
  *
- *   Copyright 1997-2006 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 Easy Software Products 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 missing or damaged please contact Easy Software Products
- *   at:
- *
- *       Attn: CUPS Licensing Information
- *       Easy Software Products
- *       44141 Airport View Drive, Suite 204
- *       Hollywood, Maryland 20636 USA
- *
- *       Voice: (301) 373-9600
- *       EMail: cups-info@cups.org
- *         WWW: http://www.cups.org
+ *   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.
  */
 
 /*
 #include <syslog.h>
 
 
+/*
+ * Local globals...
+ */
+
+static int     log_linesize = 0;       /* Size of line for output file */
+static char    *log_line = NULL;       /* Line for output file */
+
+
 /*
  * Local functions...
  */
 
-static int     check_log_file(cups_file_t **, const char *);
+static int     check_log_file(cups_file_t **lf, const char *logname);
+static char    *format_log_line(const char *message, va_list ap);
 
 
 /*
@@ -74,6 +77,13 @@ cupsdGetDateTime(time_t t)           /* I - Time value */
                };
 
 
+ /*
+  * Make sure we have a valid time...
+  */
+
+  if (!t)
+    t = time(NULL);
+
   if (t != last_time)
   {
     last_time = t;
@@ -159,166 +169,94 @@ cupsdLogGSSMessage(
 
 
 /*
- * 'cupsdLogMessage()' - Log a message to the error log file.
+ * 'cupsdLogJob()' - Log a job message.
  */
 
 int                                    /* O - 1 on success, 0 on error */
-cupsdLogMessage(int        level,      /* I - Log level */
-                const char *message,   /* I - printf-style message string */
-               ...)                    /* I - Additional args as needed */
+cupsdLogJob(cupsd_job_t *job,          /* I - Job */
+            int         level,         /* I - Log level */
+           const char  *message,       /* I - Printf-style message string */
+           ...)                        /* I - Additional arguments as needed */
 {
-  int                  len;            /* Length of message */
   va_list              ap;             /* Argument pointer */
-  static const char    levels[] =      /* Log levels... */
-               {
-                 ' ',
-                 'X',
-                 'A',
-                 'C',
-                 'E',
-                 'W',
-                 'N',
-                 'I',
-                 '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 */
-  static int   linesize = 0;           /* Size of line for output file */
-  static char  *line = NULL;           /* Line for output file */
+  char                 jobmsg[1024],   /* Format string for job message */
+                       *line;          /* Message line */
 
 
  /*
   * See if we want to log this message...
   */
 
-  if (level > LogLevel || !ErrorLog)
+  if (TestConfigFile || level > LogLevel || !ErrorLog)
     return (1);
 
-#ifdef HAVE_VSYSLOG
- /*
-  * See if we are logging errors via syslog...
-  */
-
-  if (!strcmp(ErrorLog, "syslog"))
-  {
-    va_start(ap, message);
-    vsyslog(syslevels[level], message, ap);
-    va_end(ap);
-
+  if (level > LogLevel || !ErrorLog)
     return (1);
-  }
-#endif /* HAVE_VSYSLOG */
-
- /*
-  * Not using syslog; check the log file...
-  */
-
-  if (!check_log_file(&ErrorFile, ErrorLog))
-    return (0);
 
  /*
-  * Print the log level and date/time...
+  * Format and write the log message...
   */
 
-  cupsFilePrintf(ErrorFile, "%c %s ", levels[level], cupsdGetDateTime(time(NULL)));
+  snprintf(jobmsg, sizeof(jobmsg), "[Job %d] %s", job->id, message);
 
- /*
-  * Allocate the line buffer as needed...
-  */
+  va_start(ap, message);
+  line = format_log_line(jobmsg, ap);
+  va_end(ap);
 
-  if (!linesize)
-  {
-    linesize = 8192;
-    line     = malloc(linesize);
+  if (line)
+    return (cupsdWriteErrorLog(level, line));
+  else
+    return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
+                               "Unable to allocate memory for log line!"));
+}
 
-    if (!line)
-    {
-      cupsFilePrintf(ErrorFile,
-                     "ERROR: Unable to allocate memory for line - %s\n",
-                     strerror(errno));
-      cupsFileFlush(ErrorFile);
 
-      return (0);
-    }
-  }
+/*
+ * 'cupsdLogMessage()' - Log a message to the error log file.
+ */
 
- /*
-  * Format the log message...
-  */
+int                                    /* O - 1 on success, 0 on error */
+cupsdLogMessage(int        level,      /* I - Log level */
+                const char *message,   /* I - printf-style message string */
+               ...)                    /* I - Additional args as needed */
+{
+  va_list              ap;             /* Argument pointer */
+  char                 *line;          /* Message line */
 
-  va_start(ap, message);
-  len = vsnprintf(line, linesize, message, ap);
-  va_end(ap);
 
  /*
-  * Resize the buffer as needed...
+  * See if we want to log this message...
   */
 
-  if (len >= linesize)
+  if (TestConfigFile)
   {
-    len ++;
-
-    if (len < 8192)
-      len = 8192;
-    else if (len > 65536)
-      len = 65536;
-
-    line = realloc(line, len);
-
-    if (line)
-      linesize = len;
-    else
+    if (level <= CUPSD_LOG_WARN)
     {
-      cupsFilePrintf(ErrorFile,
-                     "ERROR: Unable to allocate memory for line - %s\n",
-                     strerror(errno));
-      cupsFileFlush(ErrorFile);
-
-      return (0);
+      va_start(ap, message);
+      vfprintf(stderr, message, ap);
+      putc('\n', stderr);
+      va_end(ap);
     }
 
-    va_start(ap, message);
-    len = vsnprintf(line, linesize, message, ap);
-    va_end(ap);
+    return (1);
   }
 
-  if (len >= linesize)
-    len = linesize - 1;
-
- /*
-  * Then the log message...
-  */
-
-  cupsFilePuts(ErrorFile, line);
-
- /*
-  * Then a newline...
-  */
-
-  if (len > 0 && line[len - 1] != '\n')
-    cupsFilePutChar(ErrorFile, '\n');
+  if (level > LogLevel || !ErrorLog)
+    return (1);
 
  /*
-  * Flush the line to the file and return...
+  * Format and write the log message...
   */
 
-  cupsFileFlush(ErrorFile);
+  va_start(ap, message);
+  line = format_log_line(message, ap);
+  va_end(ap);
 
-  return (1);
+  if (line)
+    return (cupsdWriteErrorLog(level, line));
+  else
+    return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
+                               "Unable to allocate memory for log line!"));
 }
 
 
@@ -330,14 +268,160 @@ int                                      /* O - 1 on success, 0 on error */
 cupsdLogPage(cupsd_job_t *job,         /* I - Job being printed */
              const char  *page)                /* I - Page being printed */
 {
-  ipp_attribute_t *billing,            /* job-billing attribute */
-                  *hostname;           /* job-originating-host-name attribute */
+  int                  i;              /* Looping var */
+  char                 buffer[2048],   /* Buffer for page log */
+                       *bufptr,        /* Pointer into buffer */
+                       name[256];      /* Attribute name */
+  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 */
+
+
+ /*
+  * Format the line going into the page log...
+  */
+
+  if (!PageLogFormat)
+    return (1);
+
+  number = 1;
+  strcpy(copies, "1");
+  sscanf(page, "%d%255s", &number, copies);
 
+  for (format = PageLogFormat, bufptr = buffer; *format; format ++)
+  {
+    if (*format == '%')
+    {
+      format ++;
 
-  billing  = ippFindAttribute(job->attrs, "job-billing", IPP_TAG_ZERO);
-  hostname = ippFindAttribute(job->attrs, "job-originating-host-name",
-                              IPP_TAG_ZERO);
+      switch (*format)
+      {
+        case '%' :                     /* Literal % */
+           if (bufptr < (buffer + sizeof(buffer) - 1))
+             *bufptr++ = '%';
+           break;
+
+        case 'p' :                     /* Printer name */
+           strlcpy(bufptr, job->printer->name,
+                   sizeof(buffer) - (bufptr - buffer));
+           bufptr += strlen(bufptr);
+           break;
+
+        case 'j' :                     /* Job ID */
+           snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), "%d", job->id);
+           bufptr += strlen(bufptr);
+           break;
+
+        case 'u' :                     /* Username */
+           strlcpy(bufptr, job->username ? job->username : "-",
+                   sizeof(buffer) - (bufptr - buffer));
+           bufptr += strlen(bufptr);
+           break;
+
+        case 'T' :                     /* Date and time */
+           strlcpy(bufptr, cupsdGetDateTime(time(NULL)),
+                   sizeof(buffer) - (bufptr - buffer));
+           bufptr += strlen(bufptr);
+           break;
+
+        case 'P' :                     /* Page number */
+           snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), "%d", number);
+           bufptr += strlen(bufptr);
+           break;
+
+        case 'C' :                     /* Number of copies */
+           strlcpy(bufptr, copies, sizeof(buffer) - (bufptr - buffer));
+           bufptr += strlen(bufptr);
+           break;
+
+        case '{' :                     /* {attribute} */
+           if ((nameend = strchr(format, '}')) != NULL &&
+               (nameend - format - 2) < (sizeof(name) - 1))
+           {
+            /*
+             * Pull the name from inside the brackets...
+             */
+
+             memcpy(name, format + 1, nameend - format - 1);
+             name[nameend - format - 1] = '\0';
+
+             format = nameend;
+
+             if ((attr = ippFindAttribute(job->attrs, name,
+                                          IPP_TAG_ZERO)) != NULL)
+             {
+              /*
+               * Add the attribute value...
+               */
+
+                for (i = 0;
+                    i < attr->num_values &&
+                        bufptr < (buffer + sizeof(buffer) - 1);
+                    i ++)
+               {
+                 if (i)
+                   *bufptr++ = ',';
+
+                 switch (attr->value_tag)
+                 {
+                   case IPP_TAG_INTEGER :
+                   case IPP_TAG_ENUM :
+                       snprintf(bufptr, sizeof(buffer) - (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);
+                       bufptr += strlen(bufptr);
+                       break;
+
+                   case IPP_TAG_TEXTLANG :
+                   case IPP_TAG_NAMELANG :
+                   case IPP_TAG_TEXT :
+                   case IPP_TAG_NAME :
+                   case IPP_TAG_KEYWORD :
+                   case IPP_TAG_URI :
+                   case IPP_TAG_URISCHEME :
+                   case IPP_TAG_CHARSET :
+                   case IPP_TAG_LANGUAGE :
+                   case IPP_TAG_MIMETYPE :
+                       strlcpy(bufptr, attr->values[i].string.text,
+                               sizeof(buffer) - (bufptr - buffer));
+                       bufptr += strlen(bufptr);
+                       break;
+
+                   default :
+                       strlcpy(bufptr, "???",
+                               sizeof(buffer) - (bufptr - buffer));
+                       bufptr += strlen(bufptr);
+                       break;
+                 }
+               }
+             }
+             else if (bufptr < (buffer + sizeof(buffer) - 1))
+               *bufptr++ = '-';
+             break;
+           }
+
+        default :
+           if (bufptr < (buffer + sizeof(buffer) - 2))
+           {
+             *bufptr++ = '%';
+             *bufptr++ = *format;
+           }
+           break;
+      }
+    }
+    else if (bufptr < (buffer + sizeof(buffer) - 1))
+      *bufptr++ = *format;
+  }
 
+  *bufptr = '\0';
+      
 #ifdef HAVE_VSYSLOG
  /*
   * See if we are logging pages via syslog...
@@ -345,10 +429,7 @@ cupsdLogPage(cupsd_job_t *job,             /* I - Job being printed */
 
   if (!strcmp(PageLog, "syslog"))
   {
-    syslog(LOG_INFO, "PAGE %s %s %d %s %s %s", job->printer->name,
-           job->username ? job->username : "-",
-           job->id, page, billing ? billing->values[0].string.text : "-",
-           hostname->values[0].string.text);
+    syslog(LOG_INFO, "%s", buffer);
 
     return (1);
   }
@@ -364,15 +445,11 @@ cupsdLogPage(cupsd_job_t *job,            /* I - Job being printed */
  /*
   * Print a page log entry of the form:
   *
-  *    printer job-id user [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \
+  *    printer user job-id [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \
   *        billing hostname
   */
 
-  cupsFilePrintf(PageFile, "%s %s %d %s %s %s %s\n", job->printer->name,
-                job->username ? job->username : "-",
-                job->id, cupsdGetDateTime(time(NULL)), page,
-                billing ? billing->values[0].string.text : "-",
-                hostname->values[0].string.text);
+  cupsFilePrintf(PageFile, "%s\n", buffer);
   cupsFileFlush(PageFile);
 
   return (1);
@@ -387,6 +464,7 @@ int                                 /* O - 1 on success, 0 on error */
 cupsdLogRequest(cupsd_client_t *con,   /* I - Request to log */
                 http_status_t  code)   /* I - Response code */
 {
+  char temp[2048];                     /* Temporary string for URI */
   static const char * const states[] = /* HTTP client states... */
                {
                  "WAITING",
@@ -416,7 +494,7 @@ 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 : "-",
-          states[con->operation], con->uri,
+          states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)),
           con->http.version / 100, con->http.version % 100,
           code, CUPS_LLCAST con->bytes,
           con->request ?
@@ -442,7 +520,8 @@ 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 : "-",
-                cupsdGetDateTime(con->start), states[con->operation], con->uri,
+                cupsdGetDateTime(con->start), states[con->operation],
+                _httpEncodeURI(temp, con->uri, sizeof(temp)),
                 con->http.version / 100, con->http.version % 100,
                 code, CUPS_LLCAST con->bytes,
                 con->request ?
@@ -457,6 +536,75 @@ cupsdLogRequest(cupsd_client_t *con,       /* I - Request to log */
 }
 
 
+/*
+ * 'cupsdWriteErrorLog()' - Write a line to the ErrorLog.
+ */
+
+int                                    /* O - 1 on success, 0 on failure */
+cupsdWriteErrorLog(int        level,   /* I - Log level */
+                   const char *message)        /* I - Message string */
+{
+  static const char    levels[] =      /* Log levels... */
+               {
+                 ' ',
+                 'X',
+                 'A',
+                 'C',
+                 'E',
+                 'W',
+                 'N',
+                 'I',
+                 '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...
+  */
+
+  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(time(NULL)), message);
+  cupsFileFlush(ErrorFile);
+
+  return (1);
+}
+
+
 /*
  * 'check_log_file()' - Open/rotate a log file if it needs it.
  */
@@ -546,10 +694,23 @@ check_log_file(cups_file_t **lf,  /* IO - Log file */
 
     if ((*lf = cupsFileOpen(filename, "a")) == NULL)
     {
-      syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename,
-             strerror(errno));
+     /*
+      * If the file is in CUPS_LOGDIR then try to create a missing directory...
+      */
 
-      return (0);
+      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))
@@ -603,5 +764,70 @@ check_log_file(cups_file_t **lf,   /* IO - Log file */
 
 
 /*
- * End of "$Id: log.c 6328 2007-03-12 14:45:42Z mike $".
+ * 'format_log_line()' - Format a line for a log file.
+ *
+ * This function resizes a global string buffer as needed.  Each call returns
+ * a pointer to this buffer, so the contents are only good until the next call
+ * to format_log_line()...
+ */
+
+static char *                          /* O - Text or NULL on error */
+format_log_line(const char *message,   /* I - Printf-style format string */
+                va_list    ap)         /* I - Argument list */
+{
+  int  len;                            /* Length of formatted line */
+
+
+ /*
+  * Allocate the line buffer as needed...
+  */
+
+  if (!log_linesize)
+  {
+    log_linesize = 8192;
+    log_line     = malloc(log_linesize);
+
+    if (!log_line)
+      return (NULL);
+  }
+
+ /*
+  * Format the log message...
+  */
+
+  len = vsnprintf(log_line, log_linesize, message, ap);
+
+ /*
+  * Resize the buffer as needed...
+  */
+
+  if (len >= log_linesize)
+  {
+    char       *temp;                  /* Temporary string pointer */
+
+
+    len ++;
+
+    if (len < 8192)
+      len = 8192;
+    else if (len > 65536)
+      len = 65536;
+
+    temp = realloc(log_line, len);
+
+    if (temp)
+    {
+      log_line     = temp;
+      log_linesize = len;
+    }
+
+    len = vsnprintf(log_line, log_linesize, message, ap);
+  }
+
+  return (log_line);
+}
+
+
+/*
+ * End of "$Id: log.c 7697 2008-06-27 15:56:00Z mike $".
  */