scheduler/log.c

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