scheduler/log.c

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