[cups] CUPS sometimes losing jobs upon restart

[Michael Sweet]

Nick,

I'm guessing that there is a job in the printer when it gets shut off, and that CUPS thinks that the job has been successfully accepted by the printer.  Depending on the protocol being used to talk to the printer, we may or may not be able to know whether the job has been completely printed.

The proper way to manage this sort of thing is to run the "cupsdisable" command on the print queue before turning the printer off - that will stop processing of the current job.  If you are running CUPS 2.0 or later you can also use the --hold option to allow the current job to complete.

Similarly, in the morning you want to run the "cupsenable" command to start job processing again, after the printer has been turned on.

If you allow the printer to go into its sleep state (vs. physically powering it off) then all you need it to add the cupsdisable/enable commands to cron jobs that run at the appropriate times.  The printer will go to sleep overnight automatically...


> On Aug 24, 2015, at 1:46 PM, Nick Hall <darknovanick at gmail.com> wrote:
> 
> In our typical day we print orders with CUPS every few minutes, but at 5pm
> the printer gets shut off but orders continue to come in and are printed.
> These orders queue up in CUPS until the printer is turned back on around
> 7am, at which point all the orders that came in overnight are printed.
> 
> CUPS is reloaded every morning at 6:35am by logrotate.
> 
> For most jobs this process works totally fine. But we have noticed that
> every few days, CUPS loses a job. The job it loses appears to be the first
> job that was printed after the printer was turned off at 5pm, so the first
> job in a queue of perhaps 100 jobs.
> 
> Here is some output from error_log for an example job:
> 
> This was the first job printed after the printer was turned off:
> I [07/Aug/2015:17:24:36 -0500] [Job 498606] Adding start banner page "none".
> 
> Now jobs continue to print and are queued up as CUPS cannot talk to the
> printer since it is up.
> 
> The next day, logrotate reloads CUPS:
> 
> D [08/Aug/2015:06:36:28 -0500] [Job 498606] Loading from cache...
> I [08/Aug/2015:06:36:28 -0500] [Job 498606] Data files have gone away!
> E [08/Aug/2015:06:36:28 -0500] Bad File number 1 on line 88798!
> D [08/Aug/2015:06:36:28 -0500] [Job 498606] Loading attributes...
> E [08/Aug/2015:06:36:37 -0500] [Job 498606] Aborting job because it has no
> files.
> 
> 
> So you can see that it gives this "Bad File number 1" error and then
> "Aborting job because it has no files", and the job is lost. The rest of
> the jobs in the queue are fine.
> 
> And this doesn't always happen -- perhaps 70% of the time CUPS is reloaded
> it doesn't lose any jobs, but 30% of the time it loses the first job in the
> queue.
> 
> 
> This is CUPS version 1.5.3-5+deb7u6 which is part of Debian wheezy.
> 
> Does anyone know what is going on or have a suggestion of what I can do to
> track down this problem? Thanks,
> 
> Nick
> _______________________________________________
> cups mailing list
> cups at cups.org
> https://www.cups.org/mailman/listinfo/cups

_________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair