[cups] CUPS sometimes losing jobs upon restart

[Nick Hall]

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