scheduler/log.c

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