[cups] unable to open file | permission denied

Evan Cooch evan.cooch at gmail.com
Thu May 15 10:07:47 PDT 2014


On 5/15/2014 12:59 PM, Helge Blischke wrote:
> Please do the following:
>
> cupsctl --debug-logging

Done.

> lp test.pdf
> after the error message
> cupsctl --no-debug-logging

and done...

> and then post the part of the /var/log/cups/error_log that contains 
> the messages
> related to this job.

OK -- at the bottom of this note. Said section of the log is *rather* long.


>
> I suspect something is going wrong with the filter chain for 
> processing PDFs
>
> Helge

  [15/May/2014:13:04:10 -0400] Listening to ::1:631 (IPv6)
I [15/May/2014:13:04:10 -0400] Listening to 127.0.0.1:631 (IPv4)
I [15/May/2014:13:04:10 -0400] Listening to /var/run/cups/cups.sock (Domain)
I [15/May/2014:13:04:10 -0400] Remote access is disabled.
D [15/May/2014:13:04:10 -0400] Added auto ServerAlias euler.dnr.cornell.edu
D [15/May/2014:13:04:10 -0400] Added auto ServerAlias euler
I [15/May/2014:13:04:10 -0400] Loaded configuration file 
"/etc/cups/cupsd.conf"
I [15/May/2014:13:04:10 -0400] Using default TempDir of 
/var/spool/cups/tmp...
I [15/May/2014:13:04:10 -0400] Configured for up to 100 clients.
I [15/May/2014:13:04:10 -0400] Allowing up to 100 client connections per 
host.
I [15/May/2014:13:04:10 -0400] Using policy "default" as the default!
D [15/May/2014:13:04:10 -0400] load_ppd: Loading 
/var/cache/cups/Cups-PDF.ipp...
D [15/May/2014:13:04:10 -0400] 
cupsdRegisterPrinter(p=0x7fa294153c20(Cups-PDF))
D [15/May/2014:13:04:10 -0400] load_ppd: Loading 
/var/cache/cups/Ricoh.ipp...
D [15/May/2014:13:04:10 -0400] cupsdRegisterPrinter(p=0x7fa29413ad30(Ricoh))
D [15/May/2014:13:04:10 -0400] cupsdMarkDirty(---p--)
D [15/May/2014:13:04:10 -0400] cupsdSetBusyState: Dirty files
I [15/May/2014:13:04:10 -0400] Partial reload complete.
I [15/May/2014:13:04:10 -0400] Listening to ::1:631 on fd 4...
I [15/May/2014:13:04:10 -0400] Listening to 127.0.0.1:631 on fd 7...
I [15/May/2014:13:04:10 -0400] Listening to /var/run/cups/cups.sock on 
fd 8...
I [15/May/2014:13:04:10 -0400] Resuming new connection processing...
D [15/May/2014:13:04:10 -0400] 
cupsdRegisterPrinter(p=0x7fa294153c20(Cups-PDF))
D [15/May/2014:13:04:10 -0400] cupsdRegisterPrinter(p=0x7fa29413ad30(Ricoh))
D [15/May/2014:13:04:10 -0400] Discarding unused server-restarted event...
D [15/May/2014:13:04:11 -0400] Report: clients=0
D [15/May/2014:13:04:11 -0400] Report: jobs=5
D [15/May/2014:13:04:11 -0400] Report: jobs-active=2
D [15/May/2014:13:04:11 -0400] Report: printers=2
D [15/May/2014:13:04:11 -0400] Report: printers-implicit=0
D [15/May/2014:13:04:11 -0400] Report: stringpool-string-count=2269
D [15/May/2014:13:04:11 -0400] Report: stringpool-alloc-bytes=10424
D [15/May/2014:13:04:11 -0400] Report: stringpool-total-bytes=46432
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: skipping getpeercon()
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: 12 from localhost (Domain)
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 1.1 
Get-Printer-Attributes 1
D [15/May/2014:13:04:17 -0400] Get-Printer-Attributes 
ipp://localhost:631/printers/RicohC4500
D [15/May/2014:13:04:17 -0400] Get-Printer-Attributes 
client-error-not-found: The printer or class was not found.
D [15/May/2014:13:04:17 -0400] Returning IPP client-error-not-found for 
Get-Printer-Attributes (ipp://localhost:631/printers/RicohC4500) from 
localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 1.1 CUPS-Get-Default 1
D [15/May/2014:13:04:17 -0400] CUPS-Get-Default
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
CUPS-Get-Default (no URI) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 POST /printers/Ricoh 
HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 1.1 Create-Job 1
D [15/May/2014:13:04:17 -0400] Create-Job ipp://localhost:631/printers/Ricoh
D [15/May/2014:13:04:17 -0400] add_job: setting context of job to UNKNOWN SL
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(----J-)
D [15/May/2014:13:04:17 -0400] add_job: requesting-user-name="root"
I [15/May/2014:13:04:17 -0400] [Job 44] Adding start banner page "none".
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
I [15/May/2014:13:04:17 -0400] [Job 44] Queued on "Ricoh" by "root".
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Create-Job (ipp://localhost:631/printers/Ricoh) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 POST /printers/Ricoh 
HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 1.1 Send-Document 1
D [15/May/2014:13:04:17 -0400] Send-Document 
ipp://localhost:631/printers/Ricoh
D [15/May/2014:13:04:17 -0400] cupsdIsAuthorized: 
requesting-user-name="root"
D [15/May/2014:13:04:17 -0400] [Job 44] Auto-typing file...
D [15/May/2014:13:04:17 -0400] [Job 44] Request file type is 
application/pdf.
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(----J-)
I [15/May/2014:13:04:17 -0400] [Job 44] File of type application/pdf 
queued by "root".
I [15/May/2014:13:04:17 -0400] [Job 44] Adding end banner page "none".
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(----J-)
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(----J-)
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients, 
printing jobs, and dirty files
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] [Job 44] job-sheets=none,none
D [15/May/2014:13:04:17 -0400] [Job 44] argv[0]="Ricoh"
D [15/May/2014:13:04:17 -0400] [Job 44] argv[1]="44"
D [15/May/2014:13:04:17 -0400] [Job 44] argv[2]="root"
D [15/May/2014:13:04:17 -0400] [Job 44] argv[3]="chap14.pdf"
D [15/May/2014:13:04:17 -0400] [Job 44] argv[4]="1"
D [15/May/2014:13:04:17 -0400] [Job 44] argv[5]="finishings=3 
media=na_letter_8.5x11in number-up=4 output-bin=Default 
sides=two-sided-long-edge 
job-uuid=urn:uuid:54aefd19-2487-32d0-5217-64f5f4636a7d 
job-originating-host-name=localhost"
D [15/May/2014:13:04:17 -0400] [Job 44] argv[6]="/var/spool/cups/d00044-001"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[1]="CUPS_DATADIR=/usr/share/cups"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[7]="CUPS_STATEDIR=/var/run/cups"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[8]="HOME=/var/spool/cups/tmp"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[9]="PATH=/usr/lib/cups/filter:/usr/lib64/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[10]="SERVER_ADMIN=root at euler.dnr.cornell.edu"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[11]="SOFTWARE=CUPS/1.4.2"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[12]="TMPDIR=/var/spool/cups/tmp"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[13]="USER=root"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[14]="CUPS_SERVER=/var/run/cups/cups.sock"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[15]="CUPS_ENCRYPTION=IfRequested"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[16]="IPP_PORT=631"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[17]="CHARSET=utf-8"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[18]="LANG=en_US.UTF-8"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[19]="PPD=/etc/cups/ppd/Ricoh.ppd"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[20]="RIP_MAX_CACHE=128m"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[21]="CONTENT_TYPE=application/pdf"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[22]="DEVICE_URI=socket://10.236.139.7:9100"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[23]="PRINTER_INFO=Ricoh 
Aficio MP C4500"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[24]="PRINTER_LOCATION=mail 
room"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[25]="PRINTER=Ricoh"
D [15/May/2014:13:04:17 -0400] [Job 44] envp[26]="CUPS_FILETYPE=document"
D [15/May/2014:13:04:17 -0400] [Job 44] 
envp[27]="FINAL_CONTENT_TYPE=printer/Ricoh"
I [15/May/2014:13:04:17 -0400] [Job 44] Started filter 
/usr/lib/cups/filter/pdftops (PID 4462)
I [15/May/2014:13:04:17 -0400] [Job 44] Started filter 
/usr/lib/cups/filter/foomatic-rip (PID 4463)
I [15/May/2014:13:04:17 -0400] [Job 44] Started backend 
/usr/lib/cups/backend/socket (PID 4464)
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Send-Document (ipp://localhost:631/printers/Ricoh) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Printing jobs and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 WAITING Closing on EOF
D [15/May/2014:13:04:17 -0400] cupsdCloseClient: 12
D [15/May/2014:13:04:17 -0400] [Job 44] Getting input from file
D [15/May/2014:13:04:17 -0400] [Job 44] foomatic-rip version 4.0.4.217 
running...
D [15/May/2014:13:04:17 -0400] [Job 44] Parsing PPD file ...
D [15/May/2014:13:04:17 -0400] [Job 44] Added option Option_30
D [15/May/2014:13:04:17 -0400] [Job 44] Added option Option1
D [15/May/2014:13:04:17 -0400] [Job 44] Added option Option_20
D [15/May/2014:13:04:17 -0400] [Job 44] Added option ColorModel
D [15/May/2014:13:04:17 -0400] [Job 44] Added option GSCmdLine
D [15/May/2014:13:04:17 -0400] [Job 44] Added option JCLDatamode
D [15/May/2014:13:04:17 -0400] [Job 44] Added option Resolution
D [15/May/2014:13:04:17 -0400] [Job 44] Added option GSResolution
D [15/May/2014:13:04:17 -0400] [Job 44] Added option JCLResolution
D [15/May/2014:13:04:17 -0400] [Job 44] Added option PageSize
D [15/May/2014:13:04:17 -0400] [Job 44] Added option ImageableArea
D [15/May/2014:13:04:17 -0400] [Job 44] Added option PaperDimension
D [15/May/2014:13:04:17 -0400] [Job 44] Added option InputSlot
D [15/May/2014:13:04:17 -0400] [Job 44] Added option Duplex
D [15/May/2014:13:04:17 -0400] [Job 44] Added option GSDuplex
D [15/May/2014:13:04:17 -0400] [Job 44] Added option JCLDuplex
D [15/May/2014:13:04:17 -0400] [Job 44] Added option Collate
D [15/May/2014:13:04:17 -0400] [Job 44] Added option MediaType
D [15/May/2014:13:04:17 -0400] [Job 44] Added option OutputBin
D [15/May/2014:13:04:17 -0400] [Job 44] Added option StapleLocation
D [15/May/2014:13:04:17 -0400] [Job 44] Added option RIPunch
D [15/May/2014:13:04:17 -0400] [Job 44] Added option RIPrintMode
D [15/May/2014:13:04:17 -0400] [Job 44] Added option RPSBitsPerPixel
D [15/May/2014:13:04:17 -0400] [Job 44] Added option JobType
D [15/May/2014:13:04:17 -0400] [Job 44] Added option Password
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: +connecting-to-device
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] [Job 44] Looking up "10.236.139.7"...
D [15/May/2014:13:04:17 -0400] [Job 44] Added option UserCode
D [15/May/2014:13:04:17 -0400] [Job 44] Connecting to 10.236.139.7:9100
I [15/May/2014:13:04:17 -0400] [Job 44] Connecting to printer...
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] Discarding unused job-progress event...
D [15/May/2014:13:04:17 -0400] [Job 44] Added option Font
D [15/May/2014:13:04:17 -0400] [Job 44]
D [15/May/2014:13:04:17 -0400] [Job 44] Parameter Summary
D [15/May/2014:13:04:17 -0400] [Job 44] -----------------
D [15/May/2014:13:04:17 -0400] [Job 44]
D [15/May/2014:13:04:17 -0400] [Job 44] Spooler: cups
D [15/May/2014:13:04:17 -0400] [Job 44] Printer: Ricoh
D [15/May/2014:13:04:17 -0400] [Job 44] Shell: /bin/bash
D [15/May/2014:13:04:17 -0400] [Job 44] PPD file: /etc/cups/ppd/Ricoh.ppd
D [15/May/2014:13:04:17 -0400] [Job 44] ATTR file:
D [15/May/2014:13:04:17 -0400] [Job 44] Printer model: Ricoh Aficio MP 
C4500 PXL
D [15/May/2014:13:04:17 -0400] [Job 44] Job title: chap14.pdf
D [15/May/2014:13:04:17 -0400] [Job 44] File(s) to be printed:
D [15/May/2014:13:04:17 -0400] [Job 44] <STDIN>
D [15/May/2014:13:04:17 -0400] [Job 44]
D [15/May/2014:13:04:17 -0400] [Job 44] Ghostscript extra search path 
('GS_LIB'): /usr/share/cups/fonts
D [15/May/2014:13:04:17 -0400] [Job 44] Printing system options:
D [15/May/2014:13:04:17 -0400] [Job 44] Pondering option 'finishings=3'
D [15/May/2014:13:04:17 -0400] [Job 44] Unknown option finishings=3.
D [15/May/2014:13:04:17 -0400] [Job 44] Pondering option 
'media=na_letter_8.5x11in'
D [15/May/2014:13:04:17 -0400] [Job 44] Unknown "media" component: 
"na_letter_8.5x11in".
D [15/May/2014:13:04:17 -0400] [Job 44] Pondering option 'number-up=4'
D [15/May/2014:13:04:17 -0400] [Job 44] Unknown option number-up=4.
D [15/May/2014:13:04:17 -0400] [Job 44] Pondering option 
'output-bin=Default'
D [15/May/2014:13:04:17 -0400] [Job 44] Unknown option output-bin=Default.
D [15/May/2014:13:04:17 -0400] [Job 44] Pondering option 
'sides=two-sided-long-edge'
D [15/May/2014:13:04:17 -0400] [Job 44] Pondering option 
'job-uuid=urn:uuid:54aefd19-2487-32d0-5217-64f5f4636a7d'
D [15/May/2014:13:04:17 -0400] [Job 44] Unknown option 
job-uuid=urn:uuid:54aefd19-2487-32d0-5217-64f5f4636a7d.
D [15/May/2014:13:04:17 -0400] [Job 44] Pondering option 
'job-originating-host-name=localhost'
D [15/May/2014:13:04:17 -0400] [Job 44] Unknown option 
job-originating-host-name=localhost.
D [15/May/2014:13:04:17 -0400] [Job 44] Options from the PPD file:
D [15/May/2014:13:04:17 -0400] [Job 44]
D [15/May/2014:13:04:17 -0400] [Job 44] 
================================================
D [15/May/2014:13:04:17 -0400] [Job 44]
D [15/May/2014:13:04:17 -0400] [Job 44] File: <STDIN>
D [15/May/2014:13:04:17 -0400] [Job 44]
D [15/May/2014:13:04:17 -0400] [Job 44] 
================================================
D [15/May/2014:13:04:17 -0400] [Job 44]
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -connecting-to-device
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
I [15/May/2014:13:04:17 -0400] [Job 44] Connected to printer...
D [15/May/2014:13:04:17 -0400] [Job 44] Connected to 10.236.139.7:9100 
(IPv4)...
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] Discarding unused job-progress event...
D [15/May/2014:13:04:17 -0400] [Job 44] Started filter pdftops (PID 4465)
D [15/May/2014:13:04:17 -0400] [Job 44] Started filter pstops (PID 4466)
D [15/May/2014:13:04:17 -0400] [Job 44] Error: Couldn't open file 
'/var/spool/cups/d00044-001': Permission denied.
D [15/May/2014:13:04:17 -0400] [Job 44] PID 4465 (pdftops) stopped with 
status 1!
E [15/May/2014:13:04:17 -0400] [Job 44] Empty print file!
D [15/May/2014:13:04:17 -0400] [Job 44] Set job-printer-state-message to 
"Empty print file!", current level=ERROR
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] Discarding unused job-progress event...
D [15/May/2014:13:04:17 -0400] [Job 44] PID 4466 (pstops) stopped with 
status 1!
D [15/May/2014:13:04:17 -0400] PID 4462 (/usr/lib/cups/filter/pdftops) 
stopped with status 1!
D [15/May/2014:13:04:17 -0400] [Job 44] Cannot process "<STDIN>": 
Unknown filetype.
D [15/May/2014:13:04:17 -0400] [Job 44]
D [15/May/2014:13:04:17 -0400] [Job 44] Closing foomatic-rip.
D [15/May/2014:13:04:17 -0400] PID 4463 
(/usr/lib/cups/filter/foomatic-rip) exited with no errors.
D [15/May/2014:13:04:17 -0400] [Job 44] ATTR: 
marker-colors=#000000,none,#00FFFF,#FF00FF,#FFFF00
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(P-----)
D [15/May/2014:13:04:17 -0400] [Job 44] ATTR: marker-names="Black 
Toner","Waste Toner 1","Cyan Toner","Magenta Toner","Yellow Toner"
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(P-----)
D [15/May/2014:13:04:17 -0400] [Job 44] ATTR: 
marker-types=toner,wasteToner,toner,toner,toner
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(P-----)
D [15/May/2014:13:04:17 -0400] [Job 44] ATTR: marker-levels=-1,-1,-1,-1,-1
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(P-----)
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -media-low-report
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -media-empty-warning
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: +toner-low-report
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -toner-empty-warning
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -door-open-report
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -media-jam-warning
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -input-tray-missing-warning
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -output-tray-missing-warning
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: 
-marker-supply-missing-warning
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: 
-output-area-almost-full-report
D [15/May/2014:13:04:17 -0400] [Job 44] STATE: -output-area-full-warning
D [15/May/2014:13:04:17 -0400] [Job 44] backendRunLoop(print_fd=0, 
device_fd=5, snmp_fd=6, addr=0x7fe0bf433968, use_bc=1, 
side_cb=0x7fe0bed53d50)
I [15/May/2014:13:04:17 -0400] [Job 44] Print file sent, waiting for 
printer to finish...
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] Discarding unused job-progress event...
D [15/May/2014:13:04:17 -0400] [Job 44] ATTR: marker-levels=-1,-1,-1,-1,-1
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(P-----)
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
I [15/May/2014:13:04:17 -0400] [Job 44] Ready to print.
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] Discarding unused job-progress event...
D [15/May/2014:13:04:17 -0400] PID 4464 (/usr/lib/cups/backend/socket) 
exited with no errors.
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
E [15/May/2014:13:04:17 -0400] [Job 44] Job stopped due to filter 
errors; please consult the error_log file for details.
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(----J-)
D [15/May/2014:13:04:17 -0400] cupsdMarkDirty(-----S)
D [15/May/2014:13:04:17 -0400] [Job 44] The following messages were 
recorded from 01:04:17 PM to 01:04:17 PM
D [15/May/2014:13:04:17 -0400] [Job 44] hrDeviceDesc="RICOH Aficio MP C4500"
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerColorantValue.1.1 = "black"
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerColorantValue.1.2 = "other"
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerColorantValue.1.3 = "cyan"
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerColorantValue.1.4 = 
"magenta"
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerColorantValue.1.5 = 
"yellow"
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerSuppliesLevel.1.1 = -3
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerSuppliesLevel.1.2 = -3
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerSuppliesLevel.1.3 = -3
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerSuppliesLevel.1.4 = -3
D [15/May/2014:13:04:17 -0400] [Job 44] prtMarkerSuppliesLevel.1.5 = -3
D [15/May/2014:13:04:17 -0400] [Job 44] End of messages
D [15/May/2014:13:04:17 -0400] [Job 44] printer-state=3(idle)
D [15/May/2014:13:04:17 -0400] [Job 44] printer-state-message="Ready to 
print."
D [15/May/2014:13:04:17 -0400] [Job 44] 
printer-state-reasons=toner-low-report
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: skipping getpeercon()
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: 12 from localhost (Domain)
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 1.1 Get-Jobs 1
D [15/May/2014:13:04:17 -0400] Get-Jobs ipp://localhost/printers/
D [15/May/2014:13:04:17 -0400] [Job 42] Loading attributes...
D [15/May/2014:13:04:17 -0400] [Job 43] Loading attributes...
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for Get-Jobs 
(ipp://localhost/printers/) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 WAITING Closing on EOF
D [15/May/2014:13:04:17 -0400] cupsdCloseClient: 12
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: skipping getpeercon()
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: 12 from localhost (Domain)
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 1.1 Get-Notifications 1
D [15/May/2014:13:04:17 -0400] Get-Notifications /
D [15/May/2014:13:04:17 -0400] cupsdIsAuthorized: requesting-user-name="egc"
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Get-Notifications (/) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 12 1.1 Get-Job-Attributes 1
D [15/May/2014:13:04:17 -0400] Get-Job-Attributes ipp://localhost/jobs/44
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Get-Job-Attributes (ipp://localhost/jobs/44) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: skipping getpeercon()
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: 15 from localhost (Domain)
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 15 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 15 1.1 
Get-Printer-Attributes 1
D [15/May/2014:13:04:17 -0400] Get-Printer-Attributes 
ipp://euler.dnr.cornell.edu:0/printers/Ricoh
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://euler.dnr.cornell.edu:0/printers/Ricoh) 
from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 15 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 15 1.1 Get-Job-Attributes 1
D [15/May/2014:13:04:17 -0400] Get-Job-Attributes ipp://localhost/jobs/44
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Get-Job-Attributes (ipp://localhost/jobs/44) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: skipping getpeercon()
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: 16 from localhost (Domain)
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 16 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 16 1.1 
Get-Printer-Attributes 1
D [15/May/2014:13:04:17 -0400] Get-Printer-Attributes 
ipp://euler.dnr.cornell.edu:0/printers/Ricoh
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://euler.dnr.cornell.edu:0/printers/Ricoh) 
from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 16 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 16 1.1 Get-Job-Attributes 1
D [15/May/2014:13:04:17 -0400] Get-Job-Attributes ipp://localhost/jobs/44
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Get-Job-Attributes (ipp://localhost/jobs/44) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: skipping getpeercon()
D [15/May/2014:13:04:17 -0400] cupsdAcceptClient: 17 from localhost (Domain)
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 17 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 17 1.1 
Get-Printer-Attributes 1
D [15/May/2014:13:04:17 -0400] Get-Printer-Attributes 
ipp://euler.dnr.cornell.edu:0/printers/Ricoh
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://euler.dnr.cornell.edu:0/printers/Ricoh) 
from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 17 POST / HTTP/1.1
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:17 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:17 -0400] cupsdReadClient: 17 1.1 Get-Job-Attributes 1
D [15/May/2014:13:04:17 -0400] Get-Job-Attributes ipp://localhost/jobs/44
D [15/May/2014:13:04:17 -0400] Returning IPP successful-ok for 
Get-Job-Attributes (ipp://localhost/jobs/44) from localhost
D [15/May/2014:13:04:17 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:18 -0400] [Job 44] Unloading...
D [15/May/2014:13:04:28 -0400] cupsdAcceptClient: skipping getpeercon()
D [15/May/2014:13:04:28 -0400] cupsdAcceptClient: 18 from localhost (Domain)
D [15/May/2014:13:04:28 -0400] cupsdReadClient: 18 PUT 
/admin/conf/cupsd.conf HTTP/1.1
D [15/May/2014:13:04:28 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:28 -0400] cupsdAuthorize: No authentication data 
provided.
D [15/May/2014:13:04:28 -0400] cupsdIsAuthorized: username=""
D [15/May/2014:13:04:28 -0400] cupsdSendHeader: 18 WWW-Authenticate: 
Basic realm="CUPS", trc="y"
D [15/May/2014:13:04:28 -0400] cupsdCloseClient: 18
D [15/May/2014:13:04:28 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:28 -0400] cupsdAcceptClient: skipping getpeercon()
D [15/May/2014:13:04:28 -0400] cupsdAcceptClient: 18 from localhost (Domain)
D [15/May/2014:13:04:28 -0400] cupsdReadClient: 18 PUT 
/admin/conf/cupsd.conf HTTP/1.1
D [15/May/2014:13:04:28 -0400] cupsdSetBusyState: Active clients and 
dirty files
D [15/May/2014:13:04:28 -0400] cupsdAuthorize: Authorized as root using 
PeerCred
D [15/May/2014:13:04:28 -0400] cupsdIsAuthorized: username="root"
I [15/May/2014:13:04:28 -0400] Installing config file 
"/etc/cups/cupsd.conf"...
D [15/May/2014:13:04:28 -0400] cupsdSetBusyState: Dirty files
D [15/May/2014:13:04:28 -0400] cupsdCloseClient: 12
D [15/May/2014:13:04:28 -0400] cupsdCloseClient: 15
D [15/May/2014:13:04:28 -0400] cupsdCloseClient: 16
D [15/May/2014:13:04:28 -0400] cupsdCloseClient: 17
D [15/May/2014:13:04:28 -0400] cupsdCloseClient: 18
D [15/May/2014:13:04:28 -0400] 
cupsdDeregisterPrinter(p=0x7fa294153c20(Cups-PDF), removeit=1)
D [15/May/2014:13:04:28 -0400] 
cupsdDeregisterPrinter(p=0x7fa29413ad30(Ricoh), removeit=1)
I [15/May/2014:13:04:28 -0400] Saving printers.conf...
I [15/May/2014:13:04:28 -0400] Generating printcap /etc/printcap...
I [15/May/2014:13:04:28 -0400] Saving job cache file 
"/var/cache/cups/job.cache"...
I [15/May/2014:13:04:28 -0400] Saving subscriptions.conf...
D [15/May/2014:13:04:28 -0400] cupsdSetBusyState: Not busy



More information about the cups mailing list