]> git.ipfire.org Git - thirdparty/cups.git/blobdiff - scheduler/job.c
Merge changes from CUPS 1.5svn-r9400
[thirdparty/cups.git] / scheduler / job.c
index 5adf0e050e50f3de252f0c208e8024683e14e314..94fc08844a5cfeeb4b36b1aa7fd5fb80a26ab635 100644 (file)
@@ -1,9 +1,9 @@
 /*
  * "$Id: job.c 7902 2008-09-03 14:20:17Z mike $"
  *
- *   Job management routines for the Common UNIX Printing System (CUPS).
+ *   Job management routines for the CUPS scheduler.
  *
- *   Copyright 2007-2009 by Apple Inc.
+ *   Copyright 2007-2010 by Apple Inc.
  *   Copyright 1997-2007 by Easy Software Products, all rights reserved.
  *
  *   These coded instructions, statements, and computer programs are the
@@ -45,6 +45,8 @@
  *   compare_active_jobs()      - Compare the job IDs and priorities of two
  *                                jobs.
  *   compare_jobs()             - Compare the job IDs of two jobs.
+ *   dump_job_history()         - Dump any debug messages for a job.
+ *   free_job_history()         - Free any log history.
  *   finalize_job()             - Cleanup after job filter processes and support
  *                                data.
  *   get_options()              - Get a string containing the job options.
@@ -165,11 +167,13 @@ static mime_filter_t      gziptoany_filter =
 
 static int     compare_active_jobs(void *first, void *second, void *data);
 static int     compare_jobs(void *first, void *second, void *data);
-static void    finalize_job(cupsd_job_t *job);
+static void    dump_job_history(cupsd_job_t *job);
+static void    finalize_job(cupsd_job_t *job, int set_job_state);
+static void    free_job_history(cupsd_job_t *job);
 static char    *get_options(cupsd_job_t *job, int banner_page, char *copies,
                             size_t copies_size, char *title,
                             size_t title_size);
-static int     ipp_length(ipp_t *ipp);
+static size_t  ipp_length(ipp_t *ipp);
 static void    load_job_cache(const char *filename);
 static void    load_next_job_id(const char *filename);
 static void    load_request_root(void);
@@ -249,7 +253,7 @@ cupsdCancelJobs(const char *dest,   /* I - Destination to cancel */
       if (purge)
        cupsdSetJobState(job, IPP_JOB_CANCELED, CUPSD_JOB_PURGE,
                         "Job purged by user.");
-      else
+      else if (job->state_value < IPP_JOB_CANCELED)
        cupsdSetJobState(job, IPP_JOB_CANCELED, CUPSD_JOB_DEFAULT,
                         "Job canceled by user.");
     }
@@ -271,23 +275,39 @@ cupsdCheckJobs(void)
   cupsd_printer_t      *printer,       /* Printer destination */
                        *pclass;        /* Printer class destination */
   ipp_attribute_t      *attr;          /* Job attribute */
+  time_t               curtime;        /* Current time */
 
 
   cupsdLogMessage(CUPSD_LOG_DEBUG2,
                   "cupsdCheckJobs: %d active jobs, sleeping=%d, reload=%d",
                   cupsArrayCount(ActiveJobs), Sleeping, NeedReload);
 
+  curtime = time(NULL);
+
   for (job = (cupsd_job_t *)cupsArrayFirst(ActiveJobs);
        job;
        job = (cupsd_job_t *)cupsArrayNext(ActiveJobs))
   {
+   /*
+    * Kill jobs if they are unresponsive...
+    */
+
+    if (job->kill_time && job->kill_time <= curtime)
+    {
+      cupsdLogMessage(CUPSD_LOG_ERROR, "[Job %d] Stopping unresponsive job!", 
+                     job->id);
+
+      stop_job(job, CUPSD_JOB_FORCE);
+      continue;
+    }
+
    /*
     * Start held jobs if they are ready...
     */
 
     if (job->state_value == IPP_JOB_HELD &&
         job->hold_until &&
-       job->hold_until < time(NULL))
+       job->hold_until < curtime)
     {
       if (job->pending_timeout)
       {
@@ -318,12 +338,20 @@ cupsdCheckJobs(void)
                        "Job submission timed out.");
     }
 
+   /*
+    * Continue jobs that are waiting on the FilterLimit...
+    */
+
+    if (job->pending_cost > 0 &&
+       ((FilterLevel + job->pending_cost) < FilterLimit || FilterLevel == 0))
+      cupsdContinueJob(job);
+
    /*
     * Start pending jobs if the destination is available...
     */
 
     if (job->state_value == IPP_JOB_PENDING && !NeedReload && !Sleeping &&
-        !job->printer)
+        !DoingShutdown && !job->printer)
     {
       printer = cupsdFindDest(job->dest);
       pclass  = NULL;
@@ -408,11 +436,11 @@ cupsdCleanJobs(void)
   cupsd_job_t  *job;                   /* Current job */
 
 
-  if (MaxJobs <= 0)
+  if (MaxJobs <= 0 && JobHistory)
     return;
 
   for (job = (cupsd_job_t *)cupsArrayFirst(Jobs);
-       job && cupsArrayCount(Jobs) >= MaxJobs;
+       job && (cupsArrayCount(Jobs) >= MaxJobs || !JobHistory);
        job = (cupsd_job_t *)cupsArrayNext(Jobs))
     if (job->state_value >= IPP_JOB_CANCELED && !job->printer)
       cupsdDeleteJob(job, CUPSD_JOB_PURGE);
@@ -428,7 +456,7 @@ cupsdContinueJob(cupsd_job_t *job)  /* I - Job */
 {
   int                  i;              /* Looping var */
   int                  slot;           /* Pipe slot */
-  cups_array_t         *filters,       /* Filters for job */
+  cups_array_t         *filters = NULL,/* Filters for job */
                        *prefilters;    /* Filters with prefilters */
   mime_filter_t                *filter,        /* Current filter */
                        *prefilter,     /* Prefilter */
@@ -437,13 +465,16 @@ cupsdContinueJob(cupsd_job_t *job)        /* I - Job */
   ipp_attribute_t      *attr;          /* Current attribute */
   const char           *ptr,           /* Pointer into value */
                        *abort_message; /* Abort message */
+  ipp_jstate_t         abort_state = IPP_JOB_STOPPED;
+                                       /* New job state on abort */
   struct stat          backinfo;       /* Backend file information */
   int                  backroot;       /* Run backend as root? */
   int                  pid;            /* Process ID of new filter process */
   int                  banner_page;    /* 1 if banner page, 0 otherwise */
-  int                  filterfds[2][2];/* Pipes used between filters */
+  int                  filterfds[2][2] = { { -1, -1 }, { -1, -1 } };
+                                       /* Pipes used between filters */
   int                  envc;           /* Number of environment variables */
-  char                 **argv,         /* Filter command-line arguments */
+  char                 **argv = NULL,  /* Filter command-line arguments */
                        filename[1024], /* Job filename */
                        command[1024],  /* Full path to command */
                        jobid[255],     /* Job ID string */
@@ -490,7 +521,11 @@ cupsdContinueJob(cupsd_job_t *job) /* I - Job */
 
   FilterLevel -= job->cost;
 
-  filters = NULL;
+  job->cost         = 0;
+  job->pending_cost = 0;
+
+  memset(job->filters, 0, sizeof(job->filters));
+
 
   if (job->printer->raw)
   {
@@ -500,8 +535,6 @@ cupsdContinueJob(cupsd_job_t *job)  /* I - Job */
     */
 
     cupsdLogJob(job, CUPSD_LOG_DEBUG, "Sending job to queue tagged as raw...");
-
-    filters = NULL;
   }
   else
   {
@@ -518,13 +551,10 @@ cupsdContinueJob(cupsd_job_t *job)        /* I - Job */
                  "Unable to convert file %d to printable format!",
                  job->current_file);
 
-      job->current_file ++;
-
-      if (job->current_file == job->num_files)
-        cupsdSetJobState(job, IPP_JOB_ABORTED, CUPSD_JOB_DEFAULT,
-                        "Aborting job because it cannot be printed.");
+      abort_message = "Aborting job because it cannot be printed.";
+      abort_state   = IPP_JOB_ABORTED;
 
-      return;
+      goto abort_job;
     }
 
    /*
@@ -598,6 +628,9 @@ cupsdContinueJob(cupsd_job_t *job)  /* I - Job */
                "cupsdContinueJob: file=%d, cost=%d, level=%d, limit=%d",
                job->current_file, job->cost, FilterLevel,
                FilterLimit);
+
+    job->pending_cost = job->cost;
+    job->cost         = 0;
     return;
   }
 
@@ -625,12 +658,9 @@ cupsdContinueJob(cupsd_job_t *job) /* I - Job */
 
       cupsArrayDelete(filters);
 
-      cupsdSetJobState(job, IPP_JOB_STOPPED, CUPSD_JOB_DEFAULT,
-                      "Stopping job because the scheduler ran out of "
-                      "memory.");
+      abort_message = "Stopping job because the scheduler ran out of memory.";
 
-      FilterLevel -= job->cost;
-      return;
+      goto abort_job;
     }
   }
 
@@ -659,14 +689,9 @@ cupsdContinueJob(cupsd_job_t *job) /* I - Job */
       cupsdLogJob(job, CUPSD_LOG_DEBUG,
                  "Unable to add port monitor - %s", strerror(errno));
 
-      cupsArrayDelete(filters);
-
-      cupsdSetJobState(job, IPP_JOB_STOPPED, CUPSD_JOB_DEFAULT,
-                      "Stopping job because the scheduler ran out of "
-                      "memory.");
+      abort_message = "Stopping job because the scheduler ran out of memory.";
 
-      FilterLevel -= job->cost;
-      return;
+      goto abort_job;
     }
   }
 
@@ -680,13 +705,10 @@ cupsdContinueJob(cupsd_job_t *job)        /* I - Job */
                "Too many filters (%d > %d), unable to print!",
                cupsArrayCount(filters), MAX_FILTERS);
 
-    cupsArrayDelete(filters);
-    cupsdSetJobState(job, IPP_JOB_STOPPED, CUPSD_JOB_DEFAULT,
-                    "Stopping job because it needs too many filters to "
-                    "print.");
+    abort_message = "Aborting job because it needs too many filters to print.";
+    abort_state   = IPP_JOB_ABORTED;
 
-    FilterLevel -= job->cost;
-    return;
+    goto abort_job;
   }
 
  /*
@@ -726,12 +748,9 @@ cupsdContinueJob(cupsd_job_t *job) /* I - Job */
   if ((options = get_options(job, banner_page, copies, sizeof(copies), title,
                              sizeof(title))) == NULL)
   {
-    cupsdSetJobState(job, IPP_JOB_STOPPED, CUPSD_JOB_DEFAULT,
-                    "Stopping job because the scheduler ran out of memory.");
-    cupsArrayDelete(filters);
+    abort_message = "Stopping job because the scheduler ran out of memory.";
 
-    FilterLevel -= job->cost;
-    return;
+    goto abort_job;
   }
 
  /*
@@ -761,12 +780,10 @@ cupsdContinueJob(cupsd_job_t *job)        /* I - Job */
   {
     cupsdLogMessage(CUPSD_LOG_DEBUG, "Unable to allocate argument array - %s",
                     strerror(errno));
-    cupsdSetJobState(job, IPP_JOB_STOPPED, CUPSD_JOB_DEFAULT,
-                    "Stopping job because the scheduler ran out of memory.");
-    cupsArrayDelete(filters);
 
-    FilterLevel -= job->cost;
-    return;
+    abort_message = "Stopping job because the scheduler ran out of memory.";
+
+    goto abort_job;
   }
 
   sprintf(jobid, "%d", job->id);
@@ -953,13 +970,6 @@ cupsdContinueJob(cupsd_job_t *job) /* I - Job */
   * Now create processes for all of the filters...
   */
 
-  filterfds[0][0] = -1;
-  filterfds[0][1] = -1;
-  filterfds[1][0] = -1;
-  filterfds[1][1] = -1;
-
-  memset(job->filters, 0, sizeof(job->filters));
-
   for (i = 0, slot = 0, filter = (mime_filter_t *)cupsArrayFirst(filters);
        filter;
        i ++, filter = (mime_filter_t *)cupsArrayNext(filters))
@@ -1036,7 +1046,7 @@ cupsdContinueJob(cupsd_job_t *job)        /* I - Job */
     pid = cupsdStartProcess(command, argv, envp, filterfds[!slot][0],
                             filterfds[slot][1], job->status_pipes[1],
                            job->back_pipes[0], job->side_pipes[0], 0,
-                           job->profile, job->id, job->filters + i);
+                           job->profile, job, job->filters + i);
 
     cupsdClosePipe(filterfds[!slot]);
 
@@ -1045,7 +1055,7 @@ cupsdContinueJob(cupsd_job_t *job)        /* I - Job */
       cupsdLogJob(job, CUPSD_LOG_ERROR, "Unable to start filter \"%s\" - %s.",
                  filter->filter, strerror(errno));
 
-      abort_message = "Stopped job because the scheduler could not execute a "
+      abort_message = "Stopping job because the scheduler could not execute a "
                      "filter.";
 
       goto abort_job;
@@ -1091,7 +1101,7 @@ cupsdContinueJob(cupsd_job_t *job)        /* I - Job */
       pid = cupsdStartProcess(command, argv, envp, filterfds[!slot][0],
                              filterfds[slot][1], job->status_pipes[1],
                              job->back_pipes[1], job->side_pipes[1],
-                             backroot, job->profile, job->id, &(job->backend));
+                             backroot, job->profile, job, &(job->backend));
 
       if (pid == 0)
       {
@@ -1147,6 +1157,16 @@ cupsdContinueJob(cupsd_job_t *job)       /* I - Job */
   cupsdAddEvent(CUPSD_EVENT_JOB_STATE, job->printer, job, "Job #%d started.",
                 job->id);
 
+ /*
+  * If we get here than we are able to run the printer driver filters, so clear
+  * the missing and insecure warnings...
+  */
+
+  if (cupsdSetPrinterReasons(job->printer, "-cups-missing-filter-warning,"
+                                          "cups-insecure-filter-warning"))
+    cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, job->printer, NULL,
+                  "Printer drivers now functional.");
+
   return;
 
 
@@ -1157,25 +1177,53 @@ cupsdContinueJob(cupsd_job_t *job)      /* I - Job */
 
   abort_job:
 
+  FilterLevel -= job->cost;
+  job->cost = 0;
+
   for (slot = 0; slot < 2; slot ++)
     cupsdClosePipe(filterfds[slot]);
 
+  cupsArrayDelete(filters);
+
+  if (argv)
+  {
+    if (job->printer->remote && job->num_files > 1)
+    {
+      for (i = 0; i < job->num_files; i ++)
+       free(argv[i + 6]);
+    }
+
+    free(argv);
+  }
+
+  cupsdClosePipe(job->print_pipes);
+  cupsdClosePipe(job->back_pipes);
+  cupsdClosePipe(job->side_pipes);
+
+  cupsdRemoveSelect(job->status_pipes[0]);
   cupsdClosePipe(job->status_pipes);
   cupsdStatBufDelete(job->status_buffer);
   job->status_buffer = NULL;
 
-  cupsArrayDelete(filters);
+ /*
+  * Update the printer and job state.
+  */
 
-  if (job->printer->remote && job->num_files > 1)
-  {
-    for (i = 0; i < job->num_files; i ++)
-      free(argv[i + 6]);
-  }
+  cupsdSetJobState(job, abort_state, CUPSD_JOB_DEFAULT, "%s", abort_message);
+  cupsdSetPrinterState(job->printer, IPP_PRINTER_IDLE, 0);
+  update_job_attrs(job, 0);
 
-  free(argv);
+  if (job->history)
+    free_job_history(job);
+
+  cupsArrayRemove(PrintingJobs, job);
+
+ /*
+  * Clear the printer <-> job association...
+  */
 
-  cupsdSetJobState(job, IPP_JOB_STOPPED, CUPSD_JOB_DEFAULT, "%s",
-                   abort_message);
+  job->printer->job = NULL;
+  job->printer      = NULL;
 }
 
 
@@ -1188,7 +1236,7 @@ cupsdDeleteJob(cupsd_job_t       *job,    /* I - Job */
                cupsd_jobaction_t action)/* I - Action */
 {
   if (job->printer)
-    finalize_job(job);
+    finalize_job(job, 1);
 
   if (action == CUPSD_JOB_PURGE)
   {
@@ -1231,6 +1279,9 @@ cupsdDeleteJob(cupsd_job_t       *job,    /* I - Job */
     job->num_files = 0;
   }
 
+  if (job->history)
+    free_job_history(job);
+
   unload_job(job);
 
   cupsArrayRemove(Jobs, job);
@@ -1256,7 +1307,7 @@ cupsdFreeAllJobs(void)
 
   cupsdHoldSignals();
 
-  cupsdStopAllJobs(1);
+  cupsdStopAllJobs(CUPSD_JOB_FORCE, 0);
   cupsdSaveAllJobs();
 
   for (job = (cupsd_job_t *)cupsArrayFirst(Jobs);
@@ -1609,7 +1660,30 @@ cupsdLoadJob(cupsd_job_t *job)           /* I - Job */
           cupsdLogMessage(CUPSD_LOG_ERROR,
                          "[Job %d] Ran out of memory for job file types!",
                          job->id);
-         return (1);
+
+         ippDelete(job->attrs);
+         job->attrs = NULL;
+
+         if (compressions)
+           free(compressions);
+
+         if (filetypes)
+           free(filetypes);
+
+         if (job->compressions)
+         {
+           free(job->compressions);
+           job->compressions = NULL;
+         }
+
+         if (job->filetypes)
+         {
+           free(job->filetypes);
+           job->filetypes = NULL;
+         }
+
+         job->num_files = 0;
+         return (0);
        }
 
         job->compressions = compressions;
@@ -1677,6 +1751,21 @@ cupsdLoadJob(cupsd_job_t *job)           /* I - Job */
 
   ippDelete(job->attrs);
   job->attrs = NULL;
+
+  if (job->compressions)
+  {
+    free(job->compressions);
+    job->compressions = NULL;
+  }
+
+  if (job->filetypes)
+  {
+    free(job->filetypes);
+    job->filetypes = NULL;
+  }
+
+  job->num_files = 0;
+
   unlink(jobfile);
 
   return (0);
@@ -1839,6 +1928,7 @@ cupsdSaveAllJobs(void)
     cupsFilePrintf(fp, "<Job %d>\n", job->id);
     cupsFilePrintf(fp, "State %d\n", job->state_value);
     cupsFilePrintf(fp, "Priority %d\n", job->priority);
+    cupsFilePrintf(fp, "HoldUntil %d\n", (int)job->hold_until);
     cupsFilePrintf(fp, "Username %s\n", job->username);
     cupsFilePrintf(fp, "Destination %s\n", job->dest);
     cupsFilePrintf(fp, "DestType %d\n", job->dtype);
@@ -2135,19 +2225,21 @@ cupsdSetJobState(
   if (!cupsdLoadJob(job))
     return;
 
- /*
-  * Don't do anything if the state is unchanged...
-  */
+  /*
+   * Don't do anything if the state is unchanged and we aren't purging the
+   * job...
+   */
 
-  if (newstate == (oldstate = job->state_value))
-    return;
+   oldstate = job->state_value;
+   if (newstate == oldstate && action != CUPSD_JOB_PURGE)
+     return;
 
  /*
   * Stop any processes that are working on the current job...
   */
 
   if (oldstate == IPP_JOB_PROCESSING)
-    stop_job(job, action != CUPSD_JOB_DEFAULT);
+    stop_job(job, action);
 
  /*
   * Set the new job state...
@@ -2248,17 +2340,32 @@ cupsdSetJobState(
     case IPP_JOB_ABORTED :
     case IPP_JOB_CANCELED :
     case IPP_JOB_COMPLETED :
-       /*
-        * Expire job subscriptions since the job is now "completed"...
-       */
+        if (newstate == IPP_JOB_CANCELED)
+       {
+        /*
+         * Remove the job from the active list if there are no processes still
+         * running for it...
+         */
 
-        cupsdExpireSubscriptions(NULL, job);
+         for (i = 0; job->filters[i] < 0; i++);
+
+         if (!job->filters[i] && job->backend <= 0)
+           cupsArrayRemove(ActiveJobs, job);
+       }
+       else
+       {
+        /*
+         * Otherwise just remove the job from the active list immediately...
+         */
+
+         cupsArrayRemove(ActiveJobs, job);
+       }
 
        /*
-       * Remove the job from the active list...
+        * Expire job subscriptions since the job is now "completed"...
        */
 
-       cupsArrayRemove(ActiveJobs, job);
+        cupsdExpireSubscriptions(NULL, job);
 
 #ifdef __APPLE__
        /*
@@ -2333,10 +2440,24 @@ cupsdSetJobState(
          cupsdMarkDirty(CUPSD_DIRTY_JOBS);
        }
        else if (!job->printer)
+       {
+        /*
+         * Delete the job immediately if not actively printing...
+         */
+
          cupsdDeleteJob(job, CUPSD_JOB_PURGE);
+         job = NULL;
+       }
        break;
   }
 
+ /*
+  * Finalize the job immediately if we forced things...
+  */
+
+  if (action >= CUPSD_JOB_FORCE && job && job->printer)
+    finalize_job(job, 0);
+
  /*
   * Update the server "busy" state...
   */
@@ -2351,7 +2472,8 @@ cupsdSetJobState(
 
 void
 cupsdStopAllJobs(
-    cupsd_jobaction_t action)          /* I - Action */
+    cupsd_jobaction_t action,          /* I - Action */
+    int               kill_delay)      /* I - Number of seconds before we kill */
 {
   cupsd_job_t  *job;                   /* Current job */
 
@@ -2361,7 +2483,12 @@ cupsdStopAllJobs(
   for (job = (cupsd_job_t *)cupsArrayFirst(PrintingJobs);
        job;
        job = (cupsd_job_t *)cupsArrayNext(PrintingJobs))
+  {
+    if (kill_delay)
+      job->kill_time = time(NULL) + kill_delay;
+
     cupsdSetJobState(job, IPP_JOB_PENDING, action, NULL);
+  }
 }
 
 
@@ -2425,12 +2552,147 @@ compare_jobs(void *first,              /* I - First job */
 }
 
 
+/*
+ * 'dump_job_history()' - Dump any debug messages for a job.
+ */
+
+static void
+dump_job_history(cupsd_job_t *job)     /* I - Job */
+{
+  int                  i,              /* Looping var */
+                       oldsize;        /* Current MaxLogSize */
+  struct tm            *date;          /* Date/time value */
+  cupsd_joblog_t       *message;       /* Current message */
+  char                 temp[2048],     /* Log message */
+                       *ptr,           /* Pointer into log message */
+                       start[256],     /* Start time */
+                       end[256];       /* End time */
+  cupsd_printer_t      *printer;       /* Printer for job */
+
+
+ /*
+  * See if we have anything to dump...
+  */
+
+  if (!job->history)
+    return;
+
+ /*
+  * Disable log rotation temporarily...
+  */
+
+  oldsize    = MaxLogSize;
+  MaxLogSize = 0;
+
+ /*
+  * Copy the debug messages to the log...
+  */
+
+  message = (cupsd_joblog_t *)cupsArrayFirst(job->history);
+  date = localtime(&(message->time));
+  strftime(start, sizeof(start), "%X", date);
+
+  message = (cupsd_joblog_t *)cupsArrayLast(job->history);
+  date = localtime(&(message->time));
+  strftime(end, sizeof(end), "%X", date);
+
+  snprintf(temp, sizeof(temp),
+           "[Job %d] The following messages were recorded from %s to %s",
+           job->id, start, end);
+  cupsdWriteErrorLog(CUPSD_LOG_DEBUG, temp);
+
+  for (message = (cupsd_joblog_t *)cupsArrayFirst(job->history);
+       message;
+       message = (cupsd_joblog_t *)cupsArrayNext(job->history))
+    cupsdWriteErrorLog(CUPSD_LOG_DEBUG, message->message);
+
+  snprintf(temp, sizeof(temp), "[Job %d] End of messages", job->id);
+  cupsdWriteErrorLog(CUPSD_LOG_DEBUG, temp);
+
+ /*
+  * Log the printer state values...
+  */
+
+  if ((printer = job->printer) == NULL)
+    printer = cupsdFindDest(job->dest);
+
+  if (printer)
+  {
+    snprintf(temp, sizeof(temp), "[Job %d] printer-state=%d(%s)", job->id,
+             printer->state,
+            printer->state == IPP_PRINTER_IDLE ? "idle" :
+                printer->state == IPP_PRINTER_PROCESSING ? "processing" :
+                "stopped");
+    cupsdWriteErrorLog(CUPSD_LOG_DEBUG, temp);
+
+    snprintf(temp, sizeof(temp), "[Job %d] printer-state-message=\"%s\"",
+             job->id, printer->state_message);
+    cupsdWriteErrorLog(CUPSD_LOG_DEBUG, temp);
+
+    snprintf(temp, sizeof(temp), "[Job %d] printer-state-reasons=", job->id);
+    ptr = temp + strlen(temp);
+    if (printer->num_reasons == 0)
+      strlcpy(ptr, "none", sizeof(temp) - (ptr - temp));
+    else
+    {
+      for (i = 0;
+           i < printer->num_reasons && ptr < (temp + sizeof(temp) - 2);
+           i ++)
+      {
+        if (i)
+         *ptr++ = ',';
+
+       strlcpy(ptr, printer->reasons[i], sizeof(temp) - (ptr - temp));
+       ptr += strlen(ptr);
+      }
+    }
+    cupsdWriteErrorLog(CUPSD_LOG_DEBUG, temp);
+  }
+
+ /*
+  * Restore log file rotation...
+  */
+
+  MaxLogSize = oldsize;
+
+ /*
+  * Free all messages...
+  */
+
+  free_job_history(job);
+}
+
+
+/*
+ * 'free_job_history()' - Free any log history.
+ */
+
+static void
+free_job_history(cupsd_job_t *job)     /* I - Job */
+{
+  char *message;                       /* Current message */
+
+
+  if (!job->history)
+    return;
+
+  for (message = (char *)cupsArrayFirst(job->history);
+       message;
+       message = (char *)cupsArrayNext(job->history))
+    free(message);
+
+  cupsArrayDelete(job->history);
+  job->history = NULL;
+}
+
+
 /*
  * 'finalize_job()' - Cleanup after job filter processes and support data.
  */
 
 static void
-finalize_job(cupsd_job_t *job)         /* I - Job */
+finalize_job(cupsd_job_t *job,         /* I - Job */
+             int         set_job_state)        /* I - 1 = set the job state */
 {
   ipp_pstate_t         printer_state;  /* New printer state value */
   ipp_jstate_t         job_state;      /* New job state value */
@@ -2441,8 +2703,8 @@ finalize_job(cupsd_job_t *job)            /* I - Job */
   cupsdLogMessage(CUPSD_LOG_DEBUG2, "finalize_job(job=%p(%d))", job, job->id);
 
  /*
-  * Clear the "connecting-to-device" reason, which is only valid when a
-  * printer is processing...
+  * Clear the "connecting-to-device" reason, which is only valid when a printer
+  * is processing...
   */
 
   cupsdSetPrinterReasons(job->printer, "-connecting-to-device");
@@ -2463,16 +2725,21 @@ finalize_job(cupsd_job_t *job)          /* I - Job */
   job->profile = NULL;
 
  /*
-  * Close pipes and status buffer...
+  * Clear the unresponsive job watchdog timer...
   */
 
-  cupsdRemoveSelect(job->status_buffer->fd);
+  job->kill_time = 0;
+
+ /*
+  * Close pipes and status buffer...
+  */
 
   cupsdClosePipe(job->print_pipes);
   cupsdClosePipe(job->back_pipes);
   cupsdClosePipe(job->side_pipes);
-  cupsdClosePipe(job->status_pipes);
 
+  cupsdRemoveSelect(job->status_pipes[0]);
+  cupsdClosePipe(job->status_pipes);
   cupsdStatBufDelete(job->status_buffer);
   job->status_buffer = NULL;
 
@@ -2498,8 +2765,8 @@ finalize_job(cupsd_job_t *job)            /* I - Job */
     default :
     case IPP_JOB_PROCESSING :
     case IPP_JOB_COMPLETED :
-       job_state     = IPP_JOB_COMPLETED;
-       message       = "Job completed.";
+       job_state = IPP_JOB_COMPLETED;
+       message   = "Job completed.";
         break;
 
     case IPP_JOB_STOPPED :
@@ -2566,8 +2833,11 @@ finalize_job(cupsd_job_t *job)           /* I - Job */
            * another printer...
            */
 
-            job_state = IPP_JOB_PENDING;
-           message   = "Retrying job on another printer.";
+            if (job_state == IPP_JOB_COMPLETED)
+           {
+             job_state = IPP_JOB_PENDING;
+             message   = "Retrying job on another printer.";
+           }
           }
          else if (!strcmp(job->printer->error_policy, "retry-current-job"))
          {
@@ -2576,59 +2846,66 @@ finalize_job(cupsd_job_t *job)          /* I - Job */
            * and we'll retry on the same printer...
            */
 
-            job_state = IPP_JOB_PENDING;
-           message   = "Retrying job on same printer.";
+            if (job_state == IPP_JOB_COMPLETED)
+           {
+             job_state = IPP_JOB_PENDING;
+             message   = "Retrying job on same printer.";
+           }
           }
          else if ((job->printer->type & CUPS_PRINTER_FAX) ||
                   !strcmp(job->printer->error_policy, "retry-job"))
          {
-          /*
-           * The job was queued on a fax or the error policy is "retry-job" -
-           * hold the job if the number of retries is less than the
-           * JobRetryLimit, otherwise abort the job.
-           */
-
-           job->tries ++;
-
-           if (job->tries >= JobRetryLimit)
+            if (job_state == IPP_JOB_COMPLETED)
            {
             /*
-             * Too many tries...
+             * The job was queued on a fax or the error policy is "retry-job" -
+             * hold the job if the number of retries is less than the
+             * JobRetryLimit, otherwise abort the job.
              */
 
-              snprintf(buffer, sizeof(buffer),
-                      "Job aborted after %d unsuccessful attempts.",
-                      JobRetryLimit);
-              job_state = IPP_JOB_ABORTED;
-             message   = buffer;
-           }
-           else
-           {
-            /*
-             * Try again in N seconds...
-             */
+             job->tries ++;
 
-             set_hold_until(job, time(NULL) + JobRetryInterval);
+             if (job->tries > JobRetryLimit && JobRetryLimit > 0)
+             {
+              /*
+               * Too many tries...
+               */
+
+               snprintf(buffer, sizeof(buffer),
+                        "Job aborted after %d unsuccessful attempts.",
+                        JobRetryLimit);
+               job_state = IPP_JOB_ABORTED;
+               message   = buffer;
+             }
+             else
+             {
+              /*
+               * Try again in N seconds...
+               */
 
-              snprintf(buffer, sizeof(buffer),
-                      "Job held for %d seconds since it could not be sent.",
-                      JobRetryInterval);
-              job_state = IPP_JOB_HELD;
-             message   = buffer;
-           }
+               set_hold_until(job, time(NULL) + JobRetryInterval);
+
+               snprintf(buffer, sizeof(buffer),
+                        "Job held for %d seconds since it could not be sent.",
+                        JobRetryInterval);
+               job_state = IPP_JOB_HELD;
+               message   = buffer;
+             }
+            }
          }
-         else if (!strcmp(job->printer->error_policy, "abort-job"))
+         else if (!strcmp(job->printer->error_policy, "abort-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.";
          }
-         else
+         else if (job->state_value == IPP_JOB_PROCESSING)
           {
+            job_state     = IPP_JOB_PENDING;
            printer_state = IPP_PRINTER_STOPPED;
-           job_state     = IPP_JOB_PENDING;
            message       = "Printer stopped due to backend errors; please "
-                           "consult the error_log file for details.";
+                           "consult the error_log file for details.";
          }
           break;
 
@@ -2637,21 +2914,27 @@ finalize_job(cupsd_job_t *job)          /* I - Job */
          * Abort the job...
          */
 
-         job_state = IPP_JOB_ABORTED;
-         message   = "Job aborted due to backend errors; please consult "
-                     "the error_log file for details.";
+         if (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.";
+         }
           break;
 
       case CUPS_BACKEND_HOLD :
-         /*
-         * Hold the job...
-         */
+         if (job_state == IPP_JOB_COMPLETED)
+         {
+          /*
+           * Hold the job...
+           */
 
-         cupsdSetJobHoldUntil(job, "indefinite", 1);
+           cupsdSetJobHoldUntil(job, "indefinite", 1);
 
-         job_state = IPP_JOB_HELD;
-         message   = "Job held indefinitely due to backend errors; please "
-                     "consult the error_log file for details.";
+           job_state = IPP_JOB_HELD;
+           message   = "Job held indefinitely due to backend errors; please "
+                       "consult the error_log file for details.";
+          }
           break;
 
       case CUPS_BACKEND_STOP :
@@ -2660,9 +2943,11 @@ finalize_job(cupsd_job_t *job)           /* I - Job */
          */
 
          printer_state = IPP_PRINTER_STOPPED;
-         job_state     = IPP_JOB_PENDING;
          message       = "Printer stopped due to backend errors; please "
                          "consult the error_log file for details.";
+
+         if (job_state == IPP_JOB_COMPLETED)
+           job_state = IPP_JOB_PENDING;
           break;
 
       case CUPS_BACKEND_AUTH_REQUIRED :
@@ -2670,10 +2955,13 @@ finalize_job(cupsd_job_t *job)          /* I - Job */
          * Hold the job for authentication...
          */
 
-         cupsdSetJobHoldUntil(job, "auth-info-required", 1);
+         if (job_state == IPP_JOB_COMPLETED)
+         {
+           cupsdSetJobHoldUntil(job, "auth-info-required", 1);
 
-         job_state = IPP_JOB_HELD;
-         message   = "Job held for authentication.";
+           job_state = IPP_JOB_HELD;
+           message   = "Job held for authentication.";
+          }
           break;
     }
   }
@@ -2683,20 +2971,33 @@ finalize_job(cupsd_job_t *job)          /* I - Job */
     * Filter had errors; stop job...
     */
 
-    job_state = IPP_JOB_STOPPED;
-    message   = "Job stopped due to filter errors; please consult the "
-               "error_log file for details.";
+    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.";
+    }
   }
 
  /*
   * Update the printer and job state.
   */
 
-  cupsdSetJobState(job, job_state, CUPSD_JOB_DEFAULT, "%s", message);
+  if (job_state != job->state_value)
+    cupsdSetJobState(job, job_state, CUPSD_JOB_DEFAULT, "%s", message);
+
   cupsdSetPrinterState(job->printer, printer_state,
                        printer_state == IPP_PRINTER_STOPPED);
   update_job_attrs(job, 0);
 
+  if (job->history)
+  {
+    if (job->status)
+      dump_job_history(job);
+    else
+      free_job_history(job);
+  }
+
   cupsArrayRemove(PrintingJobs, job);
 
  /*
@@ -2728,39 +3029,183 @@ get_options(cupsd_job_t *job,          /* I - Job */
            size_t      title_size)     /* I - Size of title buffer */
 {
   int                  i;              /* Looping var */
+  size_t               newlength;      /* New option buffer length */
   char                 *optptr,        /* Pointer to options */
                        *valptr;        /* Pointer in value string */
   ipp_attribute_t      *attr;          /* Current attribute */
+  _pwg_t               *pwg;           /* PWG->PPD mapping data */
+  int                  num_pwgppds;    /* Number of PWG->PPD options */
+  cups_option_t                *pwgppds,       /* PWG->PPD options */
+                       *pwgppd,        /* Current PWG->PPD option */
+                       *preset;        /* Current preset option */
+  int                  output_mode,    /* Output mode (if any) */
+                       print_quality;  /* Print quality (if any) */
+  const char           *ppd;           /* PPD option choice */
+  int                  exact;          /* Did we get an exact match? */
   static char          *options = NULL;/* Full list of options */
-  static int           optlength = 0;  /* Length of option buffer */
+  static size_t                optlength = 0;  /* Length of option buffer */
 
 
  /*
-  * Building the options string is harder than it needs to be, but
-  * for the moment we need to pass strings for command-line args and
-  * not IPP attribute pointers... :)
+  * Building the options string is harder than it needs to be, but for the
+  * moment we need to pass strings for command-line args and not IPP attribute
+  * pointers... :)
   *
-  * First allocate/reallocate the option buffer as needed...
+  * First build an options array for any PWG->PPD mapped option/choice pairs.
+  */
+
+  pwg         = job->printer->pwg;
+  num_pwgppds = 0;
+  pwgppds     = NULL;
+
+  if (pwg &&
+      !ippFindAttribute(job->attrs,
+                        "com.apple.print.DocumentTicket.PMSpoolFormat",
+                       IPP_TAG_ZERO) &&
+      (ippFindAttribute(job->attrs, "output-mode", IPP_TAG_ZERO) ||
+       ippFindAttribute(job->attrs, "print-quality", IPP_TAG_ZERO)))
+  {
+   /*
+    * Map output-mode and print-quality to a preset...
+    */
+
+    if ((attr = ippFindAttribute(job->attrs, "output-mode",
+                                IPP_TAG_KEYWORD)) != NULL &&
+       !strcmp(attr->values[0].string.text, "monochrome"))
+      output_mode = _PWG_OUTPUT_MODE_MONOCHROME;
+    else
+      output_mode = _PWG_OUTPUT_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;
+    else
+      print_quality = _PWG_PRINT_QUALITY_NORMAL;
+
+    if (pwg->num_presets[output_mode][print_quality] == 0)
+    {
+     /*
+      * Try to find a preset that works so that we maximize the chances of us
+      * getting a good print using IPP attributes.
+      */
+
+      if (pwg->num_presets[output_mode][_PWG_PRINT_QUALITY_NORMAL] > 0)
+        print_quality = _PWG_PRINT_QUALITY_NORMAL;
+      else if (pwg->num_presets[_PWG_OUTPUT_MODE_COLOR][print_quality] > 0)
+        output_mode = _PWG_OUTPUT_MODE_COLOR;
+      else
+      {
+        print_quality = _PWG_PRINT_QUALITY_NORMAL;
+        output_mode   = _PWG_OUTPUT_MODE_COLOR;
+      }
+    }
+
+    if (pwg->num_presets[output_mode][print_quality] > 0)
+    {
+     /*
+      * Copy the preset options as long as the corresponding names are not
+      * already defined in the IPP request...
+      */
+
+      for (i = pwg->num_presets[output_mode][print_quality],
+              preset = pwg->presets[output_mode][print_quality];
+          i > 0;
+          i --, preset ++)
+      {
+        if (!ippFindAttribute(job->attrs, preset->name, IPP_TAG_ZERO))
+         num_pwgppds = cupsAddOption(preset->name, preset->value, num_pwgppds,
+                                     &pwgppds);
+      }
+    }
+  }
+
+  if (pwg)
+  {
+    if (pwg->sides_option &&
+        !ippFindAttribute(job->attrs, pwg->sides_option, IPP_TAG_ZERO) &&
+       (attr = ippFindAttribute(job->attrs, "sides", IPP_TAG_KEYWORD)) != NULL)
+    {
+     /*
+      * Add a duplex option...
+      */
+
+      if (!strcmp(attr->values[0].string.text, "one-sided"))
+        num_pwgppds = cupsAddOption(pwg->sides_option, pwg->sides_1sided,
+                                   num_pwgppds, &pwgppds);
+      else if (!strcmp(attr->values[0].string.text, "two-sided-long-edge"))
+        num_pwgppds = cupsAddOption(pwg->sides_option, pwg->sides_2sided_long,
+                                   num_pwgppds, &pwgppds);
+      else if (!strcmp(attr->values[0].string.text, "two-sided-short-edge"))
+        num_pwgppds = cupsAddOption(pwg->sides_option, pwg->sides_2sided_short,
+                                   num_pwgppds, &pwgppds);
+    }
+
+    if (!ippFindAttribute(job->attrs, "InputSlot", IPP_TAG_ZERO) &&
+       !ippFindAttribute(job->attrs, "HPPaperSource", IPP_TAG_ZERO))
+    {
+      if ((ppd = _pwgGetInputSlot(pwg, job->attrs, NULL)) != NULL)
+       num_pwgppds = cupsAddOption(pwg->source_option, ppd, num_pwgppds,
+                                   &pwgppds);
+      else if (!ippFindAttribute(job->attrs, "AP_D_InputSlot", IPP_TAG_ZERO))
+       num_pwgppds = cupsAddOption("AP_D_InputSlot", "", num_pwgppds,
+                                   &pwgppds);
+    }
+
+    if (!ippFindAttribute(job->attrs, "MediaType", IPP_TAG_ZERO) &&
+       (ppd = _pwgGetMediaType(pwg, job->attrs, NULL)) != NULL)
+      num_pwgppds = cupsAddOption("MediaType", ppd, num_pwgppds, &pwgppds);
+
+    if (!ippFindAttribute(job->attrs, "PageRegion", IPP_TAG_ZERO) &&
+       !ippFindAttribute(job->attrs, "PageSize", IPP_TAG_ZERO) &&
+       (ppd = _pwgGetPageSize(pwg, job->attrs, NULL, &exact)) != NULL)
+    {
+      num_pwgppds = cupsAddOption("PageSize", ppd, num_pwgppds, &pwgppds);
+
+      if (!ippFindAttribute(job->attrs, "media", IPP_TAG_ZERO))
+        num_pwgppds = cupsAddOption("media", ppd, num_pwgppds, &pwgppds);
+    }
+
+    if (!ippFindAttribute(job->attrs, "OutputBin", IPP_TAG_ZERO) &&
+       (attr = ippFindAttribute(job->attrs, "output-bin",
+                                IPP_TAG_ZERO)) != NULL &&
+       (attr->value_tag == IPP_TAG_KEYWORD ||
+        attr->value_tag == IPP_TAG_NAME) &&
+       (ppd = _pwgGetOutputBin(pwg, attr->values[0].string.text)) != NULL) 
+      num_pwgppds = cupsAddOption("OutputBin", ppd, num_pwgppds, &pwgppds);
+  }
+
+ /*
+  * Figure out how much room we need...
   */
 
-  i = ipp_length(job->attrs);
+  newlength = ipp_length(job->attrs);
+
+  for (i = num_pwgppds, pwgppd = pwgppds; i > 0; i --, pwgppd ++)
+    newlength += 1 + strlen(pwgppd->name) + 1 + strlen(pwgppd->value);
 
-  if (i > optlength || !options)
+ /*
+  * Then allocate/reallocate the option buffer as needed...
+  */
+
+  if (newlength > optlength || !options)
   {
     if (!options)
-      optptr = malloc(i);
+      optptr = malloc(newlength);
     else
-      optptr = realloc(options, i);
+      optptr = realloc(options, newlength);
 
     if (!optptr)
     {
       cupsdLogJob(job, CUPSD_LOG_CRIT,
-                 "Unable to allocate %d bytes for option buffer!", i);
+                 "Unable to allocate " CUPS_LLFMT " bytes for option buffer!",
+                 CUPS_LLCAST newlength);
       return (NULL);
     }
 
     options   = optptr;
-    optlength = i;
+    optlength = newlength;
   }
 
  /*
@@ -2796,7 +3241,8 @@ get_options(cupsd_job_t *job,             /* I - Job */
       * Filter out other unwanted attributes...
       */
 
-      if (attr->value_tag == IPP_TAG_MIMETYPE ||
+      if (attr->value_tag == IPP_TAG_NOVALUE ||
+          attr->value_tag == IPP_TAG_MIMETYPE ||
          attr->value_tag == IPP_TAG_NAMELANG ||
          attr->value_tag == IPP_TAG_TEXTLANG ||
          (attr->value_tag == IPP_TAG_URI && strcmp(attr->name, "job-uuid")) ||
@@ -2804,7 +3250,7 @@ get_options(cupsd_job_t *job,             /* I - Job */
          attr->value_tag == IPP_TAG_BEGIN_COLLECTION) /* Not yet supported */
        continue;
 
-      if (!strncmp(attr->name, "time-", 5))
+      if (!strcmp(attr->name, "job-hold-until"))
        continue;
 
       if (!strncmp(attr->name, "job-", 4) &&
@@ -2862,7 +3308,6 @@ get_options(cupsd_job_t *job,             /* I - Job */
              if (!attr->values[i].boolean)
                strlcat(optptr, "no", optlength - (optptr - options));
 
-         case IPP_TAG_NOVALUE :
              strlcat(optptr, attr->name,
                      optlength - (optptr - options));
              break;
@@ -2911,6 +3356,25 @@ get_options(cupsd_job_t *job,            /* I - Job */
     }
   }
 
+ /*
+  * Finally loop through the PWG->PPD mapped options and add them...
+  */
+
+  for (i = num_pwgppds, pwgppd = pwgppds; i > 0; i --, pwgppd ++)
+  {
+    *optptr++ = ' ';
+    strcpy(optptr, pwgppd->name);
+    optptr += strlen(optptr);
+    *optptr++ = '=';
+    strcpy(optptr, pwgppd->value);
+    optptr += strlen(optptr);
+  }
+
+  cupsFreeOptions(num_pwgppds, pwgppds);
+
+ /*
+  * Return the options string...
+  */
 
   return (options);
 }
@@ -2921,10 +3385,10 @@ get_options(cupsd_job_t *job,           /* I - Job */
  *                 the textual IPP attributes.
  */
 
-static int                             /* O - Size of attribute buffer */
+static size_t                          /* O - Size of attribute buffer */
 ipp_length(ipp_t *ipp)                 /* I - IPP request */
 {
-  int                  bytes;          /* Number of bytes */
+  size_t               bytes;          /* Number of bytes */
   int                  i;              /* Looping var */
   ipp_attribute_t      *attr;          /* Current attribute */
 
@@ -2941,16 +3405,14 @@ ipp_length(ipp_t *ipp)                  /* I - IPP request */
     * Skip attributes that won't be sent to filters...
     */
 
-    if (attr->value_tag == IPP_TAG_MIMETYPE ||
+    if (attr->value_tag == IPP_TAG_NOVALUE ||
+       attr->value_tag == IPP_TAG_MIMETYPE ||
        attr->value_tag == IPP_TAG_NAMELANG ||
        attr->value_tag == IPP_TAG_TEXTLANG ||
        attr->value_tag == IPP_TAG_URI ||
        attr->value_tag == IPP_TAG_URISCHEME)
       continue;
 
-    if (strncmp(attr->name, "time-", 5) == 0)
-      continue;
-
    /*
     * Add space for a leading space and commas between each value.
     * For the first attribute, the leading space isn't used, so the
@@ -3151,11 +3613,8 @@ load_job_cache(const char *filename)     /* I - job.cache filename */
     {
       cupsArrayAdd(Jobs, job);
 
-      if (job->state_value <= IPP_JOB_STOPPED)
-      {
-        cupsArrayAdd(ActiveJobs, job);
-       cupsdLoadJob(job);
-      }
+      if (job->state_value <= IPP_JOB_STOPPED && cupsdLoadJob(job))
+       cupsArrayAdd(ActiveJobs, job);
 
       job = NULL;
     }
@@ -3173,6 +3632,10 @@ load_job_cache(const char *filename)     /* I - job.cache filename */
       else if (job->state_value > IPP_JOB_COMPLETED)
         job->state_value = IPP_JOB_COMPLETED;
     }
+    else if (!strcasecmp(line, "HoldUntil"))
+    {
+      job->hold_until = atoi(value);
+    }
     else if (!strcasecmp(line, "Priority"))
     {
       job->priority = atoi(value);
@@ -3403,18 +3866,19 @@ load_request_root(void)
       * Load the job...
       */
 
-      cupsdLoadJob(job);
+      if (cupsdLoadJob(job))
+      {
+       /*
+        * Insert the job into the array, sorting by job priority and ID...
+        */
 
-     /*
-      * Insert the job into the array, sorting by job priority and ID...
-      */
+       cupsArrayAdd(Jobs, job);
 
-      cupsArrayAdd(Jobs, job);
-
-      if (job->state_value <= IPP_JOB_STOPPED)
-        cupsArrayAdd(ActiveJobs, job);
-      else
-        unload_job(job);
+       if (job->state_value <= IPP_JOB_STOPPED)
+         cupsArrayAdd(ActiveJobs, job);
+       else
+         unload_job(job);
+      }
     }
 
   cupsDirClose(dir);
@@ -3558,6 +4022,9 @@ start_job(cupsd_job_t     *job,           /* I - Job ID */
   job->status_buffer = cupsdStatBufNew(job->status_pipes[0], NULL);
   job->status_level  = CUPSD_LOG_INFO;
 
+  if (job->printer_message)
+    cupsdSetString(&(job->printer_message->values[0].string.text), "");
+
  /*
   * Create the backchannel pipes and make them non-blocking...
   */
@@ -3614,6 +4081,11 @@ start_job(cupsd_job_t     *job,          /* I - Job ID */
   fcntl(job->side_pipes[1], F_SETFL,
        fcntl(job->side_pipes[1], F_GETFL) | O_NONBLOCK);
 
+  fcntl(job->side_pipes[0], F_SETFD,
+       fcntl(job->side_pipes[0], F_GETFD) | FD_CLOEXEC);
+  fcntl(job->side_pipes[1], F_SETFD,
+       fcntl(job->side_pipes[1], F_GETFD) | FD_CLOEXEC);
+
  /*
   * Now start the first file in the job...
   */
@@ -3639,12 +4111,36 @@ stop_job(cupsd_job_t       *job,        /* I - Job */
   FilterLevel -= job->cost;
   job->cost   = 0;
 
+  if (action == CUPSD_JOB_DEFAULT && !job->kill_time)
+    job->kill_time = time(NULL) + JobKillDelay;
+  else if (action >= CUPSD_JOB_FORCE)
+    job->kill_time = 0;
+
   for (i = 0; job->filters[i]; i ++)
     if (job->filters[i] > 0)
-      cupsdEndProcess(job->filters[i], action == CUPSD_JOB_FORCE);
+    {
+      cupsdEndProcess(job->filters[i], action >= CUPSD_JOB_FORCE);
+
+      if (action >= CUPSD_JOB_FORCE)
+        job->filters[i] = -job->filters[i];
+    }
 
   if (job->backend > 0)
-    cupsdEndProcess(job->backend, action == CUPSD_JOB_FORCE);
+  {
+    cupsdEndProcess(job->backend, action >= CUPSD_JOB_FORCE);
+
+    if (action >= CUPSD_JOB_FORCE)
+      job->backend = -job->backend;
+  }
+
+  if (action >= CUPSD_JOB_FORCE)
+  {
+   /*
+    * Clear job status...
+    */
+
+    job->status = 0;
+  }
 }
 
 
@@ -3680,7 +4176,8 @@ update_job(cupsd_job_t *job)              /* I - Job to check */
 {
   int          i;                      /* Looping var */
   int          copies;                 /* Number of copies printed */
-  char         message[1024],          /* Message text */
+  char         message[CUPSD_SB_BUFFER_SIZE],
+                                       /* Message text */
                *ptr;                   /* Pointer update... */
   int          loglevel,               /* Log level for message */
                event = 0;              /* Events? */
@@ -3738,28 +4235,7 @@ update_job(cupsd_job_t *job)             /* I - Job to check */
         job->sheets->values[0].integer += copies;
 
        if (job->printer->page_limit)
-       {
-         cupsd_quota_t *q = cupsdUpdateQuota(job->printer, job->username,
-                                             copies, 0);
-
-#ifdef __APPLE__
-         if (AppleQuotas && q->page_count == -3)
-         {
-          /*
-           * Quota limit exceeded, cancel job in progress immediately...
-           */
-
-           cupsdSetJobState(job, IPP_JOB_CANCELED, CUPSD_JOB_DEFAULT,
-                            "Canceled job because pages exceed user %s "
-                            "quota limit on printer %s (%s).",
-                            job->username, job->printer->name,
-                            job->printer->info);
-           return;
-         }
-#else
-          (void)q;
-#endif /* __APPLE__ */
-       }
+         cupsdUpdateQuota(job->printer, job->username, copies, 0);
       }
 
       cupsdLogPage(job, message);
@@ -3777,9 +4253,8 @@ update_job(cupsd_job_t *job)              /* I - Job to check */
         cupsdStopPrinter(job->printer, 1);
        return;
       }
-      else
+      else if (cupsdSetPrinterReasons(job->printer, message))
       {
-       cupsdSetPrinterReasons(job->printer, message);
        cupsdAddPrinterHistory(job->printer);
        event |= CUPSD_EVENT_PRINTER_STATE;
       }
@@ -3920,50 +4395,39 @@ update_job(cupsd_job_t *job)            /* I - Job to check */
 
       cupsFreeOptions(num_keywords, keywords);
     }
-#ifdef __APPLE__
-    else if (!strncmp(message, "recoverable:", 12))
+    else
     {
-      ptr = message + 12;
-      while (isspace(*ptr & 255))
-        ptr ++;
+     /*
+      * Strip legacy message prefix...
+      */
 
-      if (*ptr)
+      if (!strncmp(message, "recoverable:", 12))
       {
-       cupsdSetPrinterReasons(job->printer,
-                              "+com.apple.print.recoverable-warning");
-       cupsdSetString(&(job->printer->recoverable), ptr);
-       cupsdAddPrinterHistory(job->printer);
-       event |= CUPSD_EVENT_PRINTER_STATE;
+        ptr = message + 12;
+       while (isspace(*ptr & 255))
+          ptr ++;
       }
-    }
-    else if (!strncmp(message, "recovered:", 10))
-    {
-      cupsdSetPrinterReasons(job->printer,
-                             "-com.apple.print.recoverable-warning");
+      else if (!strncmp(message, "recovered:", 10))
+      {
+        ptr = message + 10;
+       while (isspace(*ptr & 255))
+          ptr ++;
+      }
+      else
+        ptr = message;
 
-      ptr = message + 10;
-      while (isspace(*ptr & 255))
-        ptr ++;
+      cupsdLogJob(job, loglevel, "%s", ptr);
 
-      cupsdSetString(&(job->printer->recoverable), ptr);
-      cupsdAddPrinterHistory(job->printer);
-      event |= CUPSD_EVENT_PRINTER_STATE;
-    }
-#endif /* __APPLE__ */
-    else
-    {
-      if (loglevel != CUPSD_LOG_INFO && loglevel > LogLevel)
-       cupsdLogJob(job, loglevel, "%d %s", loglevel, message);
-
-      if (loglevel < CUPSD_LOG_DEBUG)
+      if (loglevel < CUPSD_LOG_DEBUG &&
+          strcmp(job->printer->state_message, ptr))
       {
-       strlcpy(job->printer->state_message, message,
+       strlcpy(job->printer->state_message, ptr,
                sizeof(job->printer->state_message));
        cupsdAddPrinterHistory(job->printer);
 
-       event |= CUPSD_EVENT_PRINTER_STATE;
+       event |= CUPSD_EVENT_PRINTER_STATE | CUPSD_EVENT_JOB_PROGRESS;
 
-       if (loglevel <= job->status_level)
+       if (loglevel <= job->status_level && job->status_level > CUPSD_LOG_ERROR)
        {
         /*
          * Some messages show in the job-printer-state-message attribute...
@@ -3987,6 +4451,9 @@ update_job(cupsd_job_t *job)              /* I - Job to check */
       break;
   }
 
+  if (event & CUPSD_EVENT_JOB_PROGRESS)
+    cupsdAddEvent(CUPSD_EVENT_JOB_PROGRESS, job->printer, job,
+                  "%s", job->printer->state_message);
   if (event & CUPSD_EVENT_PRINTER_STATE)
     cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, job->printer, NULL,
                  (job->printer->type & CUPS_PRINTER_CLASS) ?
@@ -3994,6 +4461,7 @@ update_job(cupsd_job_t *job)              /* I - Job to check */
                      "Printer \"%s\" state changed.",
                  job->printer->name);
 
+
   if (ptr == NULL && !job->status_buffer->bufused)
   {
    /*
@@ -4027,7 +4495,7 @@ update_job(cupsd_job_t *job)              /* I - Job to check */
     * Handle the end of job stuff...
     */
 
-    finalize_job(job);
+    finalize_job(job, 1);
 
    /*
     * Check for new jobs...
@@ -4081,7 +4549,7 @@ update_job_attrs(cupsd_job_t *job,        /* I - Job to update */
   else if (job->printer->state_message[0] && do_message)
     cupsdSetString(&(job->printer_message->values[0].string.text),
                   job->printer->state_message);
-  
+
  /*
   * ... and the printer-state-reasons value...
   */