CUPS stops and restarts jobs

Paul Mitchell pmitchel at email.unc.edu
Tue Feb 14 08:33:31 PST 2012


Hello All,
  Trying to diagnose repeated printings problem we're having printing from
PeopleSoft on a redhat 5 server( 2.6.18-274.7.1.el5 #1). The version of CUPS we're using is 1.3.7.

The job gets accepted on the printer (an HP LaserJet 4515 PCL 6) and prints
30 pages.  CUPS then stops the job, and restarts it..

Here's the beginning of the job:
I [14/Feb/2012:08:03:30 -0500] [Job 904] Adding start banner page "none".
I [14/Feb/2012:08:03:30 -0500] [Job 904] Adding job file of type
application/postscript.
I [14/Feb/2012:08:03:30 -0500] [Job 904] Adding end banner page "none".
I [14/Feb/2012:08:03:30 -0500] [Job 904] Queued on "our142" by "psoft".
D [14/Feb/2012:08:03:30 -0500] [Job 904] hold_until = 0
d [14/Feb/2012:08:03:30 -0500] cupsdCheckJobs: Job 904: state_value=3,
loaded=yes
d [14/Feb/2012:08:03:30 -0500] [Job 904] start_job: file = 0/1
D [14/Feb/2012:08:03:30 -0500] [Job 904] job-sheets=none,none
D [14/Feb/2012:08:03:30 -0500] [Job 904] banner_page = 0
D [14/Feb/2012:08:03:30 -0500] [Job 904] argv[0]="our142"
D [14/Feb/2012:08:03:30 -0500] [Job 904] argv[1]="904"
D [14/Feb/2012:08:03:30 -0500] [Job 904] argv[2]="psoft"
D [14/Feb/2012:08:03:30 -0500] [Job 904] argv[3]="SSR_TSRPT.ps"
D [14/Feb/2012:08:03:30 -0500] [Job 904] argv[4]="1"
D [14/Feb/2012:08:03:30 -0500] [Job 904]
argv[5]="document-name=SSR_TSRPT.ps media=Letter
sides=two-sided-short-edge finishings=3 number-up=1
job-uuid=urn:uuid:9a6cd884-d131-3da5-4333-163e426a2124"

After 29-30 pages, it flushes the job:

d [14/Feb/2012:08:03:48 -0500] cupsdCheckJobs: Job 904: state_value=5,
loaded=yes
d [14/Feb/2012:08:03:48 -0500] cupsdCheckJobs: Job 904: state_value=5,
loaded=yes
d [14/Feb/2012:08:03:48 -0500] [Job 904] cupsdStopJob: force = 1
d [14/Feb/2012:08:03:48 -0500] [Job 904] Closing print pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:48 -0500] [Job 904] Closing back pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:48 -0500] [Job 904] Closing side pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:48 -0500] [Job 904] Closing status pipes [ 16 -1 ]...

Whereupon, CUPS starts the job again with the same Job number:

D [14/Feb/2012:08:03:48 -0500] [Job 904] Loading from cache...
D [14/Feb/2012:08:03:48 -0500] [Job 904] Loading attributes...
d [14/Feb/2012:08:03:49 -0500] cupsdCheckJobs: Job 904: state_value=3,
loaded=yes
d [14/Feb/2012:08:03:49 -0500] [Job 904] start_job: file = 0/1
D [14/Feb/2012:08:03:49 -0500] [Job 904] job-sheets=none,none
D [14/Feb/2012:08:03:49 -0500] [Job 904] banner_page = 0
D [14/Feb/2012:08:03:49 -0500] [Job 904] argv[0]="our142"
D [14/Feb/2012:08:03:49 -0500] [Job 904] argv[1]="904"
D [14/Feb/2012:08:03:49 -0500] [Job 904] argv[2]="psoft"
D [14/Feb/2012:08:03:49 -0500] [Job 904] argv[3]="SSR_TSRPT.ps"
D [14/Feb/2012:08:03:49 -0500] [Job 904] argv[4]="1"
D [14/Feb/2012:08:03:49 -0500] [Job 904]
argv[5]="document-name=SSR_TSRPT.ps media=Letter
sides=two-sided-short-edge finishings=3 number-up=1
job-uuid=urn:uuid:9a6cd884-d131-3da5-4333-163e426a2124"

5 more pages get printed when, unfortunately, we restart again:
d [14/Feb/2012:08:03:50 -0500] cupsdCheckJobs: Job 904: state_value=5,
loaded=yes
d [14/Feb/2012:08:03:50 -0500] [Job 904] cupsdStopJob: force = 1
d [14/Feb/2012:08:03:50 -0500] [Job 904] Closing print pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:50 -0500] [Job 904] Closing back pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:50 -0500] [Job 904] Closing side pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:50 -0500] [Job 904] Closing status pipes [ 14 -1 ]...
d [14/Feb/2012:08:03:50 -0500] cupsdCheckJobs: Job 904: state_value=3,
loaded=yes
d [14/Feb/2012:08:03:50 -0500] [Job 904] start_job: file = 0/1
D [14/Feb/2012:08:03:50 -0500] [Job 904] job-sheets=none,none
D [14/Feb/2012:08:03:50 -0500] [Job 904] banner_page = 0
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[0]="our142"
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[1]="904"
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[2]="psoft"
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[3]="SSR_TSRPT.ps"
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[4]="1"
D [14/Feb/2012:08:03:50 -0500] [Job 904]
argv[5]="document-name=SSR_TSRPT.ps media=Letter
sides=two-sided-short-edge finishings=3 number-up=1
job-uuid=urn:uuid:9a6cd884-d131-3da5-4333-163e426a2124"

4 more pages, then another retstart:

d [14/Feb/2012:08:03:50 -0500] [Job 904] cupsdStopJob: force = 1
d [14/Feb/2012:08:03:50 -0500] [Job 904] Closing print pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:50 -0500] [Job 904] Closing back pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:50 -0500] [Job 904] Closing side pipes [ -1 -1 ]...
d [14/Feb/2012:08:03:50 -0500] [Job 904] Closing status pipes [ 17 -1 ]...
d [14/Feb/2012:08:03:50 -0500] cupsdCheckJobs: Job 904: state_value=3,
loaded=yes
d [14/Feb/2012:08:03:50 -0500] [Job 904] start_job: file = 0/1
D [14/Feb/2012:08:03:50 -0500] [Job 904] job-sheets=none,none
D [14/Feb/2012:08:03:50 -0500] [Job 904] banner_page = 0
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[0]="our142"
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[1]="904"
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[2]="psoft"
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[3]="SSR_TSRPT.ps"
D [14/Feb/2012:08:03:50 -0500] [Job 904] argv[4]="1"
D [14/Feb/2012:08:03:50 -0500] [Job 904]
argv[5]="document-name=SSR_TSRPT.ps media=Letter
sides=two-sided-short-edge finishings=3 number-up=1
job-uuid=urn:uuid:9a6cd884-d131-3da5-4333-163e426a2124"
D [14/Feb/2012:08:03:50 -0500] [Job 904]
argv[6]="/var/spool/cups/d00904-001"

and so on. There are actually 5 times in the log file of this job when the
following line appears, with different time stamps:

D [14/Feb/2012:08:03:30 -0500] [Job 904]
argv[5]="document-name=SSR_TSRPT.ps media=Letter
sides=two-sided-short-edge finishings=3 number-up=1
job-uuid=urn:uuid:9a6cd884-d131-3da5-4333-163e426a2124"

I need to discover the flag in CUPS which stops the restart process and
directs CUPS to continue where it left off.  I'm *admin* on the printer,
and there are no events occurring on the printer which would force a
restart of the print job.  Would retry-current-job under the ErrorPolicy
solve this problem?

I should mention that yesterday, at noon, we routed 4 jobs through the printer with no problems, so I'm wondering if it's a function of network noise between 8-9 AM (when the output is actually required).

Thanks for any help,

Paul Mitchell





More information about the cups mailing list