scheduler/log.c

   1 /*
   2  * Log file routines for the CUPS scheduler.
   3  *
   4  * Copyright 2007-2015 by Apple Inc.
   5  * Copyright 1997-2007 by Easy Software Products, all rights reserved.
   6  *
   7  * These coded instructions, statements, and computer programs are the
   8  * property of Apple Inc. and are protected by Federal copyright
   9  * law.  Distribution and use rights are outlined in the file "LICENSE.txt"
  10  * which should have been included with this file.  If this file is
  11  * file is missing or damaged, see the license at "http://www.cups.org/".
  12  */
  13
  14 /*
  15  * Include necessary headers...
  16  */
  17
  18 #include "cupsd.h"
  19 #include <stdarg.h>
  20 #ifdef HAVE_ASL_H
  21 #  include <asl.h>
  22 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
  23 #  define SD_JOURNAL_SUPPRESS_LOCATION
  24 #  include <systemd/sd-journal.h>
  25 #endif /* HAVE_ASL_H */
  26 #include <syslog.h>
  27
  28
  29 /*
  30  * Constants for log keys from PWG 5110.3 (PWG Common Log Format)...
  31  */
  32
  33 #define PWG_DeviceUUID                  "DUU"
  34 #define PWG_Event                       "E"
  35 #define PWG_LogNaturalLanguage          "NL"
  36 #define PWG_Status                      "S"
  37 #define PWG_ServiceURI                  "URI"
  38 #define PWG_UserHost                    "UH"
  39 #define PWG_UserName                    "UN"
  40 #define PWG_UserURI                     "UU"
  41 #define PWG_ServiceIsAcceptingJobs      "IAJ"
  42 #define PWG_ServiceState                "ST"
  43 #define PWG_ServiceStateReasons         "SR"
  44 #define PWG_ServiceUUID                 "SUU"
  45 #define PWG_JobID                       "JID"
  46 #define PWG_JobUUID                     "JUU"
  47 #define PWG_JobImagesCompleted          "JIM"
  48 #define PWG_JobImpressionsCompleted     "JIC"
  49 #define PWG_JobDestinationURI           "JD"
  50 #define PWG_JobState                    "JS"
  51 #define PWG_JobStateReasons             "JR"
  52 #define PWG_JobAccountingID             "JA"
  53 #define PWG_JobAcountingUserName        "JAUN"
  54 #define PWG_JobAccountingUserURI        "JAUU"
  55
  56
  57 /*
  58  * Local globals...
  59  */
  60
  61 static _cups_mutex_t log_mutex = _CUPS_MUTEX_INITIALIZER;
  62                                         /* Mutex for logging */
  63 static size_t   log_linesize = 0;       /* Size of line for output file */
  64 static char     *log_line = NULL;       /* Line for output file */
  65
  66 #ifdef HAVE_ASL_H
  67 static const int log_levels[] =         /* ASL levels... */
  68                 {
  69                   ASL_LEVEL_EMERG,
  70                   ASL_LEVEL_EMERG,
  71                   ASL_LEVEL_ALERT,
  72                   ASL_LEVEL_CRIT,
  73                   ASL_LEVEL_ERR,
  74                   ASL_LEVEL_WARNING,
  75                   ASL_LEVEL_NOTICE,
  76                   ASL_LEVEL_INFO,
  77                   ASL_LEVEL_DEBUG,
  78                   ASL_LEVEL_DEBUG
  79                 };
  80 #elif defined(HAVE_VSYSLOG) || defined(HAVE_SYSTEMD_SD_JOURNAL_H)
  81 static const int log_levels[] =         /* SYSLOG levels... */
  82                 {
  83                   0,
  84                   LOG_EMERG,
  85                   LOG_ALERT,
  86                   LOG_CRIT,
  87                   LOG_ERR,
  88                   LOG_WARNING,
  89                   LOG_NOTICE,
  90                   LOG_INFO,
  91                   LOG_DEBUG,
  92                   LOG_DEBUG
  93                 };
  94 #endif /* HAVE_ASL_H */
  95
  96
  97 /*
  98  * Local functions...
  99  */
 100
 101 static int      format_log_line(const char *message, va_list ap);
 102
 103
 104 /*
 105  * 'cupsdCheckLogFile()' - Open/rotate a log file if it needs it.
 106  */
 107
 108 int                                     /* O  - 1 if log file open */
 109 cupsdCheckLogFile(cups_file_t **lf,     /* IO - Log file */
 110                   const char  *logname) /* I  - Log filename */
 111 {
 112   char          backname[1024],         /* Backup log filename */
 113                 filename[1024],         /* Formatted log filename */
 114                 *ptr;                   /* Pointer into filename */
 115   const char    *logptr;                /* Pointer into log filename */
 116
 117
 118  /*
 119   * See if we have a log file to check...
 120   */
 121
 122   if (!lf || !logname || !logname[0])
 123     return (1);
 124
 125  /*
 126   * Handle logging to stderr...
 127   */
 128
 129   if (!strcmp(logname, "stderr"))
 130   {
 131     *lf = LogStderr;
 132     return (1);
 133   }
 134
 135  /*
 136   * Format the filename as needed...
 137   */
 138
 139   if (!*lf ||
 140       (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize &&
 141        MaxLogSize > 0))
 142   {
 143    /*
 144     * Handle format strings...
 145     */
 146
 147     filename[sizeof(filename) - 1] = '\0';
 148
 149     if (logname[0] != '/')
 150     {
 151       strlcpy(filename, ServerRoot, sizeof(filename));
 152       strlcat(filename, "/", sizeof(filename));
 153     }
 154     else
 155       filename[0] = '\0';
 156
 157     for (logptr = logname, ptr = filename + strlen(filename);
 158          *logptr && ptr < (filename + sizeof(filename) - 1);
 159          logptr ++)
 160       if (*logptr == '%')
 161       {
 162        /*
 163         * Format spec...
 164         */
 165
 166         logptr ++;
 167         if (*logptr == 's')
 168         {
 169          /*
 170           * Insert the server name...
 171           */
 172
 173           strlcpy(ptr, ServerName, sizeof(filename) - (size_t)(ptr - filename));
 174           ptr += strlen(ptr);
 175         }
 176         else
 177         {
 178          /*
 179           * Otherwise just insert the character...
 180           */
 181
 182           *ptr++ = *logptr;
 183         }
 184       }
 185       else
 186         *ptr++ = *logptr;
 187
 188     *ptr = '\0';
 189   }
 190
 191  /*
 192   * See if the log file is open...
 193   */
 194
 195   if (!*lf)
 196   {
 197    /*
 198     * Nope, open the log file...
 199     */
 200
 201     if ((*lf = cupsFileOpen(filename, "a")) == NULL)
 202     {
 203      /*
 204       * If the file is in CUPS_LOGDIR then try to create a missing directory...
 205       */
 206
 207       if (!strncmp(filename, CUPS_LOGDIR, strlen(CUPS_LOGDIR)))
 208       {
 209        /*
 210         * Try updating the permissions of the containing log directory, using
 211         * the log file permissions as a basis...
 212         */
 213
 214         mode_t log_dir_perm = (mode_t)(0300 | LogFilePerm);
 215                                         /* LogFilePerm + owner write/search */
 216         if (log_dir_perm & 0040)
 217           log_dir_perm |= 0010;         /* Add group search */
 218         if (log_dir_perm & 0004)
 219           log_dir_perm |= 0001;         /* Add other search */
 220
 221         cupsdCheckPermissions(CUPS_LOGDIR, NULL, log_dir_perm, RunUser, Group, 1, -1);
 222
 223         *lf = cupsFileOpen(filename, "a");
 224       }
 225
 226       if (*lf == NULL)
 227       {
 228 #ifdef HAVE_ASL_H
 229         asl_object_t    m;              /* Log message */
 230
 231         m = asl_new(ASL_TYPE_MSG);
 232         asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
 233         asl_log(NULL, m, ASL_LEVEL_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
 234         asl_release(m);
 235
 236 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
 237         sd_journal_print(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
 238
 239 #else
 240         syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
 241 #endif /* HAVE_ASL_H */
 242
 243         if (FatalErrors & CUPSD_FATAL_LOG)
 244           cupsdEndProcess(getpid(), 0);
 245
 246         return (0);
 247       }
 248     }
 249
 250     if (strncmp(filename, "/dev/", 5))
 251     {
 252      /*
 253       * Change ownership and permissions of non-device logs...
 254       */
 255
 256       fchown(cupsFileNumber(*lf), RunUser, Group);
 257       fchmod(cupsFileNumber(*lf), LogFilePerm);
 258     }
 259   }
 260
 261  /*
 262   * Do we need to rotate the log?
 263   */
 264
 265   if (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize &&
 266       MaxLogSize > 0)
 267   {
 268    /*
 269     * Rotate log file...
 270     */
 271
 272     cupsFileClose(*lf);
 273
 274     strlcpy(backname, filename, sizeof(backname));
 275     strlcat(backname, ".O", sizeof(backname));
 276
 277     unlink(backname);
 278     rename(filename, backname);
 279
 280     if ((*lf = cupsFileOpen(filename, "a")) == NULL)
 281     {
 282 #ifdef HAVE_ASL_H
 283         asl_object_t    m;              /* Log message */
 284
 285         m = asl_new(ASL_TYPE_MSG);
 286         asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
 287         asl_log(NULL, m, ASL_LEVEL_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
 288         asl_release(m);
 289
 290 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
 291         sd_journal_print(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
 292
 293 #else
 294         syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, strerror(errno));
 295 #endif /* HAVE_ASL_H */
 296
 297       if (FatalErrors & CUPSD_FATAL_LOG)
 298         cupsdEndProcess(getpid(), 0);
 299
 300       return (0);
 301     }
 302
 303    /*
 304     * Change ownership and permissions of non-device logs...
 305     */
 306
 307     fchown(cupsFileNumber(*lf), RunUser, Group);
 308     fchmod(cupsFileNumber(*lf), LogFilePerm);
 309   }
 310
 311   return (1);
 312 }
 313
 314
 315 /*
 316  * 'cupsdGetDateTime()' - Returns a pointer to a date/time string.
 317  */
 318
 319 char *                                  /* O - Date/time string */
 320 cupsdGetDateTime(struct timeval *t,     /* I - Time value or NULL for current */
 321                  cupsd_time_t   format) /* I - Format to use */
 322 {
 323   struct timeval        curtime;        /* Current time value */
 324   struct tm             *date;          /* Date/time value */
 325   static struct timeval last_time = { 0, 0 };
 326                                         /* Last time we formatted */
 327   static char           s[1024];        /* Date/time string */
 328   static const char * const months[12] =/* Months */
 329                 {
 330                   "Jan",
 331                   "Feb",
 332                   "Mar",
 333                   "Apr",
 334                   "May",
 335                   "Jun",
 336                   "Jul",
 337                   "Aug",
 338                   "Sep",
 339                   "Oct",
 340                   "Nov",
 341                   "Dec"
 342                 };
 343
 344
 345  /*
 346   * Make sure we have a valid time...
 347   */
 348
 349   if (!t)
 350   {
 351     gettimeofday(&curtime, NULL);
 352     t = &curtime;
 353   }
 354
 355   if (t->tv_sec != last_time.tv_sec ||
 356       (LogTimeFormat == CUPSD_TIME_USECS && t->tv_usec != last_time.tv_usec))
 357   {
 358     last_time = *t;
 359
 360    /*
 361     * Get the date and time from the UNIX time value, and then format it
 362     * into a string.  Note that we *can't* use the strftime() function since
 363     * it is localized and will seriously confuse automatic programs if the
 364     * month names are in the wrong language!
 365     *
 366     * Also, we use the "timezone" variable that contains the current timezone
 367     * offset from GMT in seconds so that we are reporting local time in the
 368     * log files.  If you want GMT, set the TZ environment variable accordingly
 369     * before starting the scheduler.
 370     *
 371     * (*BSD and Darwin store the timezone offset in the tm structure)
 372     */
 373
 374     date = localtime(&(t->tv_sec));
 375
 376     if (format == CUPSD_TIME_STANDARD)
 377       snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d %+03ld%02ld]",
 378                date->tm_mday, months[date->tm_mon], 1900 + date->tm_year,
 379                date->tm_hour, date->tm_min, date->tm_sec,
 380 #ifdef HAVE_TM_GMTOFF
 381                date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60);
 382 #else
 383                timezone / 3600, (timezone / 60) % 60);
 384 #endif /* HAVE_TM_GMTOFF */
 385     else
 386       snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d.%06d %+03ld%02ld]",
 387                date->tm_mday, months[date->tm_mon], 1900 + date->tm_year,
 388                date->tm_hour, date->tm_min, date->tm_sec, (int)t->tv_usec,
 389 #ifdef HAVE_TM_GMTOFF
 390                date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60);
 391 #else
 392                timezone / 3600, (timezone / 60) % 60);
 393 #endif /* HAVE_TM_GMTOFF */
 394   }
 395
 396   return (s);
 397 }
 398
 399
 400 /*
 401  * 'cupsdLogFCMessage()' - Log a file checking message.
 402  */
 403
 404 void
 405 cupsdLogFCMessage(
 406     void              *context,         /* I - Printer (if any) */
 407     _cups_fc_result_t result,           /* I - Check result */
 408     const char        *message)         /* I - Message to log */
 409 {
 410   cupsd_printer_t       *p = (cupsd_printer_t *)context;
 411                                         /* Printer */
 412   cupsd_loglevel_t      level;          /* Log level */
 413
 414
 415   if (result == _CUPS_FILE_CHECK_OK)
 416     level = CUPSD_LOG_DEBUG2;
 417   else
 418     level = CUPSD_LOG_ERROR;
 419
 420   if (p)
 421   {
 422     cupsdLogMessage(level, "%s: %s", p->name, message);
 423
 424     if (result == _CUPS_FILE_CHECK_MISSING ||
 425         result == _CUPS_FILE_CHECK_WRONG_TYPE)
 426     {
 427       strlcpy(p->state_message, message, sizeof(p->state_message));
 428
 429       if (cupsdSetPrinterReasons(p, "+cups-missing-filter-warning"))
 430         cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, p, NULL, "%s", message);
 431     }
 432     else if (result == _CUPS_FILE_CHECK_PERMISSIONS ||
 433              result == _CUPS_FILE_CHECK_RELATIVE_PATH)
 434     {
 435       strlcpy(p->state_message, message, sizeof(p->state_message));
 436
 437       if (cupsdSetPrinterReasons(p, "+cups-insecure-filter-warning"))
 438         cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, p, NULL, "%s", message);
 439     }
 440   }
 441   else
 442     cupsdLogMessage(level, "%s", message);
 443 }
 444
 445
 446 #ifdef HAVE_GSSAPI
 447 /*
 448  * 'cupsdLogGSSMessage()' - Log a GSSAPI error...
 449  */
 450
 451 int                                     /* O - 1 on success, 0 on error */
 452 cupsdLogGSSMessage(
 453     int        level,                   /* I - Log level */
 454     OM_uint32  major_status,            /* I - Major GSSAPI status */
 455     OM_uint32  minor_status,            /* I - Minor GSSAPI status */
 456     const char *message,                /* I - printf-style message string */
 457     ...)                                /* I - Additional args as needed */
 458 {
 459   OM_uint32     err_major_status,       /* Major status code for display */
 460                 err_minor_status;       /* Minor status code for display */
 461   OM_uint32     msg_ctx;                /* Message context */
 462   gss_buffer_desc major_status_string = GSS_C_EMPTY_BUFFER,
 463                                         /* Major status message */
 464                 minor_status_string = GSS_C_EMPTY_BUFFER;
 465                                         /* Minor status message */
 466   int           ret;                    /* Return value */
 467   char          buffer[8192];           /* Buffer for vsnprintf */
 468
 469
 470   if (strchr(message, '%'))
 471   {
 472    /*
 473     * Format the message string...
 474     */
 475
 476     va_list     ap;                     /* Pointer to arguments */
 477
 478     va_start(ap, message);
 479     vsnprintf(buffer, sizeof(buffer), message, ap);
 480     va_end(ap);
 481
 482     message = buffer;
 483   }
 484
 485   msg_ctx             = 0;
 486   err_major_status    = gss_display_status(&err_minor_status,
 487                                            major_status,
 488                                            GSS_C_GSS_CODE,
 489                                            GSS_C_NO_OID,
 490                                            &msg_ctx,
 491                                            &major_status_string);
 492
 493   if (!GSS_ERROR(err_major_status))
 494     gss_display_status(&err_minor_status, minor_status, GSS_C_MECH_CODE,
 495                        GSS_C_NULL_OID, &msg_ctx, &minor_status_string);
 496
 497   ret = cupsdLogMessage(level, "%s: %s, %s", message,
 498                         (char *)major_status_string.value,
 499                         (char *)minor_status_string.value);
 500   gss_release_buffer(&err_minor_status, &major_status_string);
 501   gss_release_buffer(&err_minor_status, &minor_status_string);
 502
 503   return (ret);
 504 }
 505 #endif /* HAVE_GSSAPI */
 506
 507
 508 /*
 509  * 'cupsdLogClient()' - Log a client message.
 510  */
 511
 512 int                                     /* O - 1 on success, 0 on error */
 513 cupsdLogClient(cupsd_client_t *con,     /* I - Client connection */
 514                int            level,    /* I - Log level */
 515                const char     *message, /* I - Printf-style message string */
 516                ...)                     /* I - Additional arguments as needed */
 517 {
 518   va_list               ap, ap2;        /* Argument pointers */
 519   char                  clientmsg[1024];/* Format string for client message */
 520   int                   status;         /* Formatting status */
 521
 522
 523  /*
 524   * See if we want to log this message...
 525   */
 526
 527   if (TestConfigFile || !ErrorLog)
 528     return (1);
 529
 530   if (level > LogLevel)
 531     return (1);
 532
 533  /*
 534   * Format and write the log message...
 535   */
 536
 537   if (con)
 538     snprintf(clientmsg, sizeof(clientmsg), "[Client %d] %s", con->number,
 539              message);
 540   else
 541     strlcpy(clientmsg, message, sizeof(clientmsg));
 542
 543   va_start(ap, message);
 544
 545   do
 546   {
 547     va_copy(ap2, ap);
 548     status = format_log_line(clientmsg, ap2);
 549     va_end(ap2);
 550   }
 551   while (status == 0);
 552
 553   va_end(ap);
 554
 555   if (status > 0)
 556     return (cupsdWriteErrorLog(level, log_line));
 557   else
 558     return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
 559                                "Unable to allocate memory for log line."));
 560 }
 561
 562
 563 /*
 564  * 'cupsdLogJob()' - Log a job message.
 565  */
 566
 567 int                                     /* O - 1 on success, 0 on error */
 568 cupsdLogJob(cupsd_job_t *job,           /* I - Job */
 569             int         level,          /* I - Log level */
 570             const char  *message,       /* I - Printf-style message string */
 571             ...)                        /* I - Additional arguments as needed */
 572 {
 573   va_list               ap, ap2;        /* Argument pointers */
 574   char                  jobmsg[1024];   /* Format string for job message */
 575   int                   status;         /* Formatting status */
 576
 577
 578  /*
 579   * See if we want to log this message...
 580   */
 581
 582   if (TestConfigFile || !ErrorLog)
 583     return (1);
 584
 585   if ((level > LogLevel ||
 586        (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) &&
 587       LogDebugHistory <= 0)
 588     return (1);
 589
 590 #ifdef HAVE_ASL_H
 591   if (!strcmp(ErrorLog, "syslog"))
 592   {
 593     asl_object_t        m;              /* Log message */
 594     char                job_id[32],     /* job-id string */
 595                         completed[32];  /* job-impressions-completed string */
 596     cupsd_printer_t *printer = job ? (job->printer ? job->printer : (job->dest ? cupsdFindDest(job->dest) : NULL)) : NULL;
 597     static const char * const job_states[] =
 598     {                                   /* job-state strings */
 599       "Pending",
 600       "PendingHeld",
 601       "Processing",
 602       "ProcessingStopped",
 603       "Canceled",
 604       "Aborted",
 605       "Completed"
 606     };
 607
 608     m = asl_new(ASL_TYPE_MSG);
 609     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
 610     if (printer)
 611       asl_set(m, PWG_ServiceURI, printer->uri);
 612     if (job)
 613     {
 614       snprintf(job_id, sizeof(job_id), "%d", job->id);
 615
 616       asl_set(m, PWG_Event, "JobStateChanged");
 617       asl_set(m, PWG_JobID, job_id);
 618       asl_set(m, PWG_JobState, job->state_value < IPP_JSTATE_PENDING ? "" : job_states[job->state_value - IPP_JSTATE_PENDING]);
 619
 620       if (job->impressions)
 621       {
 622         snprintf(completed, sizeof(completed), "%d", ippGetInteger(job->impressions, 0));
 623         asl_set(m, PWG_JobImpressionsCompleted, completed);
 624       }
 625     }
 626
 627     va_start(ap, message);
 628     asl_vlog(NULL, m, log_levels[level], message, ap);
 629     va_end(ap);
 630
 631     asl_release(m);
 632     return (1);
 633   }
 634
 635 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
 636   if (!strcmp(ErrorLog, "syslog"))
 637   {
 638     cupsd_printer_t *printer = job ? (job->printer ? job->printer : (job->dest ? cupsdFindDest(job->dest) : NULL)) : NULL;
 639     static const char * const job_states[] =
 640     {                                   /* job-state strings */
 641       "Pending",
 642       "PendingHeld",
 643       "Processing",
 644       "ProcessingStopped",
 645       "Canceled",
 646       "Aborted",
 647       "Completed"
 648     };
 649
 650     va_start(ap, message);
 651
 652     do
 653     {
 654       va_copy(ap2, ap);
 655       status = format_log_line(message, ap2);
 656       va_end(ap2);
 657     }
 658     while (status == 0);
 659
 660     va_end(ap);
 661
 662     if (job)
 663       sd_journal_send("MESSAGE=%s", log_line,
 664                       "PRIORITY=%i", log_levels[level],
 665                       PWG_Event"=JobStateChanged",
 666                       PWG_ServiceURI"=%s", printer ? printer->uri : "",
 667                       PWG_JobID"=%d", job->id,
 668                       PWG_JobState"=%s", job->state_value < IPP_JSTATE_PENDING ? "" : job_states[job->state_value - IPP_JSTATE_PENDING],
 669                       PWG_JobImpressionsCompleted"=%d", ippGetInteger(job->impressions, 0),
 670                       NULL);
 671     else
 672       sd_journal_send("MESSAGE=%s", log_line,
 673                       "PRIORITY=%i", log_levels[level],
 674                       NULL);
 675
 676     return (1);
 677   }
 678 #endif /* HAVE_ASL_H */
 679
 680  /*
 681   * Format and write the log message...
 682   */
 683
 684   if (job)
 685     snprintf(jobmsg, sizeof(jobmsg), "[Job %d] %s", job->id, message);
 686   else
 687     strlcpy(jobmsg, message, sizeof(jobmsg));
 688
 689   va_start(ap, message);
 690
 691   do
 692   {
 693     va_copy(ap2, ap);
 694     status = format_log_line(jobmsg, ap2);
 695     va_end(ap2);
 696   }
 697   while (status == 0);
 698
 699   va_end(ap);
 700
 701   if (status > 0)
 702   {
 703     if (job &&
 704         (level > LogLevel ||
 705          (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) &&
 706         LogDebugHistory > 0)
 707     {
 708      /*
 709       * Add message to the job history...
 710       */
 711
 712       cupsd_joblog_t *temp;             /* Copy of log message */
 713       size_t         log_len = strlen(log_line);
 714                                         /* Length of log message */
 715
 716       if ((temp = malloc(sizeof(cupsd_joblog_t) + log_len)) != NULL)
 717       {
 718         temp->time = time(NULL);
 719         memcpy(temp->message, log_line, log_len + 1);
 720       }
 721
 722       if (!job->history)
 723         job->history = cupsArrayNew(NULL, NULL);
 724
 725       if (job->history && temp)
 726       {
 727         cupsArrayAdd(job->history, temp);
 728
 729         if (cupsArrayCount(job->history) > LogDebugHistory)
 730         {
 731          /*
 732           * Remove excess messages...
 733           */
 734
 735           temp = cupsArrayFirst(job->history);
 736           cupsArrayRemove(job->history, temp);
 737           free(temp);
 738         }
 739       }
 740       else if (temp)
 741         free(temp);
 742
 743       return (1);
 744     }
 745     else if (level <= LogLevel &&
 746              (level != CUPSD_LOG_INFO || LogLevel >= CUPSD_LOG_DEBUG))
 747       return (cupsdWriteErrorLog(level, log_line));
 748     else
 749       return (1);
 750   }
 751   else
 752     return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
 753                                "Unable to allocate memory for log line."));
 754 }
 755
 756
 757 /*
 758  * 'cupsdLogMessage()' - Log a message to the error log file.
 759  */
 760
 761 int                                     /* O - 1 on success, 0 on error */
 762 cupsdLogMessage(int        level,       /* I - Log level */
 763                 const char *message,    /* I - printf-style message string */
 764                 ...)                    /* I - Additional args as needed */
 765 {
 766   va_list               ap, ap2;        /* Argument pointers */
 767   int                   status;         /* Formatting status */
 768
 769
 770  /*
 771   * See if we want to log this message...
 772   */
 773
 774   if ((TestConfigFile || !ErrorLog) && level <= CUPSD_LOG_WARN)
 775   {
 776     va_start(ap, message);
 777
 778 #ifdef HAVE_ASL_H
 779     asl_object_t        m;              /* Log message */
 780
 781     m = asl_new(ASL_TYPE_MSG);
 782     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
 783     asl_vlog(NULL, m, log_levels[level], message, ap);
 784     asl_release(m);
 785
 786 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
 787     sd_journal_printv(log_levels[level], message, ap);
 788
 789 #elif defined(HAVE_VSYSLOG)
 790     vsyslog(LOG_LPR | log_levels[level], message, ap);
 791
 792 #else
 793     vfprintf(stderr, message, ap);
 794     putc('\n', stderr);
 795 #endif /* HAVE_VSYSLOG */
 796
 797     va_end(ap);
 798
 799     return (1);
 800   }
 801
 802   if (level > LogLevel || !ErrorLog)
 803     return (1);
 804
 805 #ifdef HAVE_ASL_H
 806   if (!strcmp(ErrorLog, "syslog"))
 807   {
 808     asl_object_t        m;              /* Log message */
 809
 810     m = asl_new(ASL_TYPE_MSG);
 811     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
 812
 813     va_start(ap, message);
 814     asl_vlog(NULL, m, log_levels[level], message, ap);
 815     va_end(ap);
 816
 817     asl_release(m);
 818     return (1);
 819   }
 820
 821 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
 822   if (!strcmp(ErrorLog, "syslog"))
 823   {
 824     va_start(ap, message);
 825     sd_journal_printv(log_levels[level], message, ap);
 826     va_end(ap);
 827     return (1);
 828   }
 829 #endif /* HAVE_ASL_H */
 830
 831  /*
 832   * Format and write the log message...
 833   */
 834
 835   va_start(ap, message);
 836
 837   do
 838   {
 839     va_copy(ap2, ap);
 840     status = format_log_line(message, ap2);
 841     va_end(ap2);
 842   }
 843   while (status == 0);
 844
 845   va_end(ap);
 846
 847   if (status > 0)
 848     return (cupsdWriteErrorLog(level, log_line));
 849   else
 850     return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
 851                                "Unable to allocate memory for log line!"));
 852 }
 853
 854
 855 /*
 856  * 'cupsdLogPage()' - Log a page to the page log file.
 857  */
 858
 859 int                                     /* O - 1 on success, 0 on error */
 860 cupsdLogPage(cupsd_job_t *job,          /* I - Job being printed */
 861              const char  *page)         /* I - Page being printed */
 862 {
 863   int                   i;              /* Looping var */
 864   char                  buffer[2048],   /* Buffer for page log */
 865                         *bufptr,        /* Pointer into buffer */
 866                         name[256];      /* Attribute name */
 867   const char            *format,        /* Pointer into PageLogFormat */
 868                         *nameend;       /* End of attribute name */
 869   ipp_attribute_t       *attr;          /* Current attribute */
 870   char                  number[256];    /* Page number */
 871   int                   copies;         /* Number of copies */
 872
 873
 874  /*
 875   * Format the line going into the page log...
 876   */
 877
 878   if (!PageLogFormat)
 879     return (1);
 880
 881   strlcpy(number, "1", sizeof(number));
 882   copies = 1;
 883   sscanf(page, "%255s%d", number, &copies);
 884
 885   for (format = PageLogFormat, bufptr = buffer; *format; format ++)
 886   {
 887     if (*format == '%')
 888     {
 889       format ++;
 890
 891       switch (*format)
 892       {
 893         case '%' :                      /* Literal % */
 894             if (bufptr < (buffer + sizeof(buffer) - 1))
 895               *bufptr++ = '%';
 896             break;
 897
 898         case 'p' :                      /* Printer name */
 899             strlcpy(bufptr, job->dest, sizeof(buffer) - (size_t)(bufptr - buffer));
 900             bufptr += strlen(bufptr);
 901             break;
 902
 903         case 'j' :                      /* Job ID */
 904             snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", job->id);
 905             bufptr += strlen(bufptr);
 906             break;
 907
 908         case 'u' :                      /* Username */
 909             strlcpy(bufptr, job->username ? job->username : "-", sizeof(buffer) - (size_t)(bufptr - buffer));
 910             bufptr += strlen(bufptr);
 911             break;
 912
 913         case 'T' :                      /* Date and time */
 914             strlcpy(bufptr, cupsdGetDateTime(NULL, LogTimeFormat), sizeof(buffer) - (size_t)(bufptr - buffer));
 915             bufptr += strlen(bufptr);
 916             break;
 917
 918         case 'P' :                      /* Page number */
 919             strlcpy(bufptr, number, sizeof(buffer) - (size_t)(bufptr - buffer));
 920             bufptr += strlen(bufptr);
 921             break;
 922
 923         case 'C' :                      /* Number of copies */
 924             snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", copies);
 925             bufptr += strlen(bufptr);
 926             break;
 927
 928         case '{' :                      /* {attribute} */
 929             if ((nameend = strchr(format, '}')) != NULL && (size_t)(nameend - format - 2) < (sizeof(name) - 1))
 930             {
 931              /*
 932               * Pull the name from inside the brackets...
 933               */
 934
 935               memcpy(name, format + 1, (size_t)(nameend - format - 1));
 936               name[nameend - format - 1] = '\0';
 937
 938               format = nameend;
 939
 940               attr = ippFindAttribute(job->attrs, name, IPP_TAG_ZERO);
 941               if (!attr && !strcmp(name, "job-billing"))
 942               {
 943                /*
 944                 * Handle alias "job-account-id" (which was standardized after
 945                 * "job-billing" was defined for CUPS...
 946                 */
 947
 948                 attr = ippFindAttribute(job->attrs, "job-account-id", IPP_TAG_ZERO);
 949               }
 950               else if (!attr && !strcmp(name, "media"))
 951               {
 952                /*
 953                 * Handle alias "media-col" which uses dimensions instead of
 954                 * names...
 955                 */
 956
 957                 attr = ippFindAttribute(job->attrs, "media-col/media-size", IPP_TAG_BEGIN_COLLECTION);
 958               }
 959
 960               if (attr)
 961               {
 962                /*
 963                 * Add the attribute value...
 964                 */
 965
 966                 for (i = 0;
 967                      i < attr->num_values &&
 968                          bufptr < (buffer + sizeof(buffer) - 1);
 969                      i ++)
 970                 {
 971                   if (i)
 972                     *bufptr++ = ',';
 973
 974                   switch (attr->value_tag)
 975                   {
 976                     case IPP_TAG_INTEGER :
 977                     case IPP_TAG_ENUM :
 978                         snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", attr->values[i].integer);
 979                         bufptr += strlen(bufptr);
 980                         break;
 981
 982                     case IPP_TAG_BOOLEAN :
 983                         snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", attr->values[i].boolean);
 984                         bufptr += strlen(bufptr);
 985                         break;
 986
 987                     case IPP_TAG_TEXTLANG :
 988                     case IPP_TAG_NAMELANG :
 989                     case IPP_TAG_TEXT :
 990                     case IPP_TAG_NAME :
 991                     case IPP_TAG_KEYWORD :
 992                     case IPP_TAG_URI :
 993                     case IPP_TAG_URISCHEME :
 994                     case IPP_TAG_CHARSET :
 995                     case IPP_TAG_LANGUAGE :
 996                     case IPP_TAG_MIMETYPE :
 997                         strlcpy(bufptr, attr->values[i].string.text, sizeof(buffer) - (size_t)(bufptr - buffer));
 998                         bufptr += strlen(bufptr);
 999                         break;
1000
1001                     case IPP_TAG_BEGIN_COLLECTION :
1002                         if (!strcmp(attr->name, "media-size"))
1003                         {
1004                           ipp_attribute_t *x_dimension = ippFindAttribute(ippGetCollection(attr, 0), "x-dimension", IPP_TAG_INTEGER);
1005                           ipp_attribute_t *y_dimension = ippFindAttribute(ippGetCollection(attr, 0), "y-dimension", IPP_TAG_INTEGER);
1006                                         /* Media dimensions */
1007
1008                           if (x_dimension && y_dimension)
1009                           {
1010                             pwg_media_t *pwg = pwgMediaForSize(ippGetInteger(x_dimension, 0), ippGetInteger(y_dimension, 0));
1011                                         /* PWG media name */
1012                             strlcpy(bufptr, pwg->pwg, sizeof(buffer) - (size_t)(bufptr - buffer));
1013                             break;
1014                           }
1015                         }
1016
1017                     default :
1018                         strlcpy(bufptr, "???", sizeof(buffer) - (size_t)(bufptr - buffer));
1019                         bufptr += strlen(bufptr);
1020                         break;
1021                   }
1022                 }
1023               }
1024               else if (bufptr < (buffer + sizeof(buffer) - 1))
1025                 *bufptr++ = '-';
1026               break;
1027             }
1028
1029         default :
1030             if (bufptr < (buffer + sizeof(buffer) - 2))
1031             {
1032               *bufptr++ = '%';
1033               *bufptr++ = *format;
1034             }
1035             break;
1036       }
1037     }
1038     else if (bufptr < (buffer + sizeof(buffer) - 1))
1039       *bufptr++ = *format;
1040   }
1041
1042   *bufptr = '\0';
1043
1044 #ifdef HAVE_ASL_H
1045   if (!strcmp(ErrorLog, "syslog"))
1046   {
1047     asl_object_t        m;              /* Log message */
1048     char                job_id[32],     /* job-id string */
1049                         completed[32];  /* job-impressions-completed string */
1050     static const char * const job_states[] =
1051     {                                   /* job-state strings */
1052       "Pending",
1053       "PendingHeld",
1054       "Processing",
1055       "ProcessingStopped",
1056       "Canceled",
1057       "Aborted",
1058       "Completed"
1059     };
1060
1061     snprintf(job_id, sizeof(job_id), "%d", job->id);
1062
1063     m = asl_new(ASL_TYPE_MSG);
1064     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
1065     asl_set(m, PWG_Event, "JobStateChanged");
1066     asl_set(m, PWG_ServiceURI, job->printer->uri);
1067     asl_set(m, PWG_JobID, job_id);
1068     asl_set(m, PWG_JobState, job_states[job->state_value - IPP_JSTATE_PENDING]);
1069
1070     if (job->impressions)
1071     {
1072       snprintf(completed, sizeof(completed), "%d", ippGetInteger(job->impressions, 0));
1073       asl_set(m, PWG_JobImpressionsCompleted, completed);
1074     }
1075
1076     asl_log(NULL, m, ASL_LEVEL_INFO, "%s", buffer);
1077
1078     asl_release(m);
1079     return (1);
1080   }
1081
1082 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
1083   if (!strcmp(ErrorLog, "syslog"))
1084   {
1085     static const char * const job_states[] =
1086     {                                   /* job-state strings */
1087       "Pending",
1088       "PendingHeld",
1089       "Processing",
1090       "ProcessingStopped",
1091       "Canceled",
1092       "Aborted",
1093       "Completed"
1094     };
1095
1096     sd_journal_send("MESSAGE=%s", buffer,
1097                     "PRIORITY=%i", LOG_INFO,
1098                     PWG_Event"=JobStateChanged",
1099                     PWG_ServiceURI"=%s", job->printer->uri,
1100                     PWG_JobID"=%d", job->id,
1101                     PWG_JobState"=%s", job_states[job->state_value - IPP_JSTATE_PENDING],
1102                     PWG_JobImpressionsCompleted"=%d", ippGetInteger(job->impressions, 0),
1103                     NULL);
1104     return (1);
1105   }
1106
1107 #elif defined(HAVE_VSYSLOG)
1108  /*
1109   * See if we are logging pages via syslog...
1110   */
1111
1112   if (!strcmp(PageLog, "syslog"))
1113   {
1114     syslog(LOG_INFO, "%s", buffer);
1115
1116     return (1);
1117   }
1118 #endif /* HAVE_ASL_H */
1119
1120  /*
1121   * Not using syslog; check the log file...
1122   */
1123
1124   if (!cupsdCheckLogFile(&PageFile, PageLog))
1125     return (0);
1126
1127  /*
1128   * Print a page log entry of the form:
1129   *
1130   *    printer user job-id [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \
1131   *        billing hostname
1132   */
1133
1134   cupsFilePrintf(PageFile, "%s\n", buffer);
1135   cupsFileFlush(PageFile);
1136
1137   return (1);
1138 }
1139
1140
1141 /*
1142  * 'cupsdLogRequest()' - Log an HTTP request in Common Log Format.
1143  */
1144
1145 int                                     /* O - 1 on success, 0 on error */
1146 cupsdLogRequest(cupsd_client_t *con,    /* I - Request to log */
1147                 http_status_t  code)    /* I - Response code */
1148 {
1149   char  temp[2048];                     /* Temporary string for URI */
1150   static const char * const states[] =  /* HTTP client states... */
1151                 {
1152                   "WAITING",
1153                   "OPTIONS",
1154                   "GET",
1155                   "GET",
1156                   "HEAD",
1157                   "POST",
1158                   "POST",
1159                   "POST",
1160                   "PUT",
1161                   "PUT",
1162                   "DELETE",
1163                   "TRACE",
1164                   "CLOSE",
1165                   "STATUS"
1166                 };
1167
1168
1169  /*
1170   * Filter requests as needed...
1171   */
1172
1173   if (AccessLogLevel == CUPSD_ACCESSLOG_NONE)
1174     return (1);
1175   else if (AccessLogLevel < CUPSD_ACCESSLOG_ALL)
1176   {
1177    /*
1178     * Eliminate simple GET, POST, and PUT requests...
1179     */
1180
1181     if ((con->operation == HTTP_GET &&
1182          strncmp(con->uri, "/admin/conf", 11) &&
1183          strncmp(con->uri, "/admin/log", 10)) ||
1184         (con->operation == HTTP_POST && !con->request &&
1185          strncmp(con->uri, "/admin", 6)) ||
1186         (con->operation != HTTP_GET && con->operation != HTTP_POST &&
1187          con->operation != HTTP_PUT))
1188       return (1);
1189
1190     if (con->request && con->response &&
1191         (con->response->request.status.status_code < IPP_REDIRECTION_OTHER_SITE ||
1192          con->response->request.status.status_code == IPP_NOT_FOUND))
1193     {
1194      /*
1195       * Check successful requests...
1196       */
1197
1198       ipp_op_t op = con->request->request.op.operation_id;
1199       static cupsd_accesslog_t standard_ops[] =
1200       {
1201         CUPSD_ACCESSLOG_ALL,    /* reserved */
1202         CUPSD_ACCESSLOG_ALL,    /* reserved */
1203         CUPSD_ACCESSLOG_ACTIONS,/* Print-Job */
1204         CUPSD_ACCESSLOG_ACTIONS,/* Print-URI */
1205         CUPSD_ACCESSLOG_ACTIONS,/* Validate-Job */
1206         CUPSD_ACCESSLOG_ACTIONS,/* Create-Job */
1207         CUPSD_ACCESSLOG_ACTIONS,/* Send-Document */
1208         CUPSD_ACCESSLOG_ACTIONS,/* Send-URI */
1209         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Job */
1210         CUPSD_ACCESSLOG_ALL,    /* Get-Job-Attributes */
1211         CUPSD_ACCESSLOG_ALL,    /* Get-Jobs */
1212         CUPSD_ACCESSLOG_ALL,    /* Get-Printer-Attributes */
1213         CUPSD_ACCESSLOG_ACTIONS,/* Hold-Job */
1214         CUPSD_ACCESSLOG_ACTIONS,/* Release-Job */
1215         CUPSD_ACCESSLOG_ACTIONS,/* Restart-Job */
1216         CUPSD_ACCESSLOG_ALL,    /* reserved */
1217         CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer */
1218         CUPSD_ACCESSLOG_CONFIG, /* Resume-Printer */
1219         CUPSD_ACCESSLOG_CONFIG, /* Purge-Jobs */
1220         CUPSD_ACCESSLOG_CONFIG, /* Set-Printer-Attributes */
1221         CUPSD_ACCESSLOG_ACTIONS,/* Set-Job-Attributes */
1222         CUPSD_ACCESSLOG_CONFIG, /* Get-Printer-Supported-Values */
1223         CUPSD_ACCESSLOG_ACTIONS,/* Create-Printer-Subscription */
1224         CUPSD_ACCESSLOG_ACTIONS,/* Create-Job-Subscription */
1225         CUPSD_ACCESSLOG_ALL,    /* Get-Subscription-Attributes */
1226         CUPSD_ACCESSLOG_ALL,    /* Get-Subscriptions */
1227         CUPSD_ACCESSLOG_ACTIONS,/* Renew-Subscription */
1228         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Subscription */
1229         CUPSD_ACCESSLOG_ALL,    /* Get-Notifications */
1230         CUPSD_ACCESSLOG_ACTIONS,/* Send-Notifications */
1231         CUPSD_ACCESSLOG_ALL,    /* reserved */
1232         CUPSD_ACCESSLOG_ALL,    /* reserved */
1233         CUPSD_ACCESSLOG_ALL,    /* reserved */
1234         CUPSD_ACCESSLOG_ALL,    /* Get-Print-Support-Files */
1235         CUPSD_ACCESSLOG_CONFIG, /* Enable-Printer */
1236         CUPSD_ACCESSLOG_CONFIG, /* Disable-Printer */
1237         CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer-After-Current-Job */
1238         CUPSD_ACCESSLOG_ACTIONS,/* Hold-New-Jobs */
1239         CUPSD_ACCESSLOG_ACTIONS,/* Release-Held-New-Jobs */
1240         CUPSD_ACCESSLOG_CONFIG, /* Deactivate-Printer */
1241         CUPSD_ACCESSLOG_CONFIG, /* Activate-Printer */
1242         CUPSD_ACCESSLOG_CONFIG, /* Restart-Printer */
1243         CUPSD_ACCESSLOG_CONFIG, /* Shutdown-Printer */
1244         CUPSD_ACCESSLOG_CONFIG, /* Startup-Printer */
1245         CUPSD_ACCESSLOG_ACTIONS,/* Reprocess-Job */
1246         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Current-Job */
1247         CUPSD_ACCESSLOG_ACTIONS,/* Suspend-Current-Job */
1248         CUPSD_ACCESSLOG_ACTIONS,/* Resume-Job */
1249         CUPSD_ACCESSLOG_ACTIONS,/* Promote-Job */
1250         CUPSD_ACCESSLOG_ACTIONS /* Schedule-Job-After */
1251       };
1252       static cupsd_accesslog_t cups_ops[] =
1253       {
1254         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Default */
1255         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Printers */
1256         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Printer */
1257         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Printer */
1258         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Classes */
1259         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Class */
1260         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Class */
1261         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Accept-Jobs */
1262         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Reject-Jobs */
1263         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Set-Default */
1264         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-Devices */
1265         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-PPDs */
1266         CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Move-Job */
1267         CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Authenticate-Job */
1268         CUPSD_ACCESSLOG_ALL     /* CUPS-Get-PPD */
1269       };
1270
1271
1272       if ((op <= IPP_SCHEDULE_JOB_AFTER && standard_ops[op] > AccessLogLevel) ||
1273           (op >= CUPS_GET_DEFAULT && op <= CUPS_GET_PPD &&
1274            cups_ops[op - CUPS_GET_DEFAULT] > AccessLogLevel))
1275         return (1);
1276     }
1277   }
1278
1279 #ifdef HAVE_ASL_H
1280   if (!strcmp(ErrorLog, "syslog"))
1281   {
1282     asl_object_t        m;              /* Log message */
1283
1284     m = asl_new(ASL_TYPE_MSG);
1285     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
1286
1287     asl_log(NULL, m, ASL_LEVEL_INFO, "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
1288            con->http->hostname, con->username[0] != '\0' ? con->username : "-",
1289            states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)),
1290            con->http->version / 100, con->http->version % 100,
1291            code, CUPS_LLCAST con->bytes,
1292            con->request ?
1293                ippOpString(con->request->request.op.operation_id) : "-",
1294            con->response ?
1295                ippErrorString(con->response->request.status.status_code) : "-");
1296
1297     asl_release(m);
1298     return (1);
1299   }
1300
1301 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
1302   if (!strcmp(ErrorLog, "syslog"))
1303   {
1304     sd_journal_print(LOG_INFO, "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s", con->http->hostname, con->username[0] != '\0' ? con->username : "-", states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)), con->http->version / 100, con->http->version % 100, code, CUPS_LLCAST con->bytes, con->request ? ippOpString(con->request->request.op.operation_id) : "-", con->response ? ippErrorString(con->response->request.status.status_code) : "-");
1305     return (1);
1306   }
1307
1308 #elif defined(HAVE_VSYSLOG)
1309  /*
1310   * See if we are logging accesses via syslog...
1311   */
1312
1313   if (!strcmp(AccessLog, "syslog"))
1314   {
1315     syslog(LOG_INFO,
1316            "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
1317            con->http->hostname, con->username[0] != '\0' ? con->username : "-",
1318            states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)),
1319            con->http->version / 100, con->http->version % 100,
1320            code, CUPS_LLCAST con->bytes,
1321            con->request ?
1322                ippOpString(con->request->request.op.operation_id) : "-",
1323            con->response ?
1324                ippErrorString(con->response->request.status.status_code) : "-");
1325
1326     return (1);
1327   }
1328 #endif /* HAVE_ASL_H */
1329
1330  /*
1331   * Not using syslog; check the log file...
1332   */
1333
1334   if (!cupsdCheckLogFile(&AccessFile, AccessLog))
1335     return (0);
1336
1337  /*
1338   * Write a log of the request in "common log format"...
1339   */
1340
1341   cupsFilePrintf(AccessFile,
1342                  "%s - %s %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
1343                  con->http->hostname,
1344                  con->username[0] != '\0' ? con->username : "-",
1345                  cupsdGetDateTime(&(con->start), LogTimeFormat),
1346                  states[con->operation],
1347                  _httpEncodeURI(temp, con->uri, sizeof(temp)),
1348                  con->http->version / 100, con->http->version % 100,
1349                  code, CUPS_LLCAST con->bytes,
1350                  con->request ?
1351                      ippOpString(con->request->request.op.operation_id) : "-",
1352                  con->response ?
1353                      ippErrorString(con->response->request.status.status_code) :
1354                      "-");
1355
1356   cupsFileFlush(AccessFile);
1357
1358   return (1);
1359 }
1360
1361
1362 /*
1363  * 'cupsdWriteErrorLog()' - Write a line to the ErrorLog.
1364  */
1365
1366 int                                     /* O - 1 on success, 0 on failure */
1367 cupsdWriteErrorLog(int        level,    /* I - Log level */
1368                    const char *message) /* I - Message string */
1369 {
1370   int           ret = 1;                /* Return value */
1371   static const char     levels[] =      /* Log levels... */
1372                 {
1373                   ' ',
1374                   'X',
1375                   'A',
1376                   'C',
1377                   'E',
1378                   'W',
1379                   'N',
1380                   'I',
1381                   'D',
1382                   'd'
1383                 };
1384
1385
1386 #ifdef HAVE_ASL_H
1387   if (!strcmp(ErrorLog, "syslog"))
1388   {
1389     asl_object_t        m;              /* Log message */
1390
1391     m = asl_new(ASL_TYPE_MSG);
1392     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
1393     asl_log(NULL, m, ASL_LEVEL_INFO, "%s", message);
1394
1395     asl_release(m);
1396     return (1);
1397   }
1398
1399 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
1400   if (!strcmp(ErrorLog, "syslog"))
1401   {
1402     sd_journal_print(log_levels[level], "%s", message);
1403     return (1);
1404   }
1405
1406 #elif defined(HAVE_VSYSLOG)
1407  /*
1408   * See if we are logging errors via syslog...
1409   */
1410
1411   if (!strcmp(ErrorLog, "syslog"))
1412   {
1413     syslog(log_levels[level], "%s", message);
1414     return (1);
1415   }
1416 #endif /* HAVE_ASL_H */
1417
1418  /*
1419   * Not using syslog; check the log file...
1420   */
1421
1422   _cupsMutexLock(&log_mutex);
1423
1424   if (!cupsdCheckLogFile(&ErrorFile, ErrorLog))
1425   {
1426     ret = 0;
1427   }
1428   else
1429   {
1430    /*
1431     * Write the log message...
1432     */
1433
1434     cupsFilePrintf(ErrorFile, "%c %s %s\n", levels[level],
1435                    cupsdGetDateTime(NULL, LogTimeFormat), message);
1436     cupsFileFlush(ErrorFile);
1437   }
1438
1439   _cupsMutexUnlock(&log_mutex);
1440
1441   return (ret);
1442 }
1443
1444
1445 /*
1446  * 'format_log_line()' - Format a line for a log file.
1447  *
1448  * This function resizes a global string buffer as needed.  Each call returns
1449  * a pointer to this buffer, so the contents are only good until the next call
1450  * to format_log_line()...
1451  */
1452
1453 static int                              /* O - -1 for fatal, 0 for retry, 1 for success */
1454 format_log_line(const char *message,    /* I - Printf-style format string */
1455                 va_list    ap)          /* I - Argument list */
1456 {
1457   ssize_t       len;                    /* Length of formatted line */
1458
1459
1460  /*
1461   * Allocate the line buffer as needed...
1462   */
1463
1464   if (!log_linesize)
1465   {
1466     log_linesize = 8192;
1467     log_line     = malloc(log_linesize);
1468
1469     if (!log_line)
1470       return (-1);
1471   }
1472
1473  /*
1474   * Format the log message...
1475   */
1476
1477   len = _cups_safe_vsnprintf(log_line, log_linesize, message, ap);
1478
1479  /*
1480   * Resize the buffer as needed...
1481   */
1482
1483   if ((size_t)len >= log_linesize && log_linesize < 65536)
1484   {
1485     char        *temp;                  /* Temporary string pointer */
1486
1487     len ++;
1488
1489     if (len < 8192)
1490       len = 8192;
1491     else if (len > 65536)
1492       len = 65536;
1493
1494     temp = realloc(log_line, (size_t)len);
1495
1496     if (temp)
1497     {
1498       log_line     = temp;
1499       log_linesize = (size_t)len;
1500
1501       return (0);
1502     }
1503   }
1504
1505   return (1);
1506 }