[cups.general] PDFs do not Print

Tue Mar 13 04:17:18 PDT 2007

adfas asd wrote:
> --- George Liu <george.liu at ussj.ricoh.com> wrote:
> 
>>OK, so scenario number 1 and 2 works, but number 3
>>doesn't. 
>>
>>Which means most of your printing system works fine,
>>the problem is
>>limited to your pdftops filter.
>>
>>Again, check your error_log and see what pdf filter
>>you are using and
>>whether it reports any problems. 
> 
> 
> OK, I printed the pdf from KPDF with cupsys set to
> debug, and starting at 'Started backend' I get the
> errorlog listing at bottom hereto.  Not sure what of
> it is relevant.  But the document never prints.  I can
> see data going out the network when I print, but it is
> only about a 2 second burst.  Maybe it should be more
> like 5 or 10 seconds of data, as it is with postscript
> file.
> 
>  
> 
>>How about manually convert PDF to Postscript using
>>pdf2ps filter and raw
>>printing the generated Postscript to printer? (Sharp
>>and Gestetner)?
> 
> 
> Yes, again this works fine.
> 
> 
> I [12/Mar/2007:16:22:47 -0700] Started filter
> /usr/lib/cups/filter/pstops (PID 2336) for job 642.
> I [12/Mar/2007:16:22:47 -0700] Started filter
> /usr/lib/cups/filter/foomatic-rip (PID 2337) for job
> 642.
> I [12/Mar/2007:16:22:47 -0700] Started backend
> /usr/lib/cups/backend/socket (PID 2338) for job 642.
> D [12/Mar/2007:16:22:47 -0700] Discarding unused
> job-state event...
> D [12/Mar/2007:16:22:47 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:22:47 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:47 -0700] Discarding unused
> printer-state-changed event...
> D [12/Mar/2007:16:22:47 -0700] Discarding unused
> printer-state-changed event...
> D [12/Mar/2007:16:22:47 -0700] Discarding unused
> printer-state-changed event...
> D [12/Mar/2007:16:22:47 -0700] Discarding unused
> printer-state-changed event...
> D [12/Mar/2007:16:22:47 -0700] [Job 642] Connected to
> 10.0.10.91:9100 (IPv4)...
> D [12/Mar/2007:16:22:47 -0700] [Job 642]
> backendRunLoop(print_fd=0, device_fd=4, use_bc=1)
> D [12/Mar/2007:16:22:48 -0700] [Job 642] Page =
> 612x792; 12,12 to 600,780
> D [12/Mar/2007:16:22:48 -0700] [Job 642]
> slow_collate=0, slow_duplex=0, slow_order=0
> D [12/Mar/2007:16:22:48 -0700] [Job 642] Before
> copy_comments - %!PS-Adobe-3.0
> D [12/Mar/2007:16:22:48 -0700] [Job 642]
> %!PS-Adobe-3.0
> D [12/Mar/2007:16:22:48 -0700] [Job 642] %%Creator:
> xpdf/pdftops 3.00
> D [12/Mar/2007:16:22:48 -0700] [Job 642]
> %%LanguageLevel: 2
> D [12/Mar/2007:16:22:48 -0700] [Job 642]
> %%DocumentSuppliedResources: (atend)
> D [12/Mar/2007:16:22:48 -0700] [Job 642]
> %%DocumentMedia: plain 612 792 0 () ()
> D [12/Mar/2007:16:22:48 -0700] [Job 642]
> %%BoundingBox: 0 0 612 792
> D [12/Mar/2007:16:22:48 -0700] [Job 642] %%Pages: 1
> D [12/Mar/2007:16:22:48 -0700] [Job 642] %%EndComments
> D [12/Mar/2007:16:22:48 -0700] [Job 642] Before
> copy_prolog - %%BeginDefaults
> D [12/Mar/2007:16:22:48 -0700] [Job 642] Before
> copy_setup - %%BeginSetup
> D [12/Mar/2007:16:22:48 -0700] [Job 642] Before page
> loop - %%Page: 1 1
> D [12/Mar/2007:16:22:48 -0700] [Job 642] Copying page
> 1...
> D [12/Mar/2007:16:22:48 -0700] [Job 642] pagew =
> 588.0, pagel = 768.0
> D [12/Mar/2007:16:22:48 -0700] [Job 642] bboxw = 612,
> bboxl = 792
> D [12/Mar/2007:16:22:48 -0700] [Job 642] PageLeft =
> 12.0, PageRight = 600.0
> D [12/Mar/2007:16:22:48 -0700] [Job 642] PageTop =
> 780.0, PageBottom = 12.0
> D [12/Mar/2007:16:22:48 -0700] [Job 642] PageWidth =
> 612.0, PageLength = 792.0
> D [12/Mar/2007:16:22:54 -0700] [Job 642] foomatic-rip
> version $Revision$ running...
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Parsing PPD
> file ...
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> ColorSpace
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Option1
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Option5
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Option30
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Option40
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Option50
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Resolution
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> PageSize
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> PageRegion
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> ImageableArea
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> PaperDimension
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> InputSlot
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> LeadingEdge
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Duplex
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Collate
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIPrintMode
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> ColorModel
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RPSBitsPerPixel
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RPSRGBcorrect
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RPSColorRendDict
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RPSDitherType
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RPSBlackMode
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RPSBlackOverPrint
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Rcmyksimulation
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> MediaType
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> OutputBin
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIStaple
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIPunch
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIWatermark
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIWMText
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIwmFont
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIwmSize
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIwmAngle
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> RIwmTextStyle
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> ScreenProc
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> Font
> D [12/Mar/2007:16:22:54 -0700] [Job 642] *cupsFilter:
> "application/vnd.cups-postscript 0 foomatic-rip"
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> JobType
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> LockedPrintPassword
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Added option
> UserCode
> D [12/Mar/2007:16:22:54 -0700] [Job 642] The value
> None for LockedPrintPassword is a predefined choice
> D [12/Mar/2007:16:22:54 -0700] [Job 642] The value
> None for UserCode is a predefined choice
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Parameter
> Summary
> D [12/Mar/2007:16:22:54 -0700] [Job 642]
> -----------------
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Spooler: cups
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Printer:
> Downstairs_Color
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Shell:
> /bin/sh
> D [12/Mar/2007:16:22:54 -0700] [Job 642] PPD file:
> /etc/cups/ppd/Downstairs_Color.ppd
> D [12/Mar/2007:16:22:54 -0700] [Job 642] ATTR file: 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Printer
> model: Gestetner DSc38u PS
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Job title:
> KDE Print System
> D [12/Mar/2007:16:22:54 -0700] [Job 642] File(s) to be
> printed: 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] <STDIN>
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] GhostScript
> extra search path ('GS_LIB'): /usr/share/cups/fonts
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Pondering
> option 'orientation-requested=3'
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Unknown
> option orientation-requested=3.
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Pondering
> option
> 'job-uuid=urn:uuid:d418df5d-2f5b-30bb-7894-04b20bcbd5a9'
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Unknown
> option
> job-uuid=urn:uuid:d418df5d-2f5b-30bb-7894-04b20bcbd5a9.
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642]
> ================================================
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] File: <STDIN>
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642]
> ================================================
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Reading
> PostScript input ...
> D [12/Mar/2007:16:22:54 -0700] [Job 642] --> This
> document is DSC-conforming!
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Job claims to
> be DSC-conforming, but "%%BeginProlog" was missing
> before first line with another "%%Begin..." comment
> (is this a TeX/LaTeX/dvips-generated PostScript
> file?). Assuming start of "Prolog" here.
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] -----------
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginProlog
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%EndProlog
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] -----------
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginSetup
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Option1 None
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Option1=None --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Option5 True
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Option5=True --> Correcting numerical/string option to
> Option5=1 (Command line argument)
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Option30 Fin2250
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Option30=Fin2250 --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Option40 False
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Option40=False --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Option50 False
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Option50=False --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *PageSize Letter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> PageSize=Letter --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *InputSlot Auto
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> InputSlot=Auto --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Resolution 600dpi
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Resolution=600dpi --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RPSBitsPerPixel 2BitsPerPixel
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RPSBitsPerPixel=2BitsPerPixel --> Option will be set
> by PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIPrintMode 0rhit
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIPrintMode=0rhit --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Duplex None
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Duplex=None --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *ColorModel CMYK
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> ColorModel=CMYK --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RPSRGBcorrect DetailBright
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RPSRGBcorrect=DetailBright --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RPSColorRendDict Photograph
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RPSColorRendDict=Photograph --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RPSDitherType Photo
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RPSDitherType=Photo --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RPSBlackMode 1Color
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RPSBlackMode=1Color --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RPSBlackOverPrint True
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RPSBlackOverPrint=True --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Rcmyksimulation Off
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Rcmyksimulation=Off --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *Collate False
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> Collate=False --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *MediaType Plain
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> MediaType=Plain --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *OutputBin Default
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> OutputBin=Default --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIStaple None
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIStaple=None --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIPunch None
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIPunch=None --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *JobType Normal
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> JobType=Normal --> Setting option
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found: %%
> FoomaticRIPOptionSetting: JobType=Normal
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> JobType=Normal --> Setting option
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *LockedPrintPassword None
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> LockedPrintPassword=NoneThe value None for
> LockedPrintPassword is a predefined choice
> D [12/Mar/2007:16:22:54 -0700] [Job 642] --> Setting
> option
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *UserCode None
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> UserCode=NoneThe value None for UserCode is a
> predefined choice
> D [12/Mar/2007:16:22:54 -0700] [Job 642] --> Setting
> option
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIWatermark Off
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIWatermark=Off --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIWMText Confidential
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIWMText=Confidential --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIwmFont HelveticaB
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIwmFont=HelveticaB --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIwmSize 36
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIwmSize=36 --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIwmAngle 45Deg
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIwmAngle=45Deg --> Option will be set by PostScript
> interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginFeature: *RIwmTextStyle Gray
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Option:
> RIwmTextStyle=Gray --> Option will be set by
> PostScript interpreter
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%EndSetup
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Inserting
> PostScript code for CUPS' page accounting
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] -----------
> D [12/Mar/2007:16:22:54 -0700] [Job 642] New page:  1
> 1
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Inserting
> option code into "PageSetup" section.
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%BeginPageSetup
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> %%EndPageSetup
> D [12/Mar/2007:16:22:54 -0700] [Job 642] End of page
> header
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Stopping
> search for page header options
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Found:
> D [12/Mar/2007:16:22:54 -0700] [Job 642]
> -p)jLp"Z2PL&T@<;2r>SSa2600\Ke2S-AC$LGUIskR`_IC:rFq)ONrkDhf0-,!3f]
> D [12/Mar/2007:16:22:54 -0700] [Job 642] --> Output
> goes directly to the renderer now.
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:22:54 -0700] cupsdReadClient: 8 POST
> /printers/ HTTP/1.1
> D [12/Mar/2007:16:22:54 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:22:54 -0700] CUPS-Get-Printers
> D [12/Mar/2007:16:22:54 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:22:54 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:54 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:22:54 -0700] cupsdReadClient: 8 POST
> /classes/ HTTP/1.1
> D [12/Mar/2007:16:22:54 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:22:54 -0700] CUPS-Get-Classes
> D [12/Mar/2007:16:22:54 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:22:54 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:54 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:22:54 -0700] cupsdReadClient: 8 POST
> /printers/ HTTP/1.1
> D [12/Mar/2007:16:22:54 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:22:54 -0700] CUPS-Get-Default
> D [12/Mar/2007:16:22:54 -0700] CUPS-Get-Default
> client-error-not-found: No default printer
> D [12/Mar/2007:16:22:54 -0700] cupsdProcessIPPRequest:
> 8 status_code=406 (client-error-not-found)
> D [12/Mar/2007:16:22:54 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:54 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:22:54 -0700] cupsdReadClient: 8 POST
> / HTTP/1.1
> D [12/Mar/2007:16:22:54 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:22:54 -0700] Get-Jobs
> ipp://localhost.localdomain:631/printers/Downstairs_Color
> D [12/Mar/2007:16:22:54 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:22:54 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] Starting
> renderer
> D [12/Mar/2007:16:22:54 -0700] [Job 642] JCL: <job
> data> 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] 
> D [12/Mar/2007:16:22:54 -0700] [Job 642] renderer PID
> kid4=2368
> D [12/Mar/2007:16:22:54 -0700] [Job 642] renderer
> command: printf "%%!PS-Adobe-3.0\n%%%% %%%%\nmark\n()
> () (20`date +%y%m%d%R | sed 's/://'`) {setuserinfo}
> stopped\ncleartomark\n"; cat;
> D [12/Mar/2007:16:22:55 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:22:55 -0700] cupsdReadClient: 8 POST
> /printers/ HTTP/1.1
> D [12/Mar/2007:16:22:55 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:22:55 -0700] CUPS-Get-Printers
> D [12/Mar/2007:16:22:55 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:22:55 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:55 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:22:55 -0700] cupsdReadClient: 8 POST
> /classes/ HTTP/1.1
> D [12/Mar/2007:16:22:55 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:22:55 -0700] CUPS-Get-Classes
> D [12/Mar/2007:16:22:55 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:22:55 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:55 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:22:55 -0700] cupsdReadClient: 8 POST
> /printers/ HTTP/1.1
> D [12/Mar/2007:16:22:55 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:22:55 -0700] CUPS-Get-Default
> D [12/Mar/2007:16:22:55 -0700] CUPS-Get-Default
> client-error-not-found: No default printer
> D [12/Mar/2007:16:22:55 -0700] cupsdProcessIPPRequest:
> 8 status_code=406 (client-error-not-found)
> D [12/Mar/2007:16:22:55 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:55 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:22:55 -0700] cupsdReadClient: 8 POST
> / HTTP/1.1
> D [12/Mar/2007:16:22:55 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:22:55 -0700] Get-Jobs
> ipp://localhost.localdomain:631/printers/Downstairs_Color
> D [12/Mar/2007:16:22:55 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:22:55 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:22:55 -0700] [Job 642] Read 81 bytes
> of print data...
> D [12/Mar/2007:16:22:55 -0700] [Job 642] Wrote 81
> bytes of print data...
> D [12/Mar/2007:16:22:55 -0700] [Job 642] Wrote 1
> pages...
> D [12/Mar/2007:16:22:55 -0700] PID 2336
> (/usr/lib/cups/filter/pstops) exited with no errors.
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] 
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Closing
> renderer
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] KID3 exited
> with status 0
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] tail process
> done writing data to STDOUT
> D [12/Mar/2007:16:22:56 -0700] [Job 642] KID4 finished
> D [12/Mar/2007:16:22:56 -0700] [Job 642] KID4 exited
> with status 0
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Renderer exit
> stat: 0
> D [12/Mar/2007:16:22:56 -0700] [Job 642] KID3 finished
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Renderer
> process finished
> D [12/Mar/2007:16:22:56 -0700] [Job 642] 
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Closing
> foomatic-rip.
> D [12/Mar/2007:16:22:56 -0700] PID 2337
> (/usr/lib/cups/filter/foomatic-rip) exited with no
> errors.
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Received 100
> bytes of back-channel data!
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Received 7
> bytes of back-channel data!
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Received 63
> bytes of back-channel data!
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 8192
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Read 3338
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] [Job 642] Wrote 3338
> bytes of print data...
> D [12/Mar/2007:16:22:56 -0700] Discarding unused
> printer-state-changed event...
> D [12/Mar/2007:16:22:56 -0700] Discarding unused
> printer-state-changed event...
> D [12/Mar/2007:16:22:56 -0700] PID 2338
> (/usr/lib/cups/backend/socket) exited with no errors.
> D [12/Mar/2007:16:22:56 -0700] [Job 642] File 0 is
> complete.
> D [12/Mar/2007:16:22:56 -0700] Discarding unused
> printer-state-changed event...
> D [12/Mar/2007:16:22:56 -0700] Discarding unused
> job-completed event...
> D [12/Mar/2007:16:22:58 -0700] Unloading job 642...
> D [12/Mar/2007:16:22:58 -0700] cupsdNetIFUpdate: "lo"
> = localhost...
> D [12/Mar/2007:16:22:58 -0700] cupsdNetIFUpdate:
> "ath0" = 10.0.0.110...
> D [12/Mar/2007:16:22:58 -0700] cupsdNetIFUpdate:
> "ppp0" = 10.100.1.22...
> D [12/Mar/2007:16:23:00 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:23:00 -0700] cupsdReadClient: 8 POST
> /printers/ HTTP/1.1
> D [12/Mar/2007:16:23:00 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:23:00 -0700] CUPS-Get-Printers
> D [12/Mar/2007:16:23:00 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:23:00 -0700] cupsdAcceptClient: 10
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:23:00 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:23:00 -0700] cupsdReadClient: 10
> POST /classes/ HTTP/1.1
> D [12/Mar/2007:16:23:00 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:23:00 -0700] CUPS-Get-Classes
> D [12/Mar/2007:16:23:00 -0700] cupsdProcessIPPRequest:
> 10 status_code=0 (successful-ok)
> D [12/Mar/2007:16:23:00 -0700] cupsdCloseClient: 10
> D [12/Mar/2007:16:23:00 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:23:00 -0700] cupsdReadClient: 8 POST
> /printers/ HTTP/1.1
> D [12/Mar/2007:16:23:00 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:23:00 -0700] CUPS-Get-Default
> D [12/Mar/2007:16:23:00 -0700] CUPS-Get-Default
> client-error-not-found: No default printer
> D [12/Mar/2007:16:23:00 -0700] cupsdProcessIPPRequest:
> 8 status_code=406 (client-error-not-found)
> D [12/Mar/2007:16:23:00 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:23:00 -0700] cupsdAcceptClient: 8
> from localhost:631 (IPv4)
> D [12/Mar/2007:16:23:00 -0700] cupsdReadClient: 8 POST
> / HTTP/1.1
> D [12/Mar/2007:16:23:00 -0700] cupsdAuthorize: No
> authentication data provided.
> D [12/Mar/2007:16:23:00 -0700] Get-Jobs
> ipp://localhost.localdomain:631/printers/Downstairs_Color
> D [12/Mar/2007:16:23:00 -0700] cupsdProcessIPPRequest:
> 8 status_code=0 (successful-ok)
> D [12/Mar/2007:16:23:00 -0700] cupsdCloseClient: 8
> D [12/Mar/2007:16:24:00 -0700] cupsdNetIFUpdate: "lo"
> = localhost...
> D [12/Mar/2007:16:24:00 -0700] cupsdNetIFUpdate:
> "ath0" = 10.0.0.110...
> D [12/Mar/2007:16:24:00 -0700] cupsdNetIFUpdate:
> "ppp0" = 10.100.1.22...
> 
> 
> 
I see you are using xpdf 3.00. It is known that this version had
some slight quirks with DSC conformance, which has been
fixed with version 3.01. In the meantime 3.02 is out
(but I haven't checked it).

I guess you should upgrade to at least 3.01 and try again.

Helge

-- 
Helge Blischke
Softwareentwicklung

H.Blischke at acm.org