Waiting for printer to finish - error

Fri Dec 10 05:53:39 PST 2004

Hm, the status message should read "Ready to print" or something like
this.
It seems that the printer isn't giving any reply (perhaps an old
JetDirect firmweare?),
or the socket backend in 1.1.22 is broken.

Perhaps you try out the hpnpf backend (see the links on the CUPS web
site) and report
what that is logging.

Helge

peter at castandcrew.com wrote:
> 
> Hi,
> 
> I just install CUPS-1.1.22 on a RedHat 9 box.
> I compiled it and installed it from source. Everything went smoothly.
> Got no errors.
> 
> Before I start the server here is what I changed in cupsd.conf:
>   FileDevice Yes
>   PreserveJobHistory No
> 
> The only printer I added is a network HP LaserJet 4050
>   lpadmin -p sdlpgreg -E -v socket://sdlpgreg:9100
> 
> To test printing I ran this command:
>   echo "test" | lp -d sdlpgreg
> 
> The page printed but here is the output of lpstat command:
>   scheduler is running
>   system default destination: sdlpgreg
>   device for sdlpgreg: socket://sdlpgreg:9100
>   sdlpgreg accepting requests since Jan 01 00:00
>   printer sdlpgreg is idle.  enabled since Jan 01 00:00
>         Print file sent, waiting for printer to finish...
> 
> The message "Print file sent, waiting for printer to finish..." stays there
> until CUPS is restarted.
> 
> In general everything print but what makes people complain is when they
> print from Windows (through SAMBA) the print queue icon stays in the system
> tray and never go away even if there is nothing in the queue.
> 
> I assume the CUPS message and the print icon problem are related, aren't they?
> 
> The previous version of CUPS I use is 1.1.18 and have no problems there.
> 
> Please, any suggestions, tips, anything that may help.
> 
> Thank you for your time and for the great product.
> Peter
> 
> Here is the log output of the print command:
> ====
> D [09/Dec/2004:14:40:55 -0800] AcceptClient: 5 from localhost:631.
> D [09/Dec/2004:14:40:55 -0800] ReadClient: 5 POST / HTTP/1.1
> D [09/Dec/2004:14:40:55 -0800] ProcessIPPRequest: 5 status_code=1
> D [09/Dec/2004:14:40:55 -0800] ReadClient: 5 POST / HTTP/1.1
> D [09/Dec/2004:14:40:55 -0800] ProcessIPPRequest: 5 status_code=1
> D [09/Dec/2004:14:40:55 -0800] ReadClient: 5 POST / HTTP/1.1
> D [09/Dec/2004:14:40:55 -0800] ProcessIPPRequest: 5 status_code=0
> D [09/Dec/2004:14:40:55 -0800] CloseClient: 5
> D [09/Dec/2004:14:40:55 -0800] AcceptClient: 5 from localhost:631.
> D [09/Dec/2004:14:40:55 -0800] ReadClient: 5 POST /printers/sdlpgreg HTTP/1.1
> D [09/Dec/2004:14:40:55 -0800] print_job: auto-typing file...
> D [09/Dec/2004:14:40:55 -0800] print_job: request file type is text/plain.
> D [09/Dec/2004:14:40:55 -0800] check_quotas: requesting-user-name = 'root'
> D [09/Dec/2004:14:40:55 -0800] print_job: requesting-user-name = 'root'
> I [09/Dec/2004:14:40:55 -0800] Adding start banner page "none" to job 3.
> I [09/Dec/2004:14:40:55 -0800] Adding end banner page "none" to job 3.
> I [09/Dec/2004:14:40:55 -0800] Job 3 queued on 'sdlpgreg' by 'root'.
> D [09/Dec/2004:14:40:55 -0800] Job 3 hold_until = 0
> D [09/Dec/2004:14:40:55 -0800] StartJob(3, 0x8089288)
> D [09/Dec/2004:14:40:55 -0800] StartJob() id = 3, file = 0/1
> D [09/Dec/2004:14:40:55 -0800] StartJob: Sending job to queue tagged as raw...
> D [09/Dec/2004:14:40:55 -0800] job-sheets=none,none
> D [09/Dec/2004:14:40:55 -0800] banner_page = 0
> D [09/Dec/2004:14:40:55 -0800] StartJob: argv = "sdlpgreg","3","root","(stdin)","1","","/var/spool/cups/d00003-001"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[2]="USER=root"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[3]="CHARSET=iso-8859-1"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[4]="LANG=en"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[5]="TZ=America/Los_Angeles"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[6]="PPD=/etc/cups/ppd/sdlpgreg.ppd"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[7]="CUPS_SERVERROOT=/etc/cups"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[8]="RIP_MAX_CACHE=8m"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[9]="TMPDIR=/var/spool/cups/tmp"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[10]="CONTENT_TYPE=text/plain"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[11]="DEVICE_URI=socket://sdlpgreg:9100"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[12]="PRINTER=sdlpgreg"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[13]="CUPS_DATADIR=/usr/share/cups"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[14]="CUPS_FONTPATH=/usr/share/cups/fonts"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[15]="CUPS_SERVER=localhost"
> D [09/Dec/2004:14:40:55 -0800] StartJob: envp[16]="IPP_PORT=631"
> D [09/Dec/2004:14:40:55 -0800] StartJob: statusfds = [ 7 8 ]
> D [09/Dec/2004:14:40:55 -0800] StartJob: filterfds[1] = [ 9 -1 ]
> D [09/Dec/2004:14:40:55 -0800] StartJob: backend = "/usr/lib/cups/backend/socket"
> D [09/Dec/2004:14:40:55 -0800] StartJob: filterfds[0] = [ -1 10 ]
> D [09/Dec/2004:14:40:55 -0800] start_process("/usr/lib/cups/backend/socket", 0xbffef160, 0xbffee4d0, 9, 10, 8)
> I [09/Dec/2004:14:40:55 -0800] Started backend /usr/lib/cups/backend/socket (PID 26921) for job 3.
> D [09/Dec/2004:14:40:55 -0800] ProcessIPPRequest: 5 status_code=0
> D [09/Dec/2004:14:40:55 -0800] CloseClient: 5
> D [09/Dec/2004:14:40:55 -0800] UpdateJob: job 3, file 0 is complete.
> D [09/Dec/2004:14:40:55 -0800] CancelJob: id = 3
> D [09/Dec/2004:14:40:55 -0800] StopJob: id = 3, force = 0
> D [09/Dec/2004:14:40:55 -0800] StopJob: printer state is 3
> ===

-- 
Helge Blischke
Softwareentwicklung
SRZ Berlin | Firmengruppe besscom
http://www.srz.de
tel: +49 30 75301-360