Waiting for printer to finish - error

Anonymous anonymous at easysw.com
Fri Jan 7 12:09:58 PST 2005 

Helge Blischke wrote:
> Well, it seems that the printer isn't giving anything back to the
> socket backend. It may well be that the printer requires some more
> PJL commands to talk back anything (a @PLJ JOB or the like).
>
> Your could either edit the printer's PPD and add PJL thesssssssssss
> appropriate statements to the *JCLBegin: value, or simly use hpnpf
> as backend:
>
>   lpadmin -p sdlpgreg -E -v hpnpf://sdlpgreg:9100
>
> You get an additional /var/log/cups/status_log.sdlpgreg file
> which collects alle the INFO:... lines and, very useful, any
> messages (including errors) the PostScript interpreter prints
> to its standard output or standard error.
>
> Helge
>
> peter at castandcrew.com wrote:
> >
> > Sorry for the late response.
> >
> > Well, hpnpf actually worked. What I mean is
> > that if I use hpnpf command the printer goes back
> > to ready state. Btw, the printer is HP LaserJet 4050N.
> >
> > Here is the test result step by step:
> >
> >  lpadmin -p sdlpgreg -E -v socket://sdlpgreg:9100
> >  ./hpnpf -x sdlpgreg -vW -l test_print.log testfile
> >
> > The test file printed successfully and the printer went back to ready
> > state.
> >
> > ==> Stdout of hpnpf command:
> > ===
> > [48,sduser-p1:peter] # ./hpnpf -x sdlpgreg -vW -l test_print.log testfile
> > Connecting to sdlpgreg ... connected
> > Sending file testfile
> >
> > token = @PJL USTATUS PAGE
> > token = 1
> > token = ID=93
> > token = @PJL USTATUS JOB
> > token = END
> > token = NAME="sduser.23498"
> > token = PAGES=0
> > token = ID=94
> > token = RESULT=OK
> > ===
> >
> > ==> hpnpf log file test_print.log
> > ===
> > 18:31:50 hpnpf[23498] OpenLog: logging started
> > 18:31:50 hpnpf[23498] Process: entered
> > 18:31:50 hpnpf[23498] ResolveAddress: sdlpgreg
> > 18:31:50 hpnpf[23498] OpenSocket: entered
> > 18:31:50 hpnpf[23498] OpenSocket: using 16K send buffer
> > 18:31:50 hpnpf[23498] MakeConnection: 10.1.1.104, port 9100
> > 18:31:50 hpnpf[23498] DoNonBlocking: non-blocking on
> > 18:31:50 hpnpf[23498] Process: sending file testfile
> > 18:31:50 hpnpf[23498] SendFile: entered (TBCP=0)
> > 18:31:50 hpnpf[23498] SendFile: 20 bytes read from host
> > 18:31:50 hpnpf[23498] SendFile: 0 bytes read from host
> > 18:31:50 hpnpf[23498] SendFile: 20 bytes written to socket
> > 18:31:50 hpnpf[23498] DoNonBlocking: non-blocking off
> > 18:32:05 hpnpf[23498] Process: 30 bytes read from socket
> > 18:32:05 hpnpf[23498] @PJL USTATUS PAGE
> > 18:32:05 hpnpf[23498] 1
> > 18:32:05 hpnpf[23498] ID=93
> > 18:32:05 hpnpf[23498] Process: 72 bytes read from socket
> > 18:32:05 hpnpf[23498] @PJL USTATUS JOB
> > 18:32:05 hpnpf[23498] END
> > 18:32:05 hpnpf[23498] NAME="sduser.23498"
> > 18:32:05 hpnpf[23498] PAGES=0
> > 18:32:05 hpnpf[23498] ID=94
> > 18:32:05 hpnpf[23498] RESULT=OK
> > 18:32:05 hpnpf[23498] Process: read EOF on socket
> > 18:32:05 hpnpf[23498] StopLog: logging stopped
> > ===
> >
> > After printing with hpnpf the lpstat -t command shows that the printer
> > is idle. That is what I need but without using hpnpf utility. :-)
> >
> > Thank you Helge for your response.
> >
> > If there is anything I can do to help debugging this problem
> > please let me know.
> >
> > Thanks
> > Peter Blajev
> >
> > Helge Blischke wrote:
> > > 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
>
> --
> Helge Blischke
> Softwareentwicklung
> SRZ Berlin | Firmengruppe besscom
> http://www.srz.de
> tel: +49 30 75301-360

More information about the cups mailing list