cups renderer problem
Hi,
my cups installation stopped working, after working for a long time.
Last successful print was about a month ago (I did not try it in the
last weeks).
I am no longer able to print, not even the testpage from the cups
webinterface.
The printer is a hp officejet 5510, but I suspect that it is more a
problem with the renderer (see the logfile below).
I am not aware that I changed anything at the cups (or
gs/gv) configuration. I update the debian box every few days with
apt-get update && apt-get dist-upgrade.
The /var/log/cups/error_log suggests, that the renderer fails:
D [12/Mar/2006:13:52:24 +0100] AcceptClient: 5 from localhost:631.
D [12/Mar/2006:13:52:24 +0100] ReadClient: 5 GET
/printers/ojetsw?op=print-test-page HTTP/1.1
D [12/Mar/2006:13:52:24 +0100] CGI /usr/lib/cups/cgi-bin/printers.cgi
started - PID = 9490
I [12/Mar/2006:13:52:24 +0100] Started
"/usr/lib/cups/cgi-bin/printers.cgi" (pid=9490)
D [12/Mar/2006:13:52:24 +0100] SendCommand: 5 file=8
D [12/Mar/2006:13:52:24 +0100] AcceptClient: 7 from localhost:631.
D [12/Mar/2006:13:52:24 +0100] ReadClient: 7 POST /printers/ojetsw HTTP/1.1
D [12/Mar/2006:13:52:24 +0100] print_job: request file type is
application/postscript.
D [12/Mar/2006:13:52:24 +0100] check_quotas: requesting-user-name = ''
D [12/Mar/2006:13:52:24 +0100] print_job: requesting-user-name = ''
D [12/Mar/2006:13:52:24 +0100] Adding default job-sheets values
"none,none"...
I [12/Mar/2006:13:52:24 +0100] Adding start banner page "none" to job 120.
I [12/Mar/2006:13:52:24 +0100] Adding end banner page "none" to job 120.
I [12/Mar/2006:13:52:24 +0100] Job 120 queued on 'ojetsw' by ''.
D [12/Mar/2006:13:52:24 +0100] Job 120 hold_until = 0
D [12/Mar/2006:13:52:24 +0100] StartJob(120, 0x80949f8)
D [12/Mar/2006:13:52:24 +0100] StartJob() id = 120, file = 0/1
D [12/Mar/2006:13:52:24 +0100] job-sheets=none,none
D [12/Mar/2006:13:52:24 +0100] banner_page = 0
D [12/Mar/2006:13:52:24 +0100] StartJob: argv = "ojetsw","120","","Test
Page","1","","/var/spool/cups/d00120-001"
D [12/Mar/2006:13:52:24 +0100] StartJob:
envp[0]="PATH=/usr/lib/cups/filter:/bin:/usr/bin"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[1]="SOFTWARE=CUPS/1.1"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[2]="USER=root"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[3]="CHARSET=iso-8859-15"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[4]="LANG=de"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[5]="TZ=Europe/Berlin"
D [12/Mar/2006:13:52:24 +0100] StartJob:
envp[6]="PPD=/etc/cups/ppd/ojetsw.ppd"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[7]="CUPS_SERVERROOT=/etc/cups"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[8]="RIP_MAX_CACHE=8m"
D [12/Mar/2006:13:52:24 +0100] StartJob:
envp[9]="TMPDIR=/var/spool/cups/tmp"
D [12/Mar/2006:13:52:24 +0100] StartJob:
envp[10]="CONTENT_TYPE=application/postscript"
D [12/Mar/2006:13:52:24 +0100] StartJob:
envp[11]="DEVICE_URI=usb:/dev/hp_5510"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[12]="PRINTER=ojetsw"
D [12/Mar/2006:13:52:24 +0100] StartJob:
envp[13]="CUPS_DATADIR=/usr/share/cups"
D [12/Mar/2006:13:52:24 +0100] StartJob:
envp[14]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[15]="CUPS_SERVER=localhost"
D [12/Mar/2006:13:52:24 +0100] StartJob: envp[16]="IPP_PORT=631"
D [12/Mar/2006:13:52:24 +0100] StartJob: statusfds = [ 9 11 ]
D [12/Mar/2006:13:52:24 +0100] StartJob: filterfds[1] = [ 12 -1 ]
D [12/Mar/2006:13:52:24 +0100] StartJob: filter =
"/usr/lib/cups/filter/pstops"
D [12/Mar/2006:13:52:24 +0100] StartJob: filterfds[0] = [ 13 14 ]
D [12/Mar/2006:13:52:24 +0100]
start_process("/usr/lib/cups/filter/pstops", 0xbfab61e0, 0xbfab5758, 12,
14, 11)
I [12/Mar/2006:13:52:24 +0100] Started filter
/usr/lib/cups/filter/pstops (PID 9491) for job 120.
D [12/Mar/2006:13:52:24 +0100] StartJob: filter =
"/usr/lib/cups/filter/foomatic-rip"
D [12/Mar/2006:13:52:24 +0100] StartJob: filterfds[1] = [ 12 15 ]
D [12/Mar/2006:13:52:24 +0100]
start_process("/usr/lib/cups/filter/foomatic-rip", 0xbfab61e0,
0xbfab5758, 13, 15, 11)
I [12/Mar/2006:13:52:24 +0100] Started filter
/usr/lib/cups/filter/foomatic-rip (PID 9492) for job 120.
D [12/Mar/2006:13:52:24 +0100] StartJob: backend =
"/usr/lib/cups/backend/usb"
D [12/Mar/2006:13:52:24 +0100] StartJob: filterfds[0] = [ -1 13 ]
D [12/Mar/2006:13:52:24 +0100]
start_process("/usr/lib/cups/backend/usb", 0xbfab61e0, 0xbfab5758, 12,
13, 11)
I [12/Mar/2006:13:52:24 +0100] Started backend /usr/lib/cups/backend/usb
(PID 9493) for job 120.
D [12/Mar/2006:13:52:24 +0100] ProcessIPPRequest: 7 status_code=0
D [12/Mar/2006:13:52:24 +0100] [Job 120] Page = 595x842; 10,36 to 585,833
D [12/Mar/2006:13:52:24 +0100] [Job 120] slowcollate=0, slowduplex=0,
sloworder=0
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%BoundingBox: 0 0 612 792
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%Pages: 1
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%LanguageLevel: 1
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%DocumentData: Clean7Bit
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%DocumentSuppliedResources:
procset testprint/1.1
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%DocumentNeededResources:
font Helvetica Helvetica-Bold Times-Roman
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%Creator: Michael Sweet,
Easy Software Products
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%CreationDate: May 11, 1999
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%Title: Test Page
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%EndComments
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%BeginProlog
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%BeginResource procset
testprint 1.1 0
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%EndResource
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%EndProlog
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%Page: 1 1
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%Page: 1 1
D [12/Mar/2006:13:52:24 +0100] [Job 120] pw = 575.6, pl = 797.0
D [12/Mar/2006:13:52:24 +0100] [Job 120] PageLeft = 9.7, PageRight = 585.3
D [12/Mar/2006:13:52:24 +0100] [Job 120] PageTop = 833.0, PageBottom = 36.0
D [12/Mar/2006:13:52:24 +0100] [Job 120] PageWidth = 595.0, PageLength =
842.0
D [12/Mar/2006:13:52:24 +0100] [Job 120] 0 %%EOF
D [12/Mar/2006:13:52:24 +0100] [Job 120] Saw EOF!
D [12/Mar/2006:13:52:25 +0100] CloseClient: 7
D [12/Mar/2006:13:52:25 +0100] [Job 120] perl: warning: Setting locale
failed.
D [12/Mar/2006:13:52:25 +0100] [Job 120] perl: warning: Please check
that your locale settings:
D [12/Mar/2006:13:52:25 +0100] [Job 120] LANGUAGE = (unset),
D [12/Mar/2006:13:52:25 +0100] [Job 120] LC_ALL = (unset),
D [12/Mar/2006:13:52:25 +0100] [Job 120] LANG = "de"
D [12/Mar/2006:13:52:25 +0100] [Job 120] are supported and installed on
your system.
D [12/Mar/2006:13:52:25 +0100] [Job 120] perl: warning: Falling back to
the standard locale ("C").
D [12/Mar/2006:13:52:25 +0100] ReadClient: 5 GET /favicon.ico HTTP/1.1
D [12/Mar/2006:13:52:25 +0100] SendError: 5 code=404 (Not Found)
D [12/Mar/2006:13:52:25 +0100] CloseClient: 5
D [12/Mar/2006:13:52:25 +0100] [Job 120] foomatic-rip version $Revision:
3.43.2.15 $ running...
D [12/Mar/2006:13:52:25 +0100] [Job 120] Parsing PPD file ...
D [12/Mar/2006:13:52:25 +0100] [Job 120] *cupsFilter:
"application/vnd.cups-postscript 0 foomatic-rip"
D [12/Mar/2006:13:52:25 +0100] [Job 120] Added option ColorSpace
D [12/Mar/2006:13:52:25 +0100] [Job 120] Added option Resolution
D [12/Mar/2006:13:52:25 +0100] [Job 120] Added option PageSize
D [12/Mar/2006:13:52:25 +0100] [Job 120] Added option PageRegion
D [12/Mar/2006:13:52:25 +0100] [Job 120] Added option Model
D [12/Mar/2006:13:52:25 +0100] [Job 120] Added option PrintoutMode
D [12/Mar/2006:13:52:26 +0100] [Job 120] Added option ImageableArea
D [12/Mar/2006:13:52:26 +0100] [Job 120] Added option PaperDimension
D [12/Mar/2006:13:52:26 +0100] [Job 120] Added option Quality
D [12/Mar/2006:13:52:26 +0100] [Job 120] Added option Font
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] Parameter Summary
D [12/Mar/2006:13:52:26 +0100] [Job 120] -----------------
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] Spooler: cups
D [12/Mar/2006:13:52:26 +0100] [Job 120] Printer: ojetsw
D [12/Mar/2006:13:52:26 +0100] [Job 120] PPD file: /etc/cups/ppd/ojetsw.ppd
D [12/Mar/2006:13:52:26 +0100] [Job 120] Printer model: HP OfficeJet
5500 Foomatic/hpijs (recommended)
D [12/Mar/2006:13:52:26 +0100] [Job 120] Job title: Test Page
D [12/Mar/2006:13:52:26 +0100] [Job 120] File(s) to be printed:
D [12/Mar/2006:13:52:26 +0100] [Job 120] <STDIN>
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] GhostScript extra search path
('GS_LIB'): /usr/share/cups/fonts
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120]
================================================
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] File: <STDIN>
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120]
================================================
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] Reading PostScript input ...
D [12/Mar/2006:13:52:26 +0100] [Job 120] --> This document is
DSC-conforming!
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] -----------
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%BeginProlog
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%EndProlog
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] -----------
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%BeginSetup
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%BeginFeature:
*PrintoutMode Draft
D [12/Mar/2006:13:52:26 +0100] [Job 120] Option: PrintoutMode=Draft -->
Setting option
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%
FoomaticRIPOptionSetting: PrintoutMode=Draft
D [12/Mar/2006:13:52:26 +0100] [Job 120] Option: PrintoutMode=Draft -->
Setting option
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%BeginFeature: *Quality
300GrayscaleK
D [12/Mar/2006:13:52:26 +0100] [Job 120] Option: Quality=300GrayscaleK
--> Setting option
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%
FoomaticRIPOptionSetting: Quality=300GrayscaleK
D [12/Mar/2006:13:52:26 +0100] [Job 120] Option: Quality=300GrayscaleK
--> Setting option
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%BeginFeature: *PageSize A4
D [12/Mar/2006:13:52:26 +0100] [Job 120] Option: PageSize=A4 --> Setting
option
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%
FoomaticRIPOptionSetting: PageSize=A4
D [12/Mar/2006:13:52:26 +0100] [Job 120] Option: PageSize=A4 --> Setting
option
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found: %%EndSetup
D [12/Mar/2006:13:52:26 +0100] [Job 120] Inserting PostScript code for
CUPS' page accounting
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] -----------
D [12/Mar/2006:13:52:26 +0100] [Job 120] New page: 1 1
D [12/Mar/2006:13:52:26 +0100] [Job 120] Inserting option code into
"PageSetup" section.
D [12/Mar/2006:13:52:26 +0100] [Job 120] No page header or page header
not DSC-conforming
D [12/Mar/2006:13:52:26 +0100] [Job 120] Stopping search for page header
options
D [12/Mar/2006:13:52:26 +0100] [Job 120] Found:
D [12/Mar/2006:13:52:26 +0100] [Job 120] pageHeight sub % Move down...
D [12/Mar/2006:13:52:26 +0100] [Job 120] --> Output goes directly to the
renderer now.
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] Starting renderer
D [12/Mar/2006:13:52:26 +0100] [Job 120] JCL: <job data>
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] renderer PID kid4=9497
D [12/Mar/2006:13:52:26 +0100] [Job 120] renderer command: gs -q -dBATCH
-dPARANOIDSAFER -dQUIET -dNOPAUSE -sDEVICE=ijs -sIjsServer=hpijs
-sDeviceManufacturer="HEWLETT-PACKARD" -sDeviceModel="deskjet 3600"
-dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -r300
-sIjsParams=Quality:Quality=0,Quality:ColorMode=0,Quality:MediaType=0,Quality:PenSet=0
-dIjsUseOutputFD -sOutputFile=- -
D [12/Mar/2006:13:52:26 +0100] [Job 120]
D [12/Mar/2006:13:52:26 +0100] [Job 120] Closing renderer
D [12/Mar/2006:13:52:26 +0100] [Job 120] perl: warning: Setting locale
failed.
D [12/Mar/2006:13:52:26 +0100] [Job 120] perl: warning: Please check
that your locale settings:
D [12/Mar/2006:13:52:26 +0100] [Job 120] LANGUAGE = (unset),
D [12/Mar/2006:13:52:26 +0100] [Job 120] LC_ALL = (unset),
D [12/Mar/2006:13:52:26 +0100] [Job 120] LANG = "de"
D [12/Mar/2006:13:52:26 +0100] [Job 120] are supported and installed on
your system.
D [12/Mar/2006:13:52:26 +0100] [Job 120] perl: warning: Falling back to
the standard locale ("C").
D [12/Mar/2006:13:52:26 +0100] [Job 120] foomatic-gswrapper: gs
'-dBATCH' '-dPARANOIDSAFER' '-dQUIET' '-dNOPAUSE' '-sDEVICE=ijs'
'-sIjsServer=hpijs' '-sDeviceManufacturer=HEWLETT-PACKARD'
'-sDeviceModel=deskjet 3600' '-dDEVICEWIDTHPOINTS=595'
'-dDEVICEHEIGHTPOINTS=842' '-r300'
'-sIjsParams=Quality:Quality=0,Quality:ColorMode=0,Quality:MediaType=0,Quality:PenSet=0'
'-dIjsUseOutputFD' '-sOutputFile=/dev/fd/3' '/dev/fd/0' 3>&1 1>&2
E [12/Mar/2006:13:52:27 +0100] [Job 120] Unable to send print file to
printer: Invalid argument
above I see the first unusual thing: Unable to send print file to
printer: Invalid argument
This is also, what is reported in the web interface.
E [12/Mar/2006:13:52:27 +0100] PID 9493 stopped with status 1!
D [12/Mar/2006:13:52:29 +0100] AcceptClient: 5 from localhost:631.
D [12/Mar/2006:13:52:29 +0100] ReadClient: 5 GET /printers/ojetsw HTTP/1.1
D [12/Mar/2006:13:52:29 +0100] CGI /usr/lib/cups/cgi-bin/printers.cgi
started - PID = 9501
I [12/Mar/2006:13:52:29 +0100] Started
"/usr/lib/cups/cgi-bin/printers.cgi" (pid=9501)
D [12/Mar/2006:13:52:29 +0100] SendCommand: 5 file=8
D [12/Mar/2006:13:52:29 +0100] AcceptClient: 7 from localhost:631.
D [12/Mar/2006:13:52:29 +0100] ReadClient: 7 POST / HTTP/1.1
D [12/Mar/2006:13:52:29 +0100] ProcessIPPRequest: 7 status_code=1
D [12/Mar/2006:13:52:30 +0100] ReadClient: 7 POST / HTTP/1.1
D [12/Mar/2006:13:52:30 +0100] ProcessIPPRequest: 7 status_code=1
D [12/Mar/2006:13:52:30 +0100] ReadClient: 7 POST / HTTP/1.1
D [12/Mar/2006:13:52:30 +0100] ProcessIPPRequest: 7 status_code=1
D [12/Mar/2006:13:52:30 +0100] CloseClient: 7
D [12/Mar/2006:13:52:30 +0100] ReadClient: 5 GET /favicon.ico HTTP/1.1
D [12/Mar/2006:13:52:30 +0100] SendError: 5 code=404 (Not Found)
D [12/Mar/2006:13:52:30 +0100] CloseClient: 5
D [12/Mar/2006:13:52:37 +0100] [Job 120] KID3 exited with status 0
D [12/Mar/2006:13:52:37 +0100] [Job 120] KID4 exited with status 9
D [12/Mar/2006:13:52:37 +0100] [Job 120] Renderer exit stat: 9
D [12/Mar/2006:13:52:37 +0100] [Job 120] Process dying with "error
closing *main::STDOUT", exit stat: 9
D [12/Mar/2006:13:52:37 +0100] [Job 120] error: Broken pipe (32)
D [12/Mar/2006:13:52:37 +0100] [Job 120] error closing *main::STDOUT
D [12/Mar/2006:13:52:37 +0100] [Job 120] KID3 finished
D [12/Mar/2006:13:52:37 +0100] [Job 120] Renderer process finished
D [12/Mar/2006:13:52:37 +0100] [Job 120] Killing process 9496 (KID3)
D [12/Mar/2006:13:52:37 +0100] [Job 120] Process dying with "Error
closing renderer", exit stat: 9
D [12/Mar/2006:13:52:37 +0100] [Job 120] error: Bad file descriptor (9)
D [12/Mar/2006:13:52:37 +0100] [Job 120] Error closing renderer
E [12/Mar/2006:13:52:37 +0100] PID 9492 stopped with status 9!
PID 9492 is the /usr/lib/cups/filter/foomatic-rip process (see above).
D [12/Mar/2006:13:52:37 +0100] UpdateJob: job 120, file 0 is complete.
D [12/Mar/2006:13:52:37 +0100] StopJob: id = 120, force = 0
I [12/Mar/2006:13:52:37 +0100] Saving printers.conf...
D [12/Mar/2006:13:52:37 +0100] StopJob: printer state is 5
If this is a problem with my configuration or another package, please
tell me. Anything I could do, to nail the problem down or fix it?
thanks
Joerg Beyer
-- System Information:
Debian Release: testing/unstable
APT prefers testing
APT policy: (650, 'testing')
Architecture: i386 (i686)
Shell: /bin/sh linked to /bin/bash
Kernel: Linux 2.6.14
Locale: LANG=de_DE@euro, LC_CTYPE=de_DE@euro (charmap=ISO-8859-15)
Versions of packages cupsys depends on:
ii adduser 3.80 Add and remove users and groups
ii debconf [debconf-2.0] 1.4.71 Debian configuration
management sy
ii gs-esp 8.15.1.dfsg.1-1 The Ghostscript PostScript
interpr
ii libc6 2.3.5-13 GNU C Library: Shared
libraries an
ii libcupsimage2 1.1.23-15 Common UNIX Printing
System(tm) -
ii libcupsys2 1.1.23-15 Common UNIX Printing
System(tm) -
ii libgnutls12 1.2.9-2 the GNU TLS library -
runtime libr
ii libpam0g 0.79-3.1 Pluggable Authentication
Modules l
ii libpaper1 1.1.14-5 Library for handling paper
charact
ii libslp1 1.2.1-5 OpenSLP libraries
ii patch 2.5.9-4 Apply a diff file to an
original
ii perl-modules 5.8.8-2 Core Perl modules
ii procps 1:3.2.6-2.1 /proc file system utilities
ii xpdf-utils 3.01-7 Portable Document Format
(PDF) sui
ii zlib1g 1:1.2.3-9 compression library - runtime
Versions of packages cupsys recommends:
ii cupsys-client 1.1.23-15 Common UNIX Printing
System(tm) -
ii foomatic-filters 3.0.2-20060113-1 linuxprinting.org printer
support
ii smbclient 3.0.21b-1 a LanManager-like simple
client fo
-- debconf information:
* cupsys/raw-print: true
cupsys/ports: localhost:631
* cupsys/backend: ipp, lpd, socket, usb
cupsys/portserror:
cupsys/browse: true
Reply to: