scheduler/log.c

   1 /*
   2  * Log file routines for the CUPS scheduler.
   3  *
   4  * Copyright 2007-2016 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 && LogDebugHistory <= 0)
 586     return (1);
 587
 588 #ifdef HAVE_ASL_H
 589   if (!strcmp(ErrorLog, "syslog"))
 590   {
 591     asl_object_t        m;              /* Log message */
 592     char                job_id[32],     /* job-id string */
 593                         completed[32];  /* job-impressions-completed string */
 594     cupsd_printer_t *printer = job ? (job->printer ? job->printer : (job->dest ? cupsdFindDest(job->dest) : NULL)) : NULL;
 595     static const char * const job_states[] =
 596     {                                   /* job-state strings */
 597       "Pending",
 598       "PendingHeld",
 599       "Processing",
 600       "ProcessingStopped",
 601       "Canceled",
 602       "Aborted",
 603       "Completed"
 604     };
 605
 606     m = asl_new(ASL_TYPE_MSG);
 607     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
 608     if (printer)
 609       asl_set(m, PWG_ServiceURI, printer->uri);
 610     if (job)
 611     {
 612       snprintf(job_id, sizeof(job_id), "%d", job->id);
 613
 614       asl_set(m, PWG_Event, "JobStateChanged");
 615       asl_set(m, PWG_JobID, job_id);
 616       asl_set(m, PWG_JobState, job->state_value < IPP_JSTATE_PENDING ? "" : job_states[job->state_value - IPP_JSTATE_PENDING]);
 617
 618       if (job->impressions)
 619       {
 620         snprintf(completed, sizeof(completed), "%d", ippGetInteger(job->impressions, 0));
 621         asl_set(m, PWG_JobImpressionsCompleted, completed);
 622       }
 623     }
 624
 625     va_start(ap, message);
 626     asl_vlog(NULL, m, log_levels[level], message, ap);
 627     va_end(ap);
 628
 629     asl_release(m);
 630     return (1);
 631   }
 632
 633 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
 634   if (!strcmp(ErrorLog, "syslog"))
 635   {
 636     cupsd_printer_t *printer = job ? (job->printer ? job->printer : (job->dest ? cupsdFindDest(job->dest) : NULL)) : NULL;
 637     static const char * const job_states[] =
 638     {                                   /* job-state strings */
 639       "Pending",
 640       "PendingHeld",
 641       "Processing",
 642       "ProcessingStopped",
 643       "Canceled",
 644       "Aborted",
 645       "Completed"
 646     };
 647
 648     va_start(ap, message);
 649
 650     do
 651     {
 652       va_copy(ap2, ap);
 653       status = format_log_line(message, ap2);
 654       va_end(ap2);
 655     }
 656     while (status == 0);
 657
 658     va_end(ap);
 659
 660     if (job)
 661       sd_journal_send("MESSAGE=%s", log_line,
 662                       "PRIORITY=%i", log_levels[level],
 663                       PWG_Event"=JobStateChanged",
 664                       PWG_ServiceURI"=%s", printer ? printer->uri : "",
 665                       PWG_JobID"=%d", job->id,
 666                       PWG_JobState"=%s", job->state_value < IPP_JSTATE_PENDING ? "" : job_states[job->state_value - IPP_JSTATE_PENDING],
 667                       PWG_JobImpressionsCompleted"=%d", ippGetInteger(job->impressions, 0),
 668                       NULL);
 669     else
 670       sd_journal_send("MESSAGE=%s", log_line,
 671                       "PRIORITY=%i", log_levels[level],
 672                       NULL);
 673
 674     return (1);
 675   }
 676 #endif /* HAVE_ASL_H */
 677
 678  /*
 679   * Format and write the log message...
 680   */
 681
 682   if (job)
 683     snprintf(jobmsg, sizeof(jobmsg), "[Job %d] %s", job->id, message);
 684   else
 685     strlcpy(jobmsg, message, sizeof(jobmsg));
 686
 687   va_start(ap, message);
 688
 689   do
 690   {
 691     va_copy(ap2, ap);
 692     status = format_log_line(jobmsg, ap2);
 693     va_end(ap2);
 694   }
 695   while (status == 0);
 696
 697   va_end(ap);
 698
 699   if (status > 0)
 700   {
 701     if (job && level > LogLevel && LogDebugHistory > 0)
 702     {
 703      /*
 704       * Add message to the job history...
 705       */
 706
 707       cupsd_joblog_t *temp;             /* Copy of log message */
 708       size_t         log_len = strlen(log_line);
 709                                         /* Length of log message */
 710
 711       if ((temp = malloc(sizeof(cupsd_joblog_t) + log_len)) != NULL)
 712       {
 713         temp->time = time(NULL);
 714         memcpy(temp->message, log_line, log_len + 1);
 715       }
 716
 717       if (!job->history)
 718         job->history = cupsArrayNew(NULL, NULL);
 719
 720       if (job->history && temp)
 721       {
 722         cupsArrayAdd(job->history, temp);
 723
 724         if (cupsArrayCount(job->history) > LogDebugHistory)
 725         {
 726          /*
 727           * Remove excess messages...
 728           */
 729
 730           temp = cupsArrayFirst(job->history);
 731           cupsArrayRemove(job->history, temp);
 732           free(temp);
 733         }
 734       }
 735       else if (temp)
 736         free(temp);
 737
 738       return (1);
 739     }
 740     else if (level <= LogLevel)
 741       return (cupsdWriteErrorLog(level, log_line));
 742     else
 743       return (1);
 744   }
 745   else
 746     return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
 747                                "Unable to allocate memory for log line."));
 748 }
 749
 750
 751 /*
 752  * 'cupsdLogMessage()' - Log a message to the error log file.
 753  */
 754
 755 int                                     /* O - 1 on success, 0 on error */
 756 cupsdLogMessage(int        level,       /* I - Log level */
 757                 const char *message,    /* I - printf-style message string */
 758                 ...)                    /* I - Additional args as needed */
 759 {
 760   va_list               ap, ap2;        /* Argument pointers */
 761   int                   status;         /* Formatting status */
 762
 763
 764  /*
 765   * See if we want to log this message...
 766   */
 767
 768   if ((TestConfigFile || !ErrorLog) && level <= CUPSD_LOG_WARN)
 769   {
 770     va_start(ap, message);
 771
 772 #ifdef HAVE_ASL_H
 773     asl_object_t        m;              /* Log message */
 774
 775     m = asl_new(ASL_TYPE_MSG);
 776     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
 777     asl_vlog(NULL, m, log_levels[level], message, ap);
 778     asl_release(m);
 779
 780 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
 781     sd_journal_printv(log_levels[level], message, ap);
 782
 783 #elif defined(HAVE_VSYSLOG)
 784     vsyslog(LOG_LPR | log_levels[level], message, ap);
 785
 786 #else
 787     vfprintf(stderr, message, ap);
 788     putc('\n', stderr);
 789 #endif /* HAVE_VSYSLOG */
 790
 791     va_end(ap);
 792
 793     return (1);
 794   }
 795
 796   if (level > LogLevel || !ErrorLog)
 797     return (1);
 798
 799 #ifdef HAVE_ASL_H
 800   if (!strcmp(ErrorLog, "syslog"))
 801   {
 802     asl_object_t        m;              /* Log message */
 803
 804     m = asl_new(ASL_TYPE_MSG);
 805     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
 806
 807     va_start(ap, message);
 808     asl_vlog(NULL, m, log_levels[level], message, ap);
 809     va_end(ap);
 810
 811     asl_release(m);
 812     return (1);
 813   }
 814
 815 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
 816   if (!strcmp(ErrorLog, "syslog"))
 817   {
 818     va_start(ap, message);
 819     sd_journal_printv(log_levels[level], message, ap);
 820     va_end(ap);
 821     return (1);
 822   }
 823 #endif /* HAVE_ASL_H */
 824
 825  /*
 826   * Format and write the log message...
 827   */
 828
 829   va_start(ap, message);
 830
 831   do
 832   {
 833     va_copy(ap2, ap);
 834     status = format_log_line(message, ap2);
 835     va_end(ap2);
 836   }
 837   while (status == 0);
 838
 839   va_end(ap);
 840
 841   if (status > 0)
 842     return (cupsdWriteErrorLog(level, log_line));
 843   else
 844     return (cupsdWriteErrorLog(CUPSD_LOG_ERROR,
 845                                "Unable to allocate memory for log line!"));
 846 }
 847
 848
 849 /*
 850  * 'cupsdLogPage()' - Log a page to the page log file.
 851  */
 852
 853 int                                     /* O - 1 on success, 0 on error */
 854 cupsdLogPage(cupsd_job_t *job,          /* I - Job being printed */
 855              const char  *page)         /* I - Page being printed */
 856 {
 857   int                   i;              /* Looping var */
 858   char                  buffer[2048],   /* Buffer for page log */
 859                         *bufptr,        /* Pointer into buffer */
 860                         name[256];      /* Attribute name */
 861   const char            *format,        /* Pointer into PageLogFormat */
 862                         *nameend;       /* End of attribute name */
 863   ipp_attribute_t       *attr;          /* Current attribute */
 864   char                  number[256];    /* Page number */
 865   int                   copies;         /* Number of copies */
 866
 867
 868  /*
 869   * Format the line going into the page log...
 870   */
 871
 872   if (!PageLogFormat)
 873     return (1);
 874
 875   strlcpy(number, "1", sizeof(number));
 876   copies = 1;
 877   sscanf(page, "%255s%d", number, &copies);
 878
 879   for (format = PageLogFormat, bufptr = buffer; *format; format ++)
 880   {
 881     if (*format == '%')
 882     {
 883       format ++;
 884
 885       switch (*format)
 886       {
 887         case '%' :                      /* Literal % */
 888             if (bufptr < (buffer + sizeof(buffer) - 1))
 889               *bufptr++ = '%';
 890             break;
 891
 892         case 'p' :                      /* Printer name */
 893             strlcpy(bufptr, job->dest, sizeof(buffer) - (size_t)(bufptr - buffer));
 894             bufptr += strlen(bufptr);
 895             break;
 896
 897         case 'j' :                      /* Job ID */
 898             snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", job->id);
 899             bufptr += strlen(bufptr);
 900             break;
 901
 902         case 'u' :                      /* Username */
 903             strlcpy(bufptr, job->username ? job->username : "-", sizeof(buffer) - (size_t)(bufptr - buffer));
 904             bufptr += strlen(bufptr);
 905             break;
 906
 907         case 'T' :                      /* Date and time */
 908             strlcpy(bufptr, cupsdGetDateTime(NULL, LogTimeFormat), sizeof(buffer) - (size_t)(bufptr - buffer));
 909             bufptr += strlen(bufptr);
 910             break;
 911
 912         case 'P' :                      /* Page number */
 913             strlcpy(bufptr, number, sizeof(buffer) - (size_t)(bufptr - buffer));
 914             bufptr += strlen(bufptr);
 915             break;
 916
 917         case 'C' :                      /* Number of copies */
 918             snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", copies);
 919             bufptr += strlen(bufptr);
 920             break;
 921
 922         case '{' :                      /* {attribute} */
 923             if ((nameend = strchr(format, '}')) != NULL && (size_t)(nameend - format - 2) < (sizeof(name) - 1))
 924             {
 925              /*
 926               * Pull the name from inside the brackets...
 927               */
 928
 929               memcpy(name, format + 1, (size_t)(nameend - format - 1));
 930               name[nameend - format - 1] = '\0';
 931
 932               format = nameend;
 933
 934               attr = ippFindAttribute(job->attrs, name, IPP_TAG_ZERO);
 935               if (!attr && !strcmp(name, "job-billing"))
 936               {
 937                /*
 938                 * Handle alias "job-account-id" (which was standardized after
 939                 * "job-billing" was defined for CUPS...
 940                 */
 941
 942                 attr = ippFindAttribute(job->attrs, "job-account-id", IPP_TAG_ZERO);
 943               }
 944               else if (!attr && !strcmp(name, "media"))
 945               {
 946                /*
 947                 * Handle alias "media-col" which uses dimensions instead of
 948                 * names...
 949                 */
 950
 951                 attr = ippFindAttribute(job->attrs, "media-col/media-size", IPP_TAG_BEGIN_COLLECTION);
 952               }
 953
 954               if (attr)
 955               {
 956                /*
 957                 * Add the attribute value...
 958                 */
 959
 960                 for (i = 0;
 961                      i < attr->num_values &&
 962                          bufptr < (buffer + sizeof(buffer) - 1);
 963                      i ++)
 964                 {
 965                   if (i)
 966                     *bufptr++ = ',';
 967
 968                   switch (attr->value_tag)
 969                   {
 970                     case IPP_TAG_INTEGER :
 971                     case IPP_TAG_ENUM :
 972                         snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", attr->values[i].integer);
 973                         bufptr += strlen(bufptr);
 974                         break;
 975
 976                     case IPP_TAG_BOOLEAN :
 977                         snprintf(bufptr, sizeof(buffer) - (size_t)(bufptr - buffer), "%d", attr->values[i].boolean);
 978                         bufptr += strlen(bufptr);
 979                         break;
 980
 981                     case IPP_TAG_TEXTLANG :
 982                     case IPP_TAG_NAMELANG :
 983                     case IPP_TAG_TEXT :
 984                     case IPP_TAG_NAME :
 985                     case IPP_TAG_KEYWORD :
 986                     case IPP_TAG_URI :
 987                     case IPP_TAG_URISCHEME :
 988                     case IPP_TAG_CHARSET :
 989                     case IPP_TAG_LANGUAGE :
 990                     case IPP_TAG_MIMETYPE :
 991                         strlcpy(bufptr, attr->values[i].string.text, sizeof(buffer) - (size_t)(bufptr - buffer));
 992                         bufptr += strlen(bufptr);
 993                         break;
 994
 995                     case IPP_TAG_BEGIN_COLLECTION :
 996                         if (!strcmp(attr->name, "media-size"))
 997                         {
 998                           ipp_attribute_t *x_dimension = ippFindAttribute(ippGetCollection(attr, 0), "x-dimension", IPP_TAG_INTEGER);
 999                           ipp_attribute_t *y_dimension = ippFindAttribute(ippGetCollection(attr, 0), "y-dimension", IPP_TAG_INTEGER);
1000                                         /* Media dimensions */
1001
1002                           if (x_dimension && y_dimension)
1003                           {
1004                             pwg_media_t *pwg = pwgMediaForSize(ippGetInteger(x_dimension, 0), ippGetInteger(y_dimension, 0));
1005                                         /* PWG media name */
1006                             strlcpy(bufptr, pwg->pwg, sizeof(buffer) - (size_t)(bufptr - buffer));
1007                             break;
1008                           }
1009                         }
1010
1011                     default :
1012                         strlcpy(bufptr, "???", sizeof(buffer) - (size_t)(bufptr - buffer));
1013                         bufptr += strlen(bufptr);
1014                         break;
1015                   }
1016                 }
1017               }
1018               else if (bufptr < (buffer + sizeof(buffer) - 1))
1019                 *bufptr++ = '-';
1020               break;
1021             }
1022
1023         default :
1024             if (bufptr < (buffer + sizeof(buffer) - 2))
1025             {
1026               *bufptr++ = '%';
1027               *bufptr++ = *format;
1028             }
1029             break;
1030       }
1031     }
1032     else if (bufptr < (buffer + sizeof(buffer) - 1))
1033       *bufptr++ = *format;
1034   }
1035
1036   *bufptr = '\0';
1037
1038 #ifdef HAVE_ASL_H
1039   if (!strcmp(ErrorLog, "syslog"))
1040   {
1041     asl_object_t        m;              /* Log message */
1042     char                job_id[32],     /* job-id string */
1043                         completed[32];  /* job-impressions-completed string */
1044     static const char * const job_states[] =
1045     {                                   /* job-state strings */
1046       "Pending",
1047       "PendingHeld",
1048       "Processing",
1049       "ProcessingStopped",
1050       "Canceled",
1051       "Aborted",
1052       "Completed"
1053     };
1054
1055     snprintf(job_id, sizeof(job_id), "%d", job->id);
1056
1057     m = asl_new(ASL_TYPE_MSG);
1058     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
1059     asl_set(m, PWG_Event, "JobStateChanged");
1060     asl_set(m, PWG_ServiceURI, job->printer->uri);
1061     asl_set(m, PWG_JobID, job_id);
1062     asl_set(m, PWG_JobState, job_states[job->state_value - IPP_JSTATE_PENDING]);
1063
1064     if (job->impressions)
1065     {
1066       snprintf(completed, sizeof(completed), "%d", ippGetInteger(job->impressions, 0));
1067       asl_set(m, PWG_JobImpressionsCompleted, completed);
1068     }
1069
1070     asl_log(NULL, m, ASL_LEVEL_INFO, "%s", buffer);
1071
1072     asl_release(m);
1073     return (1);
1074   }
1075
1076 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
1077   if (!strcmp(ErrorLog, "syslog"))
1078   {
1079     static const char * const job_states[] =
1080     {                                   /* job-state strings */
1081       "Pending",
1082       "PendingHeld",
1083       "Processing",
1084       "ProcessingStopped",
1085       "Canceled",
1086       "Aborted",
1087       "Completed"
1088     };
1089
1090     sd_journal_send("MESSAGE=%s", buffer,
1091                     "PRIORITY=%i", LOG_INFO,
1092                     PWG_Event"=JobStateChanged",
1093                     PWG_ServiceURI"=%s", job->printer->uri,
1094                     PWG_JobID"=%d", job->id,
1095                     PWG_JobState"=%s", job_states[job->state_value - IPP_JSTATE_PENDING],
1096                     PWG_JobImpressionsCompleted"=%d", ippGetInteger(job->impressions, 0),
1097                     NULL);
1098     return (1);
1099   }
1100
1101 #elif defined(HAVE_VSYSLOG)
1102  /*
1103   * See if we are logging pages via syslog...
1104   */
1105
1106   if (!strcmp(PageLog, "syslog"))
1107   {
1108     syslog(LOG_INFO, "%s", buffer);
1109
1110     return (1);
1111   }
1112 #endif /* HAVE_ASL_H */
1113
1114  /*
1115   * Not using syslog; check the log file...
1116   */
1117
1118   if (!cupsdCheckLogFile(&PageFile, PageLog))
1119     return (0);
1120
1121  /*
1122   * Print a page log entry of the form:
1123   *
1124   *    printer user job-id [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \
1125   *        billing hostname
1126   */
1127
1128   cupsFilePrintf(PageFile, "%s\n", buffer);
1129   cupsFileFlush(PageFile);
1130
1131   return (1);
1132 }
1133
1134
1135 /*
1136  * 'cupsdLogRequest()' - Log an HTTP request in Common Log Format.
1137  */
1138
1139 int                                     /* O - 1 on success, 0 on error */
1140 cupsdLogRequest(cupsd_client_t *con,    /* I - Request to log */
1141                 http_status_t  code)    /* I - Response code */
1142 {
1143   char  temp[2048];                     /* Temporary string for URI */
1144   static const char * const states[] =  /* HTTP client states... */
1145                 {
1146                   "WAITING",
1147                   "OPTIONS",
1148                   "GET",
1149                   "GET",
1150                   "HEAD",
1151                   "POST",
1152                   "POST",
1153                   "POST",
1154                   "PUT",
1155                   "PUT",
1156                   "DELETE",
1157                   "TRACE",
1158                   "CLOSE",
1159                   "STATUS"
1160                 };
1161
1162
1163  /*
1164   * Filter requests as needed...
1165   */
1166
1167   if (AccessLogLevel == CUPSD_ACCESSLOG_NONE)
1168     return (1);
1169   else if (AccessLogLevel < CUPSD_ACCESSLOG_ALL)
1170   {
1171    /*
1172     * Eliminate simple GET, POST, and PUT requests...
1173     */
1174
1175     if ((con->operation == HTTP_GET &&
1176          strncmp(con->uri, "/admin/conf", 11) &&
1177          strncmp(con->uri, "/admin/log", 10)) ||
1178         (con->operation == HTTP_POST && !con->request &&
1179          strncmp(con->uri, "/admin", 6)) ||
1180         (con->operation != HTTP_GET && con->operation != HTTP_POST &&
1181          con->operation != HTTP_PUT))
1182       return (1);
1183
1184     if (con->request && con->response &&
1185         (con->response->request.status.status_code < IPP_REDIRECTION_OTHER_SITE ||
1186          con->response->request.status.status_code == IPP_NOT_FOUND))
1187     {
1188      /*
1189       * Check successful requests...
1190       */
1191
1192       ipp_op_t op = con->request->request.op.operation_id;
1193       static cupsd_accesslog_t standard_ops[] =
1194       {
1195         CUPSD_ACCESSLOG_ALL,    /* reserved */
1196         CUPSD_ACCESSLOG_ALL,    /* reserved */
1197         CUPSD_ACCESSLOG_ACTIONS,/* Print-Job */
1198         CUPSD_ACCESSLOG_ACTIONS,/* Print-URI */
1199         CUPSD_ACCESSLOG_ACTIONS,/* Validate-Job */
1200         CUPSD_ACCESSLOG_ACTIONS,/* Create-Job */
1201         CUPSD_ACCESSLOG_ACTIONS,/* Send-Document */
1202         CUPSD_ACCESSLOG_ACTIONS,/* Send-URI */
1203         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Job */
1204         CUPSD_ACCESSLOG_ALL,    /* Get-Job-Attributes */
1205         CUPSD_ACCESSLOG_ALL,    /* Get-Jobs */
1206         CUPSD_ACCESSLOG_ALL,    /* Get-Printer-Attributes */
1207         CUPSD_ACCESSLOG_ACTIONS,/* Hold-Job */
1208         CUPSD_ACCESSLOG_ACTIONS,/* Release-Job */
1209         CUPSD_ACCESSLOG_ACTIONS,/* Restart-Job */
1210         CUPSD_ACCESSLOG_ALL,    /* reserved */
1211         CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer */
1212         CUPSD_ACCESSLOG_CONFIG, /* Resume-Printer */
1213         CUPSD_ACCESSLOG_CONFIG, /* Purge-Jobs */
1214         CUPSD_ACCESSLOG_CONFIG, /* Set-Printer-Attributes */
1215         CUPSD_ACCESSLOG_ACTIONS,/* Set-Job-Attributes */
1216         CUPSD_ACCESSLOG_CONFIG, /* Get-Printer-Supported-Values */
1217         CUPSD_ACCESSLOG_ACTIONS,/* Create-Printer-Subscription */
1218         CUPSD_ACCESSLOG_ACTIONS,/* Create-Job-Subscription */
1219         CUPSD_ACCESSLOG_ALL,    /* Get-Subscription-Attributes */
1220         CUPSD_ACCESSLOG_ALL,    /* Get-Subscriptions */
1221         CUPSD_ACCESSLOG_ACTIONS,/* Renew-Subscription */
1222         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Subscription */
1223         CUPSD_ACCESSLOG_ALL,    /* Get-Notifications */
1224         CUPSD_ACCESSLOG_ACTIONS,/* Send-Notifications */
1225         CUPSD_ACCESSLOG_ALL,    /* reserved */
1226         CUPSD_ACCESSLOG_ALL,    /* reserved */
1227         CUPSD_ACCESSLOG_ALL,    /* reserved */
1228         CUPSD_ACCESSLOG_ALL,    /* Get-Print-Support-Files */
1229         CUPSD_ACCESSLOG_CONFIG, /* Enable-Printer */
1230         CUPSD_ACCESSLOG_CONFIG, /* Disable-Printer */
1231         CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer-After-Current-Job */
1232         CUPSD_ACCESSLOG_ACTIONS,/* Hold-New-Jobs */
1233         CUPSD_ACCESSLOG_ACTIONS,/* Release-Held-New-Jobs */
1234         CUPSD_ACCESSLOG_CONFIG, /* Deactivate-Printer */
1235         CUPSD_ACCESSLOG_CONFIG, /* Activate-Printer */
1236         CUPSD_ACCESSLOG_CONFIG, /* Restart-Printer */
1237         CUPSD_ACCESSLOG_CONFIG, /* Shutdown-Printer */
1238         CUPSD_ACCESSLOG_CONFIG, /* Startup-Printer */
1239         CUPSD_ACCESSLOG_ACTIONS,/* Reprocess-Job */
1240         CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Current-Job */
1241         CUPSD_ACCESSLOG_ACTIONS,/* Suspend-Current-Job */
1242         CUPSD_ACCESSLOG_ACTIONS,/* Resume-Job */
1243         CUPSD_ACCESSLOG_ACTIONS,/* Promote-Job */
1244         CUPSD_ACCESSLOG_ACTIONS /* Schedule-Job-After */
1245       };
1246       static cupsd_accesslog_t cups_ops[] =
1247       {
1248         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Default */
1249         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Printers */
1250         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Printer */
1251         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Printer */
1252         CUPSD_ACCESSLOG_ALL,    /* CUPS-Get-Classes */
1253         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Class */
1254         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Class */
1255         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Accept-Jobs */
1256         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Reject-Jobs */
1257         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Set-Default */
1258         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-Devices */
1259         CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-PPDs */
1260         CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Move-Job */
1261         CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Authenticate-Job */
1262         CUPSD_ACCESSLOG_ALL     /* CUPS-Get-PPD */
1263       };
1264
1265
1266       if ((op <= IPP_SCHEDULE_JOB_AFTER && standard_ops[op] > AccessLogLevel) ||
1267           (op >= CUPS_GET_DEFAULT && op <= CUPS_GET_PPD &&
1268            cups_ops[op - CUPS_GET_DEFAULT] > AccessLogLevel))
1269         return (1);
1270     }
1271   }
1272
1273 #ifdef HAVE_ASL_H
1274   if (!strcmp(ErrorLog, "syslog"))
1275   {
1276     asl_object_t        m;              /* Log message */
1277
1278     m = asl_new(ASL_TYPE_MSG);
1279     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
1280
1281     asl_log(NULL, m, ASL_LEVEL_INFO, "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
1282            con->http->hostname, con->username[0] != '\0' ? con->username : "-",
1283            states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)),
1284            con->http->version / 100, con->http->version % 100,
1285            code, CUPS_LLCAST con->bytes,
1286            con->request ?
1287                ippOpString(con->request->request.op.operation_id) : "-",
1288            con->response ?
1289                ippErrorString(con->response->request.status.status_code) : "-");
1290
1291     asl_release(m);
1292     return (1);
1293   }
1294
1295 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
1296   if (!strcmp(ErrorLog, "syslog"))
1297   {
1298     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) : "-");
1299     return (1);
1300   }
1301
1302 #elif defined(HAVE_VSYSLOG)
1303  /*
1304   * See if we are logging accesses via syslog...
1305   */
1306
1307   if (!strcmp(AccessLog, "syslog"))
1308   {
1309     syslog(LOG_INFO,
1310            "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
1311            con->http->hostname, con->username[0] != '\0' ? con->username : "-",
1312            states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)),
1313            con->http->version / 100, con->http->version % 100,
1314            code, CUPS_LLCAST con->bytes,
1315            con->request ?
1316                ippOpString(con->request->request.op.operation_id) : "-",
1317            con->response ?
1318                ippErrorString(con->response->request.status.status_code) : "-");
1319
1320     return (1);
1321   }
1322 #endif /* HAVE_ASL_H */
1323
1324  /*
1325   * Not using syslog; check the log file...
1326   */
1327
1328   if (!cupsdCheckLogFile(&AccessFile, AccessLog))
1329     return (0);
1330
1331  /*
1332   * Write a log of the request in "common log format"...
1333   */
1334
1335   cupsFilePrintf(AccessFile,
1336                  "%s - %s %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
1337                  con->http->hostname,
1338                  con->username[0] != '\0' ? con->username : "-",
1339                  cupsdGetDateTime(&(con->start), LogTimeFormat),
1340                  states[con->operation],
1341                  _httpEncodeURI(temp, con->uri, sizeof(temp)),
1342                  con->http->version / 100, con->http->version % 100,
1343                  code, CUPS_LLCAST con->bytes,
1344                  con->request ?
1345                      ippOpString(con->request->request.op.operation_id) : "-",
1346                  con->response ?
1347                      ippErrorString(con->response->request.status.status_code) :
1348                      "-");
1349
1350   cupsFileFlush(AccessFile);
1351
1352   return (1);
1353 }
1354
1355
1356 /*
1357  * 'cupsdWriteErrorLog()' - Write a line to the ErrorLog.
1358  */
1359
1360 int                                     /* O - 1 on success, 0 on failure */
1361 cupsdWriteErrorLog(int        level,    /* I - Log level */
1362                    const char *message) /* I - Message string */
1363 {
1364   int           ret = 1;                /* Return value */
1365   static const char     levels[] =      /* Log levels... */
1366                 {
1367                   ' ',
1368                   'X',
1369                   'A',
1370                   'C',
1371                   'E',
1372                   'W',
1373                   'N',
1374                   'I',
1375                   'D',
1376                   'd'
1377                 };
1378
1379
1380 #ifdef HAVE_ASL_H
1381   if (!strcmp(ErrorLog, "syslog"))
1382   {
1383     asl_object_t        m;              /* Log message */
1384
1385     m = asl_new(ASL_TYPE_MSG);
1386     asl_set(m, ASL_KEY_FACILITY, "org.cups.cupsd");
1387     asl_log(NULL, m, ASL_LEVEL_INFO, "%s", message);
1388
1389     asl_release(m);
1390     return (1);
1391   }
1392
1393 #elif defined(HAVE_SYSTEMD_SD_JOURNAL_H)
1394   if (!strcmp(ErrorLog, "syslog"))
1395   {
1396     sd_journal_print(log_levels[level], "%s", message);
1397     return (1);
1398   }
1399
1400 #elif defined(HAVE_VSYSLOG)
1401  /*
1402   * See if we are logging errors via syslog...
1403   */
1404
1405   if (!strcmp(ErrorLog, "syslog"))
1406   {
1407     syslog(log_levels[level], "%s", message);
1408     return (1);
1409   }
1410 #endif /* HAVE_ASL_H */
1411
1412  /*
1413   * Not using syslog; check the log file...
1414   */
1415
1416   _cupsMutexLock(&log_mutex);
1417
1418   if (!cupsdCheckLogFile(&ErrorFile, ErrorLog))
1419   {
1420     ret = 0;
1421   }
1422   else
1423   {
1424    /*
1425     * Write the log message...
1426     */
1427
1428     cupsFilePrintf(ErrorFile, "%c %s %s\n", levels[level],
1429                    cupsdGetDateTime(NULL, LogTimeFormat), message);
1430     cupsFileFlush(ErrorFile);
1431   }
1432
1433   _cupsMutexUnlock(&log_mutex);
1434
1435   return (ret);
1436 }
1437
1438
1439 /*
1440  * 'format_log_line()' - Format a line for a log file.
1441  *
1442  * This function resizes a global string buffer as needed.  Each call returns
1443  * a pointer to this buffer, so the contents are only good until the next call
1444  * to format_log_line()...
1445  */
1446
1447 static int                              /* O - -1 for fatal, 0 for retry, 1 for success */
1448 format_log_line(const char *message,    /* I - Printf-style format string */
1449                 va_list    ap)          /* I - Argument list */
1450 {
1451   ssize_t       len;                    /* Length of formatted line */
1452
1453
1454  /*
1455   * Allocate the line buffer as needed...
1456   */
1457
1458   if (!log_linesize)
1459   {
1460     log_linesize = 8192;
1461     log_line     = malloc(log_linesize);
1462
1463     if (!log_line)
1464       return (-1);
1465   }
1466
1467  /*
1468   * Format the log message...
1469   */
1470
1471   len = _cups_safe_vsnprintf(log_line, log_linesize, message, ap);
1472
1473  /*
1474   * Resize the buffer as needed...
1475   */
1476
1477   if ((size_t)len >= log_linesize && log_linesize < 65536)
1478   {
1479     char        *temp;                  /* Temporary string pointer */
1480
1481     len ++;
1482
1483     if (len < 8192)
1484       len = 8192;
1485     else if (len > 65536)
1486       len = 65536;
1487
1488     temp = realloc(log_line, (size_t)len);
1489
1490     if (temp)
1491     {
1492       log_line     = temp;
1493       log_linesize = (size_t)len;
1494
1495       return (0);
1496     }
1497   }
1498
1499   return (1);
1500 }