Why Are Some Users' Jobs Always Held Pending?

[Helge Blischke]

Brian White wrote:
> Still fighting with this...  Anybody have any ideas?
> 
> Brian White wrote:
> 
>>> If you set "LogLevel debug" on the server -- do you see any
>>> suspicious job-option set? Like "job-hold-until=indefinite"?
>>
>>
>>
>> That helps.  It seems that those computers that have the correct driver
>> installed via Samba are the ones having the problem.  Their print
>> requests appear as "application/postscript" while the other (working)
>> ones appear as "application/vnd.cups-raw".
>>
>> There was a bug in "cupsaddsmb" that was greating driver "ppd" files
>> with all cr/lf characters removed.  That bug has been fixed (see my
>> other news post).
>>
>> Here is a job that gets held pending...
>>
>> D [20/Jun/2006:13:16:45 -0400] AcceptClient: 5 from
>> titan.ott.precidia.com:631.
>> D [20/Jun/2006:13:16:45 -0400] ReadClient: 5 POST /printers/Doyle 
>> HTTP/1.1
>> D [20/Jun/2006:13:16:45 -0400] ProcessIPPRequest: 5 status_code=1
>> D [20/Jun/2006:13:16:45 -0400] ReadClient: 5 POST /printers/Doyle 
>> HTTP/1.1
>> D [20/Jun/2006:13:16:45 -0400] print_job: request file type is
>> application/postscript.
>> D [20/Jun/2006:13:16:45 -0400] CancelJob: id = 778
>> D [20/Jun/2006:13:16:45 -0400] check_quotas: requesting-user-name =
>> 'bcwhite'
>> D [20/Jun/2006:13:16:45 -0400] print_job: requesting-user-name = 
>> 'bcwhite'
>> D [20/Jun/2006:13:16:45 -0400] SetJobHoldUntil(1278,
>> "no-hold<0A>%!PS-Adobe-3.0")
>> D [20/Jun/2006:13:16:45 -0400] SetJobHoldUntil: hold_until = 0
>> D [20/Jun/2006:13:16:45 -0400] Adding default job-sheets values
>> "none,none"...
>> I [20/Jun/2006:13:16:45 -0400] Adding start banner page "none" to job 
>> 1278.
>> I [20/Jun/2006:13:16:45 -0400] Adding end banner page "none" to job 1278.
>> I [20/Jun/2006:13:16:45 -0400] Job 1278 queued on 'Doyle' by 'bcwhite'.
>> D [20/Jun/2006:13:16:45 -0400] Job 1278 hold_until = 0
>> D [20/Jun/2006:13:16:45 -0400] ProcessIPPRequest: 5 status_code=0
>> D [20/Jun/2006:13:16:45 -0400] ReadClient: 5 POST /printers/Doyle 
>> HTTP/1.1
>> D [20/Jun/2006:13:16:45 -0400] ProcessIPPRequest: 5 status_code=1
>> D [20/Jun/2006:13:16:45 -0400] ReadClient: 5 POST /printers/Doyle 
>> HTTP/1.1
>> D [20/Jun/2006:13:16:45 -0400] ProcessIPPRequest: 5 status_code=1
>> D [20/Jun/2006:13:16:45 -0400] CloseClient: 5
>>
>> It says "no-hold" and "hold_until = 0" and yet still gets held.  In
>> contrast, one that prints immediately looks like this:
>>
>> D [20/Jun/2006:13:04:51 -0400] AcceptClient: 8 from
>> titan.ott.precidia.com:631.
>> D [20/Jun/2006:13:04:51 -0400] ReadClient: 8 POST /printers/Doyle 
>> HTTP/1.1
>> D [20/Jun/2006:13:04:51 -0400] ProcessIPPRequest: 8 status_code=1
>> D [20/Jun/2006:13:04:51 -0400] ReadClient: 8 POST /printers/Doyle 
>> HTTP/1.1
>> D [20/Jun/2006:13:04:51 -0400] print_job: request file type is
>> application/vnd.cups-raw.
>> D [20/Jun/2006:13:04:51 -0400] CancelJob: id = 776
>> D [20/Jun/2006:13:04:51 -0400] check_quotas: requesting-user-name =
>> 'fschafer'
>> D [20/Jun/2006:13:04:51 -0400] print_job: requesting-user-name = 
>> 'fschafer'
>> D [20/Jun/2006:13:04:51 -0400] Adding default job-sheets values
>> "none,none"...
>> I [20/Jun/2006:13:04:51 -0400] Adding start banner page "none" to job 
>> 1276.
>> I [20/Jun/2006:13:04:51 -0400] Adding end banner page "none" to job 1276.
>> I [20/Jun/2006:13:04:51 -0400] Job 1276 queued on 'Doyle' by 'fschafer'.
>> D [20/Jun/2006:13:04:51 -0400] Job 1276 hold_until = 0
>> D [20/Jun/2006:13:04:51 -0400] StartJob(1276, 0x80b8b50)
>> D [20/Jun/2006:13:04:51 -0400] StartJob() id = 1276, file = 0/1
>> D [20/Jun/2006:13:04:51 -0400] job-sheets=none,none
>> D [20/Jun/2006:13:04:51 -0400] banner_page = 0
>> D [20/Jun/2006:13:04:51 -0400] StartJob: argv =
>> "Doyle","1276","fschafer","smbprn.00000077 All Journal
>> Entries","1","","/var/spool/cups/d01276-001"
>> D [20/Jun/2006:13:04:51 -0400] StartJob:
>> envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
>> D [20/Jun/2006:13:04:51 -0400] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
>> D [20/Jun/2006:13:04:51 -0400] StartJob: envp[2]="USER=root"
>> [...]
>>
>> I guess the question here is:  Why do the postscript jobs get held?
>>
>> Thanks!
> 
> 
>                                           Brian
>                                  ( bcwhite at precidia.com )
> 
> ------------------------------------------------------------------------------- 
> 
>         We seldom regret doing things.  We often regret not doing them.

I suspect the following message (from your error_log) will point to the cause:

D [20/Jun/2006:13:16:45 -0400] SetJobHoldUntil(1278,"no-hold<0A>%!PS-Adobe-3.0")
                                                             ^^^^^^^^^^^^^^^^^^
I suspect the PPD file copied to your Windows box is somehow corrupted - the <0A> for
denoting a newline should only occur *within* snippets to be copied into the PS stream.
The string above is not a valid option value, so the scheduler might get disturbed.

Helge


-- 
Helge Blischke
Softwareentwicklung
SRZ Berlin | Firmengruppe besscom
http://www.srz.de