]> git.ipfire.org Git - thirdparty/cups.git/blobdiff - scheduler/job.c
Fix an issue with and time values (Issue #5538)
[thirdparty/cups.git] / scheduler / job.c
index 1edf585e1caf62d1f1365d78adb979d145393dec..4f041388c47c9949b2dc5f26627984d4d5a68dd4 100644 (file)
@@ -1,16 +1,14 @@
 /*
- * "$Id$"
- *
  * Job management routines for the CUPS scheduler.
  *
- * Copyright 2007-2015 by Apple Inc.
+ * Copyright 2007-2019 by Apple Inc.
  * Copyright 1997-2007 by Easy Software Products, all rights reserved.
  *
  * These coded instructions, statements, and computer programs are the
  * property of Apple Inc. and are protected by Federal copyright
  * law.  Distribution and use rights are outlined in the file "LICENSE.txt"
  * which should have been included with this file.  If this file is
- * file is missing or damaged, see the license at "http://www.cups.org/".
+ * missing or damaged, see the license at "http://www.cups.org/".
  */
 
 /*
@@ -213,8 +211,6 @@ cupsdCancelJobs(const char *dest,   /* I - Destination to cancel */
                         "Job canceled by user.");
     }
   }
-
-  cupsdCheckJobs();
 }
 
 
@@ -231,6 +227,7 @@ cupsdCheckJobs(void)
                        *pclass;        /* Printer class destination */
   ipp_attribute_t      *attr;          /* Job attribute */
   time_t               curtime;        /* Current time */
+  const char           *reasons;       /* job-state-reasons value */
 
 
   curtime = time(NULL);
@@ -324,6 +321,25 @@ cupsdCheckJobs(void)
        ((FilterLevel + job->pending_cost) < FilterLimit || FilterLevel == 0))
       cupsdContinueJob(job);
 
+   /*
+    * Skip jobs that where held-on-create
+    */
+
+    reasons = ippGetString(job->reasons, 0, NULL);
+    if (reasons && !strcmp(reasons, "job-held-on-create"))
+    {
+     /*
+      * Check whether the printer is still holding new jobs...
+      */
+
+      printer = cupsdFindDest(job->dest);
+
+      if (printer->holding_new_jobs)
+        continue;
+
+      ippSetString(job->attrs, &job->reasons, 0, "none");
+    }
+
    /*
     * Start pending jobs if the destination is available...
     */
@@ -361,7 +377,7 @@ cupsdCheckJobs(void)
                         "Job aborted because the destination printer/class "
                         "has gone away.");
       }
-      else if (printer && !printer->holding_new_jobs)
+      else if (printer)
       {
        /*
         * See if the printer is available or remote and not printing a job;
@@ -371,16 +387,14 @@ cupsdCheckJobs(void)
         if (pclass)
        {
         /*
-         * Add/update a job-actual-printer-uri attribute for this job
+         * Add/update a job-printer-uri-actual attribute for this job
          * so that we know which printer actually printed the job...
          */
 
-          if ((attr = ippFindAttribute(job->attrs, "job-actual-printer-uri",
-                                      IPP_TAG_URI)) != NULL)
-            cupsdSetString(&attr->values[0].string.text, printer->uri);
+          if ((attr = ippFindAttribute(job->attrs, "job-printer-uri-actual", IPP_TAG_URI)) != NULL)
+            ippSetString(job->attrs, &attr, 0, printer->uri);
          else
-           ippAddString(job->attrs, IPP_TAG_JOB, IPP_TAG_URI,
-                        "job-actual-printer-uri", NULL, printer->uri);
+           ippAddString(job->attrs, IPP_TAG_JOB, IPP_TAG_URI, "job-printer-uri-actual", NULL, printer->uri);
 
           job->dirty = 1;
           cupsdMarkDirty(CUPSD_DIRTY_JOBS);
@@ -392,7 +406,9 @@ cupsdCheckJobs(void)
          * Start the job...
          */
 
+         cupsArraySave(ActiveJobs);
          start_job(job, printer);
+         cupsArrayRestore(ActiveJobs);
        }
       }
     }
@@ -421,10 +437,20 @@ cupsdCleanJobs(void)
   curtime          = time(NULL);
   JobHistoryUpdate = 0;
 
+  cupsdLogMessage(CUPSD_LOG_DEBUG2, "cupsdCleanJobs: curtime=%d", (int)curtime);
+
   for (job = (cupsd_job_t *)cupsArrayFirst(Jobs);
        job;
        job = (cupsd_job_t *)cupsArrayNext(Jobs))
   {
+    cupsdLogMessage(CUPSD_LOG_DEBUG2, "cupsdCleanJobs: Job %d, state=%d, printer=%p, history_time=%d, file_time=%d", job->id, (int)job->state_value, (void *)job->printer, (int)job->history_time, (int)job->file_time);
+
+    if ((job->history_time && job->history_time) < JobHistoryUpdate || !JobHistoryUpdate)
+      JobHistoryUpdate = job->history_time;
+
+    if ((job->file_time && job->file_time < JobHistoryUpdate) || !JobHistoryUpdate)
+      JobHistoryUpdate = job->file_time;
+
     if (job->state_value >= IPP_JOB_CANCELED && !job->printer)
     {
      /*
@@ -442,16 +468,7 @@ cupsdCleanJobs(void)
         cupsdLogJob(job, CUPSD_LOG_DEBUG, "Removing document files.");
         remove_job_files(job);
 
-        if (job->history_time < JobHistoryUpdate || !JobHistoryUpdate)
-         JobHistoryUpdate = job->history_time;
-      }
-      else
-      {
-        if (job->history_time < JobHistoryUpdate || !JobHistoryUpdate)
-         JobHistoryUpdate = job->history_time;
-
-       if (job->file_time < JobHistoryUpdate || !JobHistoryUpdate)
-         JobHistoryUpdate = job->file_time;
+        cupsdMarkDirty(CUPSD_DIRTY_JOBS);
       }
     }
   }
@@ -730,8 +747,8 @@ cupsdContinueJob(cupsd_job_t *job)  /* I - Job */
   * Add decompression/raw filter as needed...
   */
 
-  if (job->compressions[job->current_file] &&
-      (!job->printer->remote || job->num_files == 1))
+  if ((job->compressions[job->current_file] && (!job->printer->remote || job->num_files == 1)) ||
+      (!job->printer->remote && job->printer->raw && job->num_files > 1))
   {
    /*
     * Add gziptoany filter to the front of the list...
@@ -1710,7 +1727,7 @@ cupsdLoadJob(cupsd_job_t *job)            /* I - Job */
     job->completed_time = attr->values[0].integer;
 
     if (JobHistory < INT_MAX)
-      job->history_time = attr->values[0].integer + JobHistory;
+      job->history_time = job->completed_time + JobHistory;
     else
       job->history_time = INT_MAX;
 
@@ -1721,10 +1738,12 @@ cupsdLoadJob(cupsd_job_t *job)          /* I - Job */
       JobHistoryUpdate = job->history_time;
 
     if (JobFiles < INT_MAX)
-      job->file_time = attr->values[0].integer + JobFiles;
+      job->file_time = job->completed_time + JobFiles;
     else
       job->file_time = INT_MAX;
 
+    cupsdLogJob(job, CUPSD_LOG_DEBUG2, "cupsdLoadJob: job->file_time=%ld, time-at-completed=%ld, JobFiles=%d", (long)job->file_time, (long)attr->values[0].integer, JobFiles);
+
     if (job->file_time < JobHistoryUpdate || !JobHistoryUpdate)
       JobHistoryUpdate = job->file_time;
 
@@ -1823,9 +1842,14 @@ cupsdLoadJob(cupsd_job_t *job)           /* I - Job */
       ippSetString(job->attrs, &job->reasons, 0, "none");
   }
 
-  job->sheets     = ippFindAttribute(job->attrs, "job-media-sheets-completed",
-                                     IPP_TAG_INTEGER);
-  job->job_sheets = ippFindAttribute(job->attrs, "job-sheets", IPP_TAG_NAME);
+  job->impressions = ippFindAttribute(job->attrs, "job-impressions-completed", IPP_TAG_INTEGER);
+  job->sheets      = ippFindAttribute(job->attrs, "job-media-sheets-completed", IPP_TAG_INTEGER);
+  job->job_sheets  = ippFindAttribute(job->attrs, "job-sheets", IPP_TAG_NAME);
+
+  if (!job->impressions)
+    job->impressions = ippAddInteger(job->attrs, IPP_TAG_JOB, IPP_TAG_INTEGER, "job-impressions-completed", 0);
+  if (!job->sheets)
+    job->sheets = ippAddInteger(job->attrs, IPP_TAG_JOB, IPP_TAG_INTEGER, "job-media-sheets-completed", 0);
 
   if (!job->priority)
   {
@@ -2096,7 +2120,7 @@ cupsdMoveJob(cupsd_job_t     *job,        /* I - Job */
 
   if ((attr = ippFindAttribute(job->attrs, "job-printer-uri",
                                IPP_TAG_URI)) != NULL)
-    cupsdSetString(&(attr->values[0].string.text), p->uri);
+    ippSetString(job->attrs, &attr, 0, p->uri);
 
   cupsdAddEvent(CUPSD_EVENT_JOB_STOPPED, p, job,
                 "Job #%d moved from %s to %s.", job->id, olddest,
@@ -2190,6 +2214,15 @@ cupsdSaveAllJobs(void)
        job;
        job = (cupsd_job_t *)cupsArrayNext(Jobs))
   {
+    if (job->printer && job->printer->temporary)
+    {
+     /*
+      * Don't save jobs on temporary printers...
+      */
+
+      continue;
+    }
+
     cupsFilePrintf(fp, "<Job %d>\n", job->id);
     cupsFilePrintf(fp, "State %d\n", job->state_value);
     cupsFilePrintf(fp, "Created %ld\n", (long)job->creation_time);
@@ -2229,6 +2262,16 @@ cupsdSaveJob(cupsd_job_t *job)           /* I - Job */
   cupsdLogMessage(CUPSD_LOG_DEBUG2, "cupsdSaveJob(job=%p(%d)): job->attrs=%p",
                   job, job->id, job->attrs);
 
+  if (job->printer && job->printer->temporary)
+  {
+   /*
+    * Don't save jobs on temporary printers...
+    */
+
+    job->dirty = 0;
+    return;
+  }
+
   snprintf(filename, sizeof(filename), "%s/c%05d", RequestRoot, job->id);
 
   if ((fp = cupsdCreateConfFile(filename, ConfigFilePerm & 0600)) == NULL)
@@ -2293,7 +2336,7 @@ cupsdSetJobHoldUntil(cupsd_job_t *job,    /* I - Job */
       attr = ippFindAttribute(job->attrs, "job-hold-until", IPP_TAG_NAME);
 
     if (attr)
-      cupsdSetString(&(attr->values[0].string.text), when);
+      ippSetString(job->attrs, &attr, 0, when);
     else
       attr = ippAddString(job->attrs, IPP_TAG_JOB, IPP_TAG_KEYWORD,
                           "job-hold-until", NULL, when);
@@ -2311,7 +2354,10 @@ cupsdSetJobHoldUntil(cupsd_job_t *job,   /* I - Job */
 
   }
 
-  ippSetString(job->attrs, &job->reasons, 0, "job-hold-until-specified");
+  if (strcmp(when, "no-hold"))
+    ippSetString(job->attrs, &job->reasons, 0, "job-hold-until-specified");
+  else
+    ippSetString(job->attrs, &job->reasons, 0, "none");
 
  /*
   * Update the hold time...
@@ -2548,8 +2594,8 @@ cupsdSetJobState(
 
        if (attr)
        {
-         attr->value_tag = IPP_TAG_KEYWORD;
-         cupsdSetString(&(attr->values[0].string.text), "no-hold");
+         ippSetValueTag(job->attrs, &attr, IPP_TAG_KEYWORD);
+         ippSetString(job->attrs, &attr, 0, "no-hold");
        }
 
     default :
@@ -2722,7 +2768,7 @@ cupsdSetJobState(
   * Update the server "busy" state...
   */
 
-  cupsdSetBusyState();
+  cupsdSetBusyState(0);
 }
 
 
@@ -2781,7 +2827,8 @@ cupsdUnloadCompletedJobs(void)
       if (job->dirty)
         cupsdSaveJob(job);
 
-      unload_job(job);
+      if (!job->dirty)
+        unload_job(job);
     }
 }
 
@@ -2813,8 +2860,10 @@ cupsdUpdateJobs(void)
       * Update history/file expiration times...
       */
 
+      job->completed_time = attr->values[0].integer;
+
       if (JobHistory < INT_MAX)
-       job->history_time = attr->values[0].integer + JobHistory;
+       job->history_time = job->completed_time + JobHistory;
       else
        job->history_time = INT_MAX;
 
@@ -2828,16 +2877,18 @@ cupsdUpdateJobs(void)
        JobHistoryUpdate = job->history_time;
 
       if (JobFiles < INT_MAX)
-       job->file_time = attr->values[0].integer + JobFiles;
+       job->file_time = job->completed_time + JobFiles;
       else
        job->file_time = INT_MAX;
 
+      cupsdLogJob(job, CUPSD_LOG_DEBUG2, "cupsdUpdateJobs: job->file_time=%ld, time-at-completed=%ld, JobFiles=%d", (long)job->file_time, (long)attr->values[0].integer, JobFiles);
+
       if (job->file_time < JobHistoryUpdate || !JobHistoryUpdate)
        JobHistoryUpdate = job->file_time;
     }
   }
 
-  cupsdLogMessage(CUPSD_LOG_DEBUG2, "cupsdUpdateAllJobs: JobHistoryUpdate=%ld",
+  cupsdLogMessage(CUPSD_LOG_DEBUG2, "cupsdUpdateJobs: JobHistoryUpdate=%ld",
                   (long)JobHistoryUpdate);
 }
 
@@ -3105,6 +3156,13 @@ finalize_job(cupsd_job_t *job,           /* I - Job */
   cupsdStatBufDelete(job->status_buffer);
   job->status_buffer = NULL;
 
+ /*
+  * Log the final impression (page) count...
+  */
+
+  snprintf(buffer, sizeof(buffer), "total %d", ippGetInteger(job->impressions, 0));
+  cupsdLogPage(job, buffer);
+
  /*
   * Process the exit status...
   */
@@ -3162,7 +3220,7 @@ finalize_job(cupsd_job_t *job,            /* I - Job */
 
    /*
     * Convert the status to an exit code.  Due to the way the W* macros are
-    * implemented on MacOS X (bug?), we have to store the exit status in a
+    * implemented on macOS (bug?), we have to store the exit status in a
     * variable first and then convert...
     */
 
@@ -3281,8 +3339,14 @@ finalize_job(cupsd_job_t *job,           /* I - Job */
                   job_state == IPP_JOB_COMPLETED)
          {
            job_state = IPP_JOB_ABORTED;
-           message   = "Job aborted due to backend errors; please consult "
-                       "the error_log file for details.";
+
+           if (ErrorLog)
+           {
+             snprintf(buffer, sizeof(buffer), "Job aborted due to backend errors; please consult the %s file for details.", ErrorLog);
+             message = buffer;
+            }
+            else
+             message = "Job aborted due to backend errors.";
 
            ippSetString(job->attrs, &job->reasons, 0, "aborted-by-system");
          }
@@ -3290,8 +3354,14 @@ finalize_job(cupsd_job_t *job,           /* I - Job */
           {
             job_state     = IPP_JOB_PENDING;
            printer_state = IPP_PRINTER_STOPPED;
-           message       = "Printer stopped due to backend errors; please "
-                           "consult the error_log file for details.";
+
+           if (ErrorLog)
+           {
+             snprintf(buffer, sizeof(buffer), "Printer stopped due to backend errors; please consult the %s file for details.", ErrorLog);
+             message = buffer;
+            }
+            else
+             message = "Printer stopped due to backend errors.";
 
            ippSetString(job->attrs, &job->reasons, 0, "none");
          }
@@ -3329,15 +3399,20 @@ finalize_job(cupsd_job_t *job,          /* I - Job */
 
              ippSetString(job->attrs, &job->reasons, 0,
                           "job-hold-until-specified");
-             message = "Job held indefinitely due to backend errors; please "
-                       "consult the error_log file for details.";
+
+             if (ErrorLog)
+             {
+               snprintf(buffer, sizeof(buffer), "Job held indefinitely due to backend errors; please consult the %s file for details.", ErrorLog);
+               message = buffer;
+             }
+             else
+               message = "Job held indefinitely due to backend errors.";
             }
             else if (!strcmp(reason, "account-info-needed"))
             {
              cupsdSetJobHoldUntil(job, "indefinite", 0);
 
-             message = "Job held indefinitely - account information is "
-                       "required.";
+             message = "Job held indefinitely - account information is required.";
             }
             else if (!strcmp(reason, "account-closed"))
             {
@@ -3349,8 +3424,7 @@ finalize_job(cupsd_job_t *job,            /* I - Job */
             {
              cupsdSetJobHoldUntil(job, "indefinite", 0);
 
-             message = "Job held indefinitely - account limit has been "
-                       "reached.";
+             message = "Job held indefinitely - account limit has been reached.";
            }
             else
             {
@@ -3368,16 +3442,27 @@ finalize_job(cupsd_job_t *job,          /* I - Job */
          * Stop the printer...
          */
 
+          if (job_state == IPP_JSTATE_CANCELED || job_state == IPP_JSTATE_ABORTED)
+          {
+            cupsdLogJob(job, CUPSD_LOG_INFO, "Ignored STOP from backend since the job is %s.", job_state == IPP_JSTATE_CANCELED ? "canceled" : "aborted");
+            break;
+         }
+
          printer_state = IPP_PRINTER_STOPPED;
-         message       = "Printer stopped due to backend errors; please "
-                         "consult the error_log file for details.";
+
+         if (ErrorLog)
+         {
+           snprintf(buffer, sizeof(buffer), "Printer stopped due to backend errors; please consult the %s file for details.", ErrorLog);
+           message = buffer;
+         }
+         else
+           message = "Printer stopped due to backend errors.";
 
          if (job_state == IPP_JOB_COMPLETED)
          {
            job_state = IPP_JOB_PENDING;
 
-           ippSetString(job->attrs, &job->reasons, 0,
-                        "resources-are-not-ready");
+           ippSetString(job->attrs, &job->reasons, 0, "resources-are-not-ready");
          }
           break;
 
@@ -3467,8 +3552,14 @@ finalize_job(cupsd_job_t *job,           /* I - Job */
     if (job_state == IPP_JOB_COMPLETED)
     {
       job_state = IPP_JOB_STOPPED;
-      message   = "Job stopped due to filter errors; please consult the "
-                 "error_log file for details.";
+
+      if (ErrorLog)
+      {
+       snprintf(buffer, sizeof(buffer), "Job stopped due to filter errors; please consult the %s file for details.", ErrorLog);
+       message = buffer;
+      }
+      else
+       message = "Job stopped due to filter errors.";
 
       if (WIFSIGNALED(job->status))
        ippSetString(job->attrs, &job->reasons, 0, "cups-filter-crashed");
@@ -3500,6 +3591,13 @@ finalize_job(cupsd_job_t *job,           /* I - Job */
 
   cupsArrayRemove(PrintingJobs, job);
 
+ /*
+  * Clear informational messages...
+  */
+
+  if (job->status_level > CUPSD_LOG_ERROR)
+    job->printer->state_message[0] = '\0';
+
  /*
   * Apply any PPD updates...
   */
@@ -3521,13 +3619,6 @@ finalize_job(cupsd_job_t *job,           /* I - Job */
 
   job->printer->job = NULL;
   job->printer      = NULL;
-
- /*
-  * Try printing another job...
-  */
-
-  if (printer_state != IPP_PRINTER_STOPPED)
-    cupsdCheckJobs();
 }
 
 
@@ -3575,12 +3666,9 @@ get_options(cupsd_job_t *job,            /* I - Job */
   pwgppds     = NULL;
 
   if (pc &&
-      !ippFindAttribute(job->attrs,
-                        "com.apple.print.DocumentTicket.PMSpoolFormat",
-                       IPP_TAG_ZERO) &&
+      !ippFindAttribute(job->attrs, "com.apple.print.DocumentTicket.PMSpoolFormat", IPP_TAG_ZERO) &&
       !ippFindAttribute(job->attrs, "APPrinterPreset", IPP_TAG_ZERO) &&
-      (ippFindAttribute(job->attrs, "print-color-mode", IPP_TAG_ZERO) ||
-       ippFindAttribute(job->attrs, "print-quality", IPP_TAG_ZERO)))
+      (ippFindAttribute(job->attrs, "print-color-mode", IPP_TAG_ZERO) || ippFindAttribute(job->attrs, "print-quality", IPP_TAG_ZERO) || ippFindAttribute(job->attrs, "cupsPrintQuality", IPP_TAG_ZERO)))
   {
    /*
     * Map print-color-mode and print-quality to a preset...
@@ -3593,13 +3681,36 @@ get_options(cupsd_job_t *job,           /* I - Job */
     else
       print_color_mode = _PWG_PRINT_COLOR_MODE_COLOR;
 
-    if ((attr = ippFindAttribute(job->attrs, "print-quality",
-                                IPP_TAG_ENUM)) != NULL &&
-       attr->values[0].integer >= IPP_QUALITY_DRAFT &&
-       attr->values[0].integer <= IPP_QUALITY_HIGH)
-      print_quality = attr->values[0].integer - IPP_QUALITY_DRAFT;
+    if ((attr = ippFindAttribute(job->attrs, "print-quality", IPP_TAG_ENUM)) != NULL)
+    {
+      ipp_quality_t pq = (ipp_quality_t)ippGetInteger(attr, 0);
+
+      if (pq >= IPP_QUALITY_DRAFT && pq <= IPP_QUALITY_HIGH)
+        print_quality = attr->values[0].integer - IPP_QUALITY_DRAFT;
+      else
+        print_quality = _PWG_PRINT_QUALITY_NORMAL;
+    }
+    else if ((attr = ippFindAttribute(job->attrs, "cupsPrintQuality", IPP_TAG_NAME)) != NULL)
+    {
+      const char *pq = ippGetString(attr, 0, NULL);
+
+      if (!_cups_strcasecmp(pq, "draft"))
+        print_quality = _PWG_PRINT_QUALITY_DRAFT;
+      else if (!_cups_strcasecmp(pq, "high"))
+        print_quality = _PWG_PRINT_QUALITY_HIGH;
+      else
+        print_quality = _PWG_PRINT_QUALITY_NORMAL;
+
+      if (!ippFindAttribute(job->attrs, "print-quality", IPP_TAG_ENUM))
+      {
+        cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Mapping cupsPrintQuality=%s to print-quality=%d", pq, print_quality + IPP_QUALITY_DRAFT);
+        num_pwgppds = cupsAddIntegerOption("print-quality", print_quality + IPP_QUALITY_DRAFT, num_pwgppds, &pwgppds);
+      }
+    }
     else
+    {
       print_quality = _PWG_PRINT_QUALITY_NORMAL;
+    }
 
     if (pc->num_presets[print_color_mode][print_quality] == 0)
     {
@@ -3632,14 +3743,30 @@ get_options(cupsd_job_t *job,           /* I - Job */
           i --, preset ++)
       {
         if (!ippFindAttribute(job->attrs, preset->name, IPP_TAG_ZERO))
-         num_pwgppds = cupsAddOption(preset->name, preset->value, num_pwgppds,
-                                     &pwgppds);
+        {
+          cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Adding preset option %s=%s", preset->name, preset->value);
+
+         num_pwgppds = cupsAddOption(preset->name, preset->value, num_pwgppds, &pwgppds);
+        }
       }
     }
   }
 
   if (pc)
   {
+    if ((attr = ippFindAttribute(job->attrs, "print-quality", IPP_TAG_ENUM)) != NULL)
+    {
+      int pq = ippGetInteger(attr, 0);
+      static const char * const pqs[] = { "Draft", "Normal", "High" };
+
+      if (pq >= IPP_QUALITY_DRAFT && pq <= IPP_QUALITY_HIGH)
+      {
+        cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Mapping print-quality=%d to cupsPrintQuality=%s", pq, pqs[pq - IPP_QUALITY_DRAFT]);
+
+        num_pwgppds = cupsAddOption("cupsPrintQuality", pqs[pq - IPP_QUALITY_DRAFT], num_pwgppds, &pwgppds);
+      }
+    }
+
     if (!ippFindAttribute(job->attrs, "InputSlot", IPP_TAG_ZERO) &&
        !ippFindAttribute(job->attrs, "HPPaperSource", IPP_TAG_ZERO))
     {
@@ -3649,16 +3776,26 @@ get_options(cupsd_job_t *job,           /* I - Job */
     }
     if (!ippFindAttribute(job->attrs, "MediaType", IPP_TAG_ZERO) &&
        (ppd = _ppdCacheGetMediaType(pc, job->attrs, NULL)) != NULL)
+    {
+      cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Mapping media to MediaType=%s", ppd);
+
       num_pwgppds = cupsAddOption("MediaType", ppd, num_pwgppds, &pwgppds);
+    }
 
     if (!ippFindAttribute(job->attrs, "PageRegion", IPP_TAG_ZERO) &&
        !ippFindAttribute(job->attrs, "PageSize", IPP_TAG_ZERO) &&
        (ppd = _ppdCacheGetPageSize(pc, job->attrs, NULL, &exact)) != NULL)
     {
+      cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Mapping media to Pagesize=%s", ppd);
+
       num_pwgppds = cupsAddOption("PageSize", ppd, num_pwgppds, &pwgppds);
 
       if (!ippFindAttribute(job->attrs, "media", IPP_TAG_ZERO))
+      {
+        cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Adding media=%s", ppd);
+
         num_pwgppds = cupsAddOption("media", ppd, num_pwgppds, &pwgppds);
+      }
     }
 
     if (!ippFindAttribute(job->attrs, "OutputBin", IPP_TAG_ZERO) &&
@@ -3672,6 +3809,8 @@ get_options(cupsd_job_t *job,             /* I - Job */
       * Map output-bin to OutputBin option...
       */
 
+      cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Mapping output-bin to OutputBin=%s", ppd);
+
       num_pwgppds = cupsAddOption("OutputBin", ppd, num_pwgppds, &pwgppds);
     }
 
@@ -3684,23 +3823,33 @@ get_options(cupsd_job_t *job,           /* I - Job */
       */
 
       if (!strcmp(attr->values[0].string.text, "one-sided"))
-        num_pwgppds = cupsAddOption(pc->sides_option, pc->sides_1sided,
-                                   num_pwgppds, &pwgppds);
+      {
+        cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Mapping sizes to Duplex=%s", pc->sides_1sided);
+
+        num_pwgppds = cupsAddOption(pc->sides_option, pc->sides_1sided, num_pwgppds, &pwgppds);
+      }
       else if (!strcmp(attr->values[0].string.text, "two-sided-long-edge"))
-        num_pwgppds = cupsAddOption(pc->sides_option, pc->sides_2sided_long,
-                                   num_pwgppds, &pwgppds);
+      {
+        cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Mapping sizes to Duplex=%s", pc->sides_2sided_long);
+
+        num_pwgppds = cupsAddOption(pc->sides_option, pc->sides_2sided_long, num_pwgppds, &pwgppds);
+      }
       else if (!strcmp(attr->values[0].string.text, "two-sided-short-edge"))
-        num_pwgppds = cupsAddOption(pc->sides_option, pc->sides_2sided_short,
-                                   num_pwgppds, &pwgppds);
+      {
+        cupsdLogJob(job, CUPSD_LOG_DEBUG2, "Mapping sizes to Duplex=%s", pc->sides_2sided_short);
+
+        num_pwgppds = cupsAddOption(pc->sides_option, pc->sides_2sided_short, num_pwgppds, &pwgppds);
+      }
     }
 
    /*
     * Map finishings values...
     */
 
-    num_pwgppds = _ppdCacheGetFinishingOptions(pc, job->attrs,
-                                               IPP_FINISHINGS_NONE, num_pwgppds,
-                                               &pwgppds);
+    num_pwgppds = _ppdCacheGetFinishingOptions(pc, job->attrs, IPP_FINISHINGS_NONE, num_pwgppds, &pwgppds);
+
+    for (i = num_pwgppds, pwgppd = pwgppds; i > 0; i --, pwgppd ++)
+      cupsdLogJob(job, CUPSD_LOG_DEBUG2, "After mapping finishings %s=%s", pwgppd->name, pwgppd->value);
   }
 
  /*
@@ -4115,7 +4264,15 @@ load_job_cache(const char *filename)     /* I - job.cache filename */
        {
          cupsdLogMessage(CUPSD_LOG_ERROR, "[Job %d] Files have gone away.",
                          jobid);
-         continue;
+
+         /*
+          * job.cache file is out-of-date compared to spool directory; load
+          * that instead...
+          */
+
+         cupsFileClose(fp);
+          load_request_root();
+          return;
        }
       }
 
@@ -4541,7 +4698,7 @@ set_time(cupsd_job_t *job,                /* I - Job to update */
     job->completed_time = curtime;
 
     if (JobHistory < INT_MAX && attr)
-      job->history_time = attr->values[0].integer + JobHistory;
+      job->history_time = job->completed_time + JobHistory;
     else
       job->history_time = INT_MAX;
 
@@ -4549,7 +4706,7 @@ set_time(cupsd_job_t *job,                /* I - Job to update */
       JobHistoryUpdate = job->history_time;
 
     if (JobFiles < INT_MAX && attr)
-      job->file_time = attr->values[0].integer + JobFiles;
+      job->file_time = job->completed_time + JobFiles;
     else
       job->file_time = INT_MAX;
 
@@ -4604,7 +4761,7 @@ start_job(cupsd_job_t     *job,           /* I - Job ID */
                                             "job-printer-state-message",
                                             IPP_TAG_TEXT);
   if (job->printer_message)
-    cupsdSetString(&(job->printer_message->values[0].string.text), "");
+    ippSetString(job->attrs, &job->printer_message, 0, "");
 
   ippSetString(job->attrs, &job->reasons, 0, "job-printing");
   cupsdSetJobState(job, IPP_JOB_PROCESSING, CUPSD_JOB_DEFAULT, NULL);
@@ -4659,6 +4816,18 @@ start_job(cupsd_job_t     *job,          /* I - Job ID */
   job->profile  = cupsdCreateProfile(job->id, 0);
   job->bprofile = cupsdCreateProfile(job->id, 1);
 
+#ifdef HAVE_SANDBOX_H
+  if ((!job->profile || !job->bprofile) && UseSandboxing && Sandboxing != CUPSD_SANDBOXING_OFF)
+  {
+   /*
+    * Failure to create the sandbox profile means something really bad has
+    * happened and we need to shutdown immediately.
+    */
+
+    return;
+  }
+#endif /* HAVE_SANDBOX_H */
+
  /*
   * Create the status pipes and buffer...
   */
@@ -4822,6 +4991,7 @@ unload_job(cupsd_job_t *job)              /* I - Job */
   job->attrs           = NULL;
   job->state           = NULL;
   job->reasons         = NULL;
+  job->impressions     = NULL;
   job->sheets          = NULL;
   job->job_sheets      = NULL;
   job->printer_message = NULL;
@@ -4837,12 +5007,13 @@ void
 update_job(cupsd_job_t *job)           /* I - Job to check */
 {
   int          i;                      /* Looping var */
-  int          copies;                 /* Number of copies printed */
   char         message[CUPSD_SB_BUFFER_SIZE],
                                        /* Message text */
                *ptr;                   /* Pointer update... */
   int          loglevel,               /* Log level for message */
                event = 0;              /* Events? */
+  cupsd_printer_t *printer = job->printer;
+                                       /* Printer */
   static const char * const levels[] = /* Log levels */
                {
                  "NONE",
@@ -4873,6 +5044,10 @@ update_job(cupsd_job_t *job)             /* I - Job to check */
 
     if (loglevel == CUPSD_LOG_PAGE)
     {
+      int      impressions = ippGetInteger(job->impressions, 0);
+                               /* Number of impressions printed */
+      int      delta;          /* Number of impressions added */
+
      /*
       * Page message; send the message to the page_log file and update the
       * job sheet count...
@@ -4880,31 +5055,57 @@ update_job(cupsd_job_t *job)            /* I - Job to check */
 
       cupsdLogJob(job, CUPSD_LOG_DEBUG, "PAGE: %s", message);
 
-      if (job->sheets)
+      if (!_cups_strncasecmp(message, "total ", 6))
       {
-        if (!_cups_strncasecmp(message, "total ", 6))
-       {
-        /*
-         * Got a total count of pages from a backend or filter...
-         */
+       /*
+       * Got a total count of pages from a backend or filter...
+       */
 
-         copies = atoi(message + 6);
-         copies -= job->sheets->values[0].integer; /* Just track the delta */
+       int total = atoi(message + 6);  /* Total impressions */
+
+       if (total > impressions)
+       {
+         delta       = total - impressions;
+         impressions = total;
        }
-       else if (!sscanf(message, "%*d%d", &copies))
-         copies = 1;
+       else
+         delta = 0;
+      }
+      else
+      {
+       /*
+        * Add the number of copies to the impression count...
+        */
+
+       int copies;                     /* Number of copies */
 
-        job->sheets->values[0].integer += copies;
+       if (!sscanf(message, "%*d%d", &copies) || copies <= 0)
+         copies = 1;
 
-       if (job->printer->page_limit)
-         cupsdUpdateQuota(job->printer, job->username, copies, 0);
+        delta = copies;
+       impressions += copies;
       }
 
-      cupsdLogPage(job, message);
+      if (job->impressions)
+        ippSetInteger(job->attrs, &job->impressions, 0, impressions);
 
       if (job->sheets)
-       cupsdAddEvent(CUPSD_EVENT_JOB_PROGRESS, job->printer, job,
-                     "Printed %d page(s).", job->sheets->values[0].integer);
+      {
+       const char *sides = ippGetString(ippFindAttribute(job->attrs, "sides", IPP_TAG_KEYWORD), 0, NULL);
+
+        if (sides && strcmp(sides, "one-sided"))
+          ippSetInteger(job->attrs, &job->sheets, 0, impressions / 2);
+       else
+          ippSetInteger(job->attrs, &job->sheets, 0, impressions);
+
+       cupsdAddEvent(CUPSD_EVENT_JOB_PROGRESS, job->printer, job, "Printed %d page(s).", ippGetInteger(job->sheets, 0));
+      }
+
+      job->dirty = 1;
+      cupsdMarkDirty(CUPSD_DIRTY_JOBS);
+
+      if (job->printer->page_limit)
+       cupsdUpdateQuota(job->printer, job->username, delta, 0);
     }
     else if (loglevel == CUPSD_LOG_JOBSTATE)
     {
@@ -4952,8 +5153,10 @@ update_job(cupsd_job_t *job)             /* I - Job to check */
 
             if (cancel_after)
              job->cancel_time = time(NULL) + ippGetInteger(cancel_after, 0);
-           else
+           else if (MaxJobTime > 0)
              job->cancel_time = time(NULL) + MaxJobTime;
+           else
+             job->cancel_time = 0;
          }
         }
       }
@@ -5115,7 +5318,7 @@ update_job(cupsd_job_t *job)              /* I - Job to check */
         ptr = message;
 
       if (*ptr)
-        cupsdLogJob(job, loglevel, "%s", ptr);
+        cupsdLogJob(job, loglevel == CUPSD_LOG_INFO ? CUPSD_LOG_DEBUG : loglevel, "%s", ptr);
 
       if (loglevel < CUPSD_LOG_DEBUG &&
           strcmp(job->printer->state_message, ptr))
@@ -5196,10 +5399,11 @@ update_job(cupsd_job_t *job)            /* I - Job to check */
     finalize_job(job, 1);
 
    /*
-    * Check for new jobs...
+    * Try printing another job...
     */
 
-    cupsdCheckJobs();
+    if (printer->state != IPP_PRINTER_STOPPED)
+      cupsdCheckJobs();
   }
 }
 
@@ -5244,15 +5448,14 @@ update_job_attrs(cupsd_job_t *job,      /* I - Job to update */
   if (job->state_value != IPP_JOB_PROCESSING &&
       job->status_level == CUPSD_LOG_INFO)
   {
-    cupsdSetString(&(job->printer_message->values[0].string.text), "");
+    ippSetString(job->attrs, &job->printer_message, 0, "");
 
     job->dirty = 1;
     cupsdMarkDirty(CUPSD_DIRTY_JOBS);
   }
   else if (job->printer->state_message[0] && do_message)
   {
-    cupsdSetString(&(job->printer_message->values[0].string.text),
-                  job->printer->state_message);
+    ippSetString(job->attrs, &job->printer_message, 0, job->printer->state_message);
 
     job->dirty = 1;
     cupsdMarkDirty(CUPSD_DIRTY_JOBS);
@@ -5317,8 +5520,3 @@ update_job_attrs(cupsd_job_t *job,        /* I - Job to update */
   job->dirty = 1;
   cupsdMarkDirty(CUPSD_DIRTY_JOBS);
 }
-
-
-/*
- * End of "$Id$".
- */