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, (size_t)(nameend - format - 1));
 726               name[nameend - format - 1] = '\0';
 727
 728               format = nameend;
 729
 730               attr = ippFindAttribute(job->attrs, name, IPP_TAG_ZERO);
 731               if (!attr && !strcmp(name, "job-billing"))
 732               {
 733                /*
 734                 * Handle alias "job-account-id" (which was standardized after
 735                 * "job-billing" was defined for CUPS...
 736                 */
 737
 738                 attr = ippFindAttribute(job->attrs, "job-account-id", IPP_TAG_ZERO);
 739               }
 740               else if (!attr && !strcmp(name, "media"))
 741               {
 742                /*
 743                 * Handle alias "media-col" which uses dimensions instead of
 744                 * names...
 745                 */
 746
 747                 attr = ippFindAttribute(job->attrs, "media-col/media-size", IPP_TAG_BEGIN_COLLECTION);
 748               }
 749
 750               if (attr)
 751               {
 752                /*
 753                 * Add the attribute value...
 754                 */
 755
 756                 for (i = 0;
 757                      i < attr->num_values &&
 758                          bufptr < (buffer + sizeof(buffer) - 1);
 759                      i ++)
 760                 {
 761                   if (i)
 762                     *bufptr++ = ',';
 763
 764                   switch (attr->value_tag)
 765                   {
 766                     case IPP_TAG_INTEGER :
 767                     case IPP_TAG_ENUM :
 768                         snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", attr->values[i].integer);
 769                         bufptr += strlen(bufptr);
 770                         break;
 771
 772                     case IPP_TAG_BOOLEAN :
 773                         snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", attr->values[i].boolean);
 774                         bufptr += strlen(bufptr);
 775                         break;
 776
 777                     case IPP_TAG_TEXTLANG :
 778                     case IPP_TAG_NAMELANG :
 779                     case IPP_TAG_TEXT :
 780                     case IPP_TAG_NAME :
 781                     case IPP_TAG_KEYWORD :
 782                     case IPP_TAG_URI :
 783                     case IPP_TAG_URISCHEME :
 784                     case IPP_TAG_CHARSET :
 785                     case IPP_TAG_LANGUAGE :
 786                     case IPP_TAG_MIMETYPE :
 787                         strlcpy(bufptr, attr->values[i].string.text, sizeof(buffer) - (size_t)(bufptr - buffer));
 788                         bufptr += strlen(bufptr);
 789                         break;
 790
 791                     case IPP_TAG_BEGIN_COLLECTION :
 792                         if (!strcmp(attr->name, "media-size"))
 793                         {
 794                           ipp_attribute_t *x_dimension = ippFindAttribute(ippGetCollection(attr, 0), "x-dimension", IPP_TAG_INTEGER);
 795                           ipp_attribute_t *y_dimension = ippFindAttribute(ippGetCollection(attr, 0), "y-dimension", IPP_TAG_INTEGER);
 796                                         /* Media dimensions */
 797
 798                           if (x_dimension && y_dimension)
 799                           {
 800                             pwg_media_t *pwg = pwgMediaForSize(ippGetInteger(x_dimension, 0), ippGetInteger(y_dimension, 0));
 801                                         /* PWG media name */
 802                             strlcpy(bufptr, pwg->pwg, sizeof(buffer) - (size_t)(bufptr - buffer));
 803                             break;
 804                           }
 805                         }
 806
 807                     default :
 808                         strlcpy(bufptr, "???", sizeof(buffer) - (size_t)(bufptr - buffer));
 809                         bufptr += strlen(bufptr);
 810                         break;
 811                   }
 812                 }
 813               }
 814               else if (bufptr < (buffer + sizeof(buffer) - 1))
 815                 *bufptr++ = '-';
 816               break;
 817             }
 818
 819         default :
 820             if (bufptr < (buffer + sizeof(buffer) - 2))
 821             {
 822               *bufptr++ = '%';
 823               *bufptr++ = *format;
 824             }
 825             break;
 826       }
 827     }
 828     else if (bufptr < (buffer + sizeof(buffer) - 1))
 829       *bufptr++ = *format;
 830   }
 831
 832   *bufptr = '\0';
 833
 834 #ifdef HAVE_VSYSLOG
 835  /*
 836   * See if we are logging pages via syslog...
 837   */
 838
 839   if (!strcmp(PageLog, "syslog"))
 840   {
 841     syslog(LOG_INFO, "%s", buffer);
 842
 843     return (1);
 844   }
 845 #endif /* HAVE_VSYSLOG */
 846
 847  /*
 848   * Not using syslog; check the log file...
 849   */
 850
 851   if (!cupsdCheckLogFile(&PageFile, PageLog))
 852     return (0);
 853
 854  /*
 855   * Print a page log entry of the form:
 856   *
 857   *    printer user job-id [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \
 858   *        billing hostname
 859   */
 860
 861   cupsFilePrintf(PageFile, "%s\n", buffer);
 862   cupsFileFlush(PageFile);
 863
 864   return (1);
 865 }
 866
 867
 868 /*
 869  * 'cupsdLogRequest()' - Log an HTTP request in Common Log Format.
 870  */
 871
 872 int                                     /* O - 1 on success, 0 on error */
 873 cupsdLogRequest(cupsd_client_t *con,    /* I - Request to log */
 874                 http_status_t  code)    /* I - Response code */
 875 {
 876   char  temp[2048];                     /* Temporary string for URI */
 877   static const char * const states[] =  /* HTTP client states... */
 878                 {
 879                   "WAITING",
 880                   "OPTIONS",
 881                   "GET",
 882                   "GET",
 883                   "HEAD",
 884                   "POST",
 885                   "POST",
 886                   "POST",
 887                   "PUT",
 888                   "PUT",
 889                   "DELETE",
 890                   "TRACE",
 891                   "CLOSE",
 892                   "STATUS"
 893                 };
 894
 895
 896  /*
 897   * Filter requests as needed...
 898   */
 899
 900   if (AccessLogLevel == CUPSD_ACCESSLOG_NONE)
 901     return (1);
 902   else if (AccessLogLevel < CUPSD_ACCESSLOG_ALL)
 903   {
 904    /*
 905     * Eliminate simple GET, POST, and PUT requests...
 906     */
 907
 908     if ((con->operation == HTTP_GET &&
 909          strncmp(con->uri, "/admin/conf", 11) &&
 910          strncmp(con->uri, "/admin/log", 10)) ||
 911         (con->operation == HTTP_POST && !con->request &&
 912          strncmp(con->uri, "/admin", 6)) ||
 913         (con->operation != HTTP_GET && con->operation != HTTP_POST &&
 914          con->operation != HTTP_PUT))
 915       return (1);
 916
 917     if (con->request && con->response &&
 918         (con->response->request.status.status_code < IPP_REDIRECTION_OTHER_SITE ||
 919          con->response->request.status.status_code == IPP_NOT_FOUND))
 920     {
 921      /*
 922       * Check successful requests...
 923       */
 924
 925       ipp_op_t op = con->request->request.op.operation_id;
 926       static cupsd_accesslog_t standard_ops[] =
 927       {
 928         CUPSD_ACCESSLOG_ALL,    /* reserved */
 929         CUPSD_ACCESSLOG_ALL,    /* reserved */
 930         CUPSD_ACCESSLOG_ACTIONS,/* Print-Job */
 931         CUPSD_ACCESSLOG_ACTIONS,/* Print-URI */
 932         CUPSD_ACCESSLOG_ACTIONS,/* Validate-Job */
 933         CUPSD_ACCESSLOG_ACTIONS,/* Create-Job */
 934         CUPSD_ACCESSLOG_ACTIONS,/* Send-Document */
 935         CUPSD_ACCESSLOG_ACTIONS,/* Send-URI */
 936         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Job */
 937         CUPSD_ACCESSLOG_ALL,    /* Get-Job-Attributes */
 938         CUPSD_ACCESSLOG_ALL,    /* Get-Jobs */
 939         CUPSD_ACCESSLOG_ALL,    /* Get-Printer-Attributes */
 940         CUPSD_ACCESSLOG_ACTIONS,/* Hold-Job */
 941         CUPSD_ACCESSLOG_ACTIONS,/* Release-Job */
 942         CUPSD_ACCESSLOG_ACTIONS,/* Restart-Job */
 943         CUPSD_ACCESSLOG_ALL,    /* reserved */
 944         CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer */
 945         CUPSD_ACCESSLOG_CONFIG, /* Resume-Printer */
 946         CUPSD_ACCESSLOG_CONFIG, /* Purge-Jobs */
 947         CUPSD_ACCESSLOG_CONFIG, /* Set-Printer-Attributes */
 948         CUPSD_ACCESSLOG_ACTIONS,/* Set-Job-Attributes */
 949         CUPSD_ACCESSLOG_CONFIG, /* Get-Printer-Supported-Values */
 950         CUPSD_ACCESSLOG_ACTIONS,/* Create-Printer-Subscription */
 951         CUPSD_ACCESSLOG_ACTIONS,/* Create-Job-Subscription */
 952         CUPSD_ACCESSLOG_ALL,    /* Get-Subscription-Attributes */
 953         CUPSD_ACCESSLOG_ALL,    /* Get-Subscriptions */
 954         CUPSD_ACCESSLOG_ACTIONS,/* Renew-Subscription */
 955         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Subscription */
 956         CUPSD_ACCESSLOG_ALL,    /* Get-Notifications */
 957         CUPSD_ACCESSLOG_ACTIONS,/* Send-Notifications */
 958         CUPSD_ACCESSLOG_ALL,    /* reserved */
 959         CUPSD_ACCESSLOG_ALL,    /* reserved */
 960         CUPSD_ACCESSLOG_ALL,    /* reserved */
 961         CUPSD_ACCESSLOG_ALL,    /* Get-Print-Support-Files */
 962         CUPSD_ACCESSLOG_CONFIG, /* Enable-Printer */
 963         CUPSD_ACCESSLOG_CONFIG, /* Disable-Printer */
 964         CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer-After-Current-Job */
 965         CUPSD_ACCESSLOG_ACTIONS,/* Hold-New-Jobs */
 966         CUPSD_ACCESSLOG_ACTIONS,/* Release-Held-New-Jobs */
 967         CUPSD_ACCESSLOG_CONFIG, /* Deactivate-Printer */
 968         CUPSD_ACCESSLOG_CONFIG, /* Activate-Printer */
 969         CUPSD_ACCESSLOG_CONFIG, /* Restart-Printer */
 970         CUPSD_ACCESSLOG_CONFIG, /* Shutdown-Printer */
 971         CUPSD_ACCESSLOG_CONFIG, /* Startup-Printer */
 972         CUPSD_ACCESSLOG_ACTIONS,/* Reprocess-Job */
 973         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Current-Job */
 974         CUPSD_ACCESSLOG_ACTIONS,/* Suspend-Current-Job */
 975         CUPSD_ACCESSLOG_ACTIONS,/* Resume-Job */
 976         CUPSD_ACCESSLOG_ACTIONS,/* Promote-Job */
 977         CUPSD_ACCESSLOG_ACTIONS /* Schedule-Job-After */
 978       };
 979       static cupsd_accesslog_t cups_ops[] =
 980       {
 981         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Default */
 982         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Printers */
 983         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Printer */
 984         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Printer */
 985         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Classes */
 986         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Class */
 987         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Class */
 988         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Accept-Jobs */
 989         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Reject-Jobs */
 990         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Set-Default */
 991         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-Devices */
 992         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-PPDs */
 993         CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Move-Job */
 994         CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Authenticate-Job */
 995         CUPSD_ACCESSLOG_ALL     /* CUPS-Get-PPD */
 996       };
 997
 998
 999       if ((op <= IPP_SCHEDULE_JOB_AFTER && standard_ops[op] > AccessLogLevel) ||
1000           (op >= CUPS_GET_DEFAULT && op <= CUPS_GET_PPD &&
1001            cups_ops[op - CUPS_GET_DEFAULT] > AccessLogLevel))
1002         return (1);
1003     }
1004   }
1005
1006 #ifdef HAVE_VSYSLOG
1007  /*
1008   * See if we are logging accesses via syslog...
1009   */
1010
1011   if (!strcmp(AccessLog, "syslog"))
1012   {
1013     syslog(LOG_INFO,
1014            "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
1015            con->http->hostname, con->username[0] != '\0' ? con->username : "-",
1016            states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)),
1017            con->http->version / 100, con->http->version % 100,
1018            code, CUPS_LLCAST con->bytes,
1019            con->request ?
1020                ippOpString(con->request->request.op.operation_id) : "-",
1021            con->response ?
1022                ippErrorString(con->response->request.status.status_code) : "-");
1023
1024     return (1);
1025   }
1026 #endif /* HAVE_VSYSLOG */
1027
1028  /*
1029   * Not using syslog; check the log file...
1030   */
1031
1032   if (!cupsdCheckLogFile(&AccessFile, AccessLog))
1033     return (0);
1034
1035  /*
1036   * Write a log of the request in "common log format"...
1037   */
1038
1039   cupsFilePrintf(AccessFile,
1040                  "%s - %s %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
1041                  con->http->hostname,
1042                  con->username[0] != '\0' ? con->username : "-",
1043                  cupsdGetDateTime(&(con->start), LogTimeFormat),
1044                  states[con->operation],
1045                  _httpEncodeURI(temp, con->uri, sizeof(temp)),
1046                  con->http->version / 100, con->http->version % 100,
1047                  code, CUPS_LLCAST con->bytes,
1048                  con->request ?
1049                      ippOpString(con->request->request.op.operation_id) : "-",
1050                  con->response ?
1051                      ippErrorString(con->response->request.status.status_code) :
1052                      "-");
1053
1054   cupsFileFlush(AccessFile);
1055
1056   return (1);
1057 }
1058
1059
1060 /*
1061  * 'cupsdWriteErrorLog()' - Write a line to the ErrorLog.
1062  */
1063
1064 int                                     /* O - 1 on success, 0 on failure */
1065 cupsdWriteErrorLog(int        level,    /* I - Log level */
1066                    const char *message) /* I - Message string */
1067 {
1068   int           ret = 1;                /* Return value */
1069   static const char     levels[] =      /* Log levels... */
1070                 {
1071                   ' ',
1072                   'X',
1073                   'A',
1074                   'C',
1075                   'E',
1076                   'W',
1077                   'N',
1078                   'I',
1079                   'D',
1080                   'd'
1081                 };
1082
1083
1084 #ifdef HAVE_VSYSLOG
1085  /*
1086   * See if we are logging errors via syslog...
1087   */
1088
1089   if (!strcmp(ErrorLog, "syslog"))
1090   {
1091     syslog(syslevels[level], "%s", message);
1092     return (1);
1093   }
1094 #endif /* HAVE_VSYSLOG */
1095
1096  /*
1097   * Not using syslog; check the log file...
1098   */
1099
1100   _cupsMutexLock(&log_mutex);
1101
1102   if (!cupsdCheckLogFile(&ErrorFile, ErrorLog))
1103   {
1104     ret = 0;
1105   }
1106   else
1107   {
1108    /*
1109     * Write the log message...
1110     */
1111
1112     cupsFilePrintf(ErrorFile, "%c %s %s\n", levels[level],
1113                    cupsdGetDateTime(NULL, LogTimeFormat), message);
1114     cupsFileFlush(ErrorFile);
1115   }
1116
1117   _cupsMutexUnlock(&log_mutex);
1118
1119   return (ret);
1120 }
1121
1122
1123 /*
1124  * 'format_log_line()' - Format a line for a log file.
1125  *
1126  * This function resizes a global string buffer as needed.  Each call returns
1127  * a pointer to this buffer, so the contents are only good until the next call
1128  * to format_log_line()...
1129  */
1130
1131 static int                              /* O - -1 for fatal, 0 for retry, 1 for success */
1132 format_log_line(const char *message,    /* I - Printf-style format string */
1133                 va_list    ap)          /* I - Argument list */
1134 {
1135   ssize_t       len;                    /* Length of formatted line */
1136
1137
1138  /*
1139   * Allocate the line buffer as needed...
1140   */
1141
1142   if (!log_linesize)
1143   {
1144     log_linesize = 8192;
1145     log_line     = malloc(log_linesize);
1146
1147     if (!log_line)
1148       return (-1);
1149   }
1150
1151  /*
1152   * Format the log message...
1153   */
1154
1155   len = vsnprintf(log_line, log_linesize, message, ap);
1156
1157  /*
1158   * Resize the buffer as needed...
1159   */
1160
1161   if ((size_t)len >= log_linesize && log_linesize < 65536)
1162   {
1163     char        *temp;                  /* Temporary string pointer */
1164
1165
1166     len ++;
1167
1168     if (len < 8192)
1169       len = 8192;
1170     else if (len > 65536)
1171       len = 65536;
1172
1173     temp = realloc(log_line, (size_t)len);
1174
1175     if (temp)
1176     {
1177       log_line     = temp;
1178       log_linesize = (size_t)len;
1179
1180       return (0);
1181     }
1182   }
1183
1184   return (1);
1185 }
1186
1187
1188 /*
1189  * End of "$Id$".
1190  */