[cups] compression=gzip between cups 1.5 and 1.4

Steve Bergman sbergman27 at gmail.com
Wed May 14 10:53:33 PDT 2014 

On 05/14/2014 10:17 AM, Michael Sweet wrote:
> Steve,
>
> This is a known bug for raw jobs on 1.4 through 1.7.0. It was fixed
> in 1.7.1.
>


Thank you. Using a ppd on the client side is not necessarily a problem.
But as far as I can tell, it's not actually doing any compression on
non-raw jobs. I have a test setup on 1 machine using CUPS 1.5.2. I have
a testlocal set up with a URI of:

DEVICE_URI=ipp://127.0.0.1/printers/testremote?compression=gzip

And testremote just uses a URI of:

DEVICE_URI=file://tmp/testremote.out

I'm using the foomatic postscript ppd for both printers. Here is the 
debug output at LogLevel debug. I've also run it with debug2, and I 
never see the call to gziptoany that I'm used to seeing when it's 
working, and which I still see when I print from the old 1.3 CUPS to the 
1.4 CUPS.

D [14/May/2014:12:17:31 -0500] cupsdAcceptClient: 14 from localhost (Domain)
D [14/May/2014:12:17:31 -0500] Avahi client started
D [14/May/2014:12:17:31 -0500] cupsdReadClient: 14 POST / HTTP/1.1
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Active 
clients", busy="Not busy"
D [14/May/2014:12:17:31 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:31 -0500] cupsdReadClient: 14 1.1 
Get-Printer-Attributes 1
D [14/May/2014:12:17:31 -0500] Get-Printer-Attributes 
ipp://localhost:631/printers/testlocal
D [14/May/2014:12:17:31 -0500] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://localhost:631/printers/testlocal) from 
localhost
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [14/May/2014:12:17:31 -0500] cupsdReadClient: 14 POST 
/printers/testlocal HTTP/1.1
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Active 
clients", busy="Not busy"
D [14/May/2014:12:17:31 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:31 -0500] cupsdReadClient: 14 1.1 Create-Job 1
D [14/May/2014:12:17:31 -0500] Create-Job 
ipp://localhost:631/printers/testlocal
D [14/May/2014:12:17:31 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Active 
clients and dirty files", busy="Active clients"
D [14/May/2014:12:17:31 -0500] add_job: requesting-user-name="root"
I [14/May/2014:12:17:31 -0500] [Job 44] Adding start banner page "none".
D [14/May/2014:12:17:31 -0500] Discarding unused job-created event...
I [14/May/2014:12:17:31 -0500] [Job 44] Queued on "testlocal" by "root".
D [14/May/2014:12:17:31 -0500] Returning IPP successful-ok for 
Create-Job (ipp://localhost:631/printers/testlocal) from localhost
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Dirty files", 
busy="Active clients and dirty files"
D [14/May/2014:12:17:31 -0500] cupsdReadClient: 14 POST 
/printers/testlocal HTTP/1.1
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Active 
clients and dirty files", busy="Dirty files"
D [14/May/2014:12:17:31 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:31 -0500] cupsdReadClient: 14 1.1 Send-Document 1
D [14/May/2014:12:17:31 -0500] Send-Document 
ipp://localhost:631/printers/testlocal
D [14/May/2014:12:17:31 -0500] cupsdIsAuthorized: 
requesting-user-name="root"
D [14/May/2014:12:17:31 -0500] [Job 44] Auto-typing file...
D [14/May/2014:12:17:31 -0500] [Job 44] Request file type is 
application/postscript.
D [14/May/2014:12:17:31 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Active 
clients and dirty files", busy="Active clients and dirty files"
I [14/May/2014:12:17:31 -0500] [Job 44] File of type 
application/postscript queued by "root".
I [14/May/2014:12:17:31 -0500] [Job 44] Adding end banner page "none".
D [14/May/2014:12:17:31 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Active 
clients and dirty files", busy="Active clients and dirty files"
D [14/May/2014:12:17:31 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Active 
clients and dirty files", busy="Active clients and dirty files"
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Active 
clients and dirty files", busy="Active clients and dirty files"
D [14/May/2014:12:17:31 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:31 -0500] [Job 44] job-sheets=none,none
D [14/May/2014:12:17:31 -0500] [Job 44] argv[0]="testlocal"
D [14/May/2014:12:17:31 -0500] [Job 44] argv[1]="44"
D [14/May/2014:12:17:31 -0500] [Job 44] argv[2]="root"
D [14/May/2014:12:17:31 -0500] [Job 44] argv[3]="(stdin)"
D [14/May/2014:12:17:31 -0500] [Job 44] argv[4]="1"
D [14/May/2014:12:17:31 -0500] [Job 44] argv[5]="finishings=3 
number-up=1 job-uuid=urn:uuid:4186601e-fc13-3edb-604f-bedce83e6c08 
job-originating-host-name=localhost time-at-creation=1400087851 
time-at-processing=1400087851"
D [14/May/2014:12:17:31 -0500] [Job 44] argv[6]="/var/spool/cups/d00044-001"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[1]="CUPS_DATADIR=/usr/share/cups"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[7]="CUPS_STATEDIR=/var/run/cups"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[8]="HOME=/var/spool/cups/tmp"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[10]="SERVER_ADMIN=root at voyager"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[11]="SOFTWARE=CUPS/1.5.3"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[12]="TMPDIR=/var/spool/cups/tmp"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[13]="TZ=America/Chicago"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[14]="USER=root"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[16]="CUPS_ENCRYPTION=IfRequested"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[17]="IPP_PORT=631"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[18]="CHARSET=utf-8"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[19]="LANG=en_US.UTF-8"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[20]="PPD=/etc/cups/ppd/testlocal.ppd"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[21]="RIP_MAX_CACHE=128m"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[22]="CONTENT_TYPE=application/postscript"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[23]="DEVICE_URI=ipp://127.0.0.1/printers/testremote?compression=gzip"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[24]="PRINTER_INFO=testlocal"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[25]="PRINTER_LOCATION=local"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[26]="PRINTER=testlocal"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[27]="PRINTER_STATE_REASONS=none"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[28]="CUPS_FILETYPE=document"
D [14/May/2014:12:17:31 -0500] [Job 44] 
envp[29]="FINAL_CONTENT_TYPE=printer/testlocal"
D [14/May/2014:12:17:31 -0500] [Job 44] envp[30]="AUTH_I****"
I [14/May/2014:12:17:31 -0500] [Job 44] Started filter 
/usr/lib/cups/filter/pstopdf (PID 2551)
I [14/May/2014:12:17:31 -0500] [Job 44] Started filter 
/usr/lib/cups/filter/pdftopdf (PID 2552)
I [14/May/2014:12:17:31 -0500] [Job 44] Started filter 
/usr/lib/cups/filter/foomatic-rip (PID 2553)
I [14/May/2014:12:17:31 -0500] [Job 44] Started backend 
/usr/lib/cups/backend/ipp (PID 2554)
D [14/May/2014:12:17:31 -0500] Discarding unused job-state-changed event...
D [14/May/2014:12:17:31 -0500] Returning IPP successful-ok for 
Send-Document (ipp://localhost:631/printers/testlocal) from localhost
D [14/May/2014:12:17:31 -0500] [Job 44] pstopdf 6 args: 44 root (stdin) 
1 finishings=3 number-up=1 
job-uuid=urn:uuid:4186601e-fc13-3edb-604f-bedce83e6c08 
job-originating-host-name=localhost time-at-creation=1400087851 
time-at-processing=1400087851 /var/spool/cups/d00044-001
D [14/May/2014:12:17:31 -0500] [Job 44] PPD: /etc/cups/ppd/testlocal.ppd
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Active clients and dirty files"
D [14/May/2014:12:17:31 -0500] cupsdReadClient: 14 WAITING Closing on EOF
D [14/May/2014:12:17:31 -0500] cupsdCloseClient: 14
D [14/May/2014:12:17:31 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:31 -0500] [Job 44] Getting input from file
D [14/May/2014:12:17:31 -0500] [Job 44] foomatic-rip version 4.0.17.256 
running...
D [14/May/2014:12:17:31 -0500] [Job 44] Parsing PPD file ...
D [14/May/2014:12:17:31 -0500] [Job 44] Added option ColorSpace
D [14/May/2014:12:17:31 -0500] [Job 44] Added option PageSize
D [14/May/2014:12:17:31 -0500] [Job 44] CUPS page accounting disabled by 
driver.
D [14/May/2014:12:17:31 -0500] [Job 44] Added option ImageableArea
D [14/May/2014:12:17:31 -0500] [Job 44] Added option PaperDimension
D [14/May/2014:12:17:31 -0500] [Job 44] Added option InputSlot
D [14/May/2014:12:17:31 -0500] [Job 44] Sending stdin for job...
D [14/May/2014:12:17:31 -0500] [Job 44] Added option Duplex
D [14/May/2014:12:17:31 -0500] [Job 44] update_reasons(attr=0(), 
s="+connecting-to-device")
D [14/May/2014:12:17:31 -0500] [Job 44] STATE: +connecting-to-device
D [14/May/2014:12:17:31 -0500] [Job 44] Looking up "127.0.0.1"...
D [14/May/2014:12:17:31 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:31 -0500] [Job 44] Added option Resolution
D [14/May/2014:12:17:31 -0500] [Job 44] Added option Font
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] Parameter Summary
D [14/May/2014:12:17:31 -0500] [Job 44] -----------------
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] Spooler: cups
D [14/May/2014:12:17:31 -0500] [Job 44] Printer: testlocal
D [14/May/2014:12:17:31 -0500] [Job 44] Shell: /bin/bash
D [14/May/2014:12:17:31 -0500] [Job 44] PPD file: 
/etc/cups/ppd/testlocal.ppd
D [14/May/2014:12:17:31 -0500] [Job 44] ATTR file:
D [14/May/2014:12:17:31 -0500] [Job 44] Printer model: Generic 
PostScript Printer Foomatic/Postscript (recommended)
D [14/May/2014:12:17:31 -0500] [Job 44] Job title: stdin
D [14/May/2014:12:17:31 -0500] [Job 44] File(s) to be printed:
D [14/May/2014:12:17:31 -0500] [Job 44] <STDIN>
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] Ghostscript extra search path 
('GS_LIB'): /usr/share/cups/fonts
D [14/May/2014:12:17:31 -0500] [Job 44] Printing system options:
D [14/May/2014:12:17:31 -0500] [Job 44] Pondering option 'finishings=3'
D [14/May/2014:12:17:31 -0500] [Job 44] Unknown option finishings=3.
D [14/May/2014:12:17:31 -0500] [Job 44] Pondering option 'number-up=1'
D [14/May/2014:12:17:31 -0500] [Job 44] Unknown option number-up=1.
D [14/May/2014:12:17:31 -0500] [Job 44] Pondering option 
'job-uuid=urn:uuid:4186601e-fc13-3edb-604f-bedce83e6c08'
D [14/May/2014:12:17:31 -0500] [Job 44] Unknown option 
job-uuid=urn:uuid:4186601e-fc13-3edb-604f-bedce83e6c08.
D [14/May/2014:12:17:31 -0500] [Job 44] Pondering option 
'job-originating-host-name=localhost'
D [14/May/2014:12:17:31 -0500] [Job 44] Unknown option 
job-originating-host-name=localhost.
D [14/May/2014:12:17:31 -0500] [Job 44] Pondering option 
'time-at-creation=1400087851'
D [14/May/2014:12:17:31 -0500] [Job 44] Unknown option 
time-at-creation=1400087851.
D [14/May/2014:12:17:31 -0500] [Job 44] Pondering option 
'time-at-processing=1400087851'
D [14/May/2014:12:17:31 -0500] [Job 44] Unknown option 
time-at-processing=1400087851.
D [14/May/2014:12:17:31 -0500] [Job 44] Options from the PPD file:
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] 
================================================
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] File: <STDIN>
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] 
================================================
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] Resolution: 300x300
D [14/May/2014:12:17:31 -0500] [Job 44] Page size: Letter
D [14/May/2014:12:17:31 -0500] [Job 44] Width: 612, height: 792, 
absolute margins: 18, 36, 594, 756
D [14/May/2014:12:17:31 -0500] [Job 44] Relative margins: 18, 36, 18, 36
D [14/May/2014:12:17:31 -0500] [Job 44] PPD options: -r300 
-dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792
D [14/May/2014:12:17:31 -0500] [Job 44] PostScript to be injected:
D [14/May/2014:12:17:31 -0500] [Job 44] Running cat | /usr/bin/gs -q 
-dNOPAUSE -dBATCH -sDEVICE=pdfwrite -dCompatibilityLevel=1.3 
-dAutoRotatePages=/None -dAutoFilterColorImages=false 
-dNOPLATFONTS -dPARANOIDSAFER -dNOINTERPOLATE -sstdout=%stderr 
-dColorImageFilter=/FlateEncode                 -dPDFSETTINGS=/printer 
                -dColorConversionStrategy=/LeaveColorUnchanged 
-dDoNumCopies -r300 -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 
-sOutputFile=-  -c .setpdfwrite -f -
D [14/May/2014:12:17:31 -0500] PID 2551 (/usr/lib/cups/filter/pstopdf) 
exited with no errors.
D [14/May/2014:12:17:31 -0500] [Job 44] Filetype: PDF
D [14/May/2014:12:17:31 -0500] [Job 44] PostScript option found: 
PageSize=Letter: "<</PageSize[612 792]/ImagingBBox null>>setpagedevice"
D [14/May/2014:12:17:31 -0500] [Job 44] Driver does not understand PDF 
input, converting to PostScript
D [14/May/2014:12:17:31 -0500] [Job 44] Storing temporary files in 
/var/spool/cups/tmp
D [14/May/2014:12:17:31 -0500] PID 2552 (/usr/lib/cups/filter/pdftopdf) 
exited with no errors.
D [14/May/2014:12:17:31 -0500] [Job 44] Starting process "pdf-to-ps" 
(generation 1)
D [14/May/2014:12:17:31 -0500] [Job 44] Using image rendering resolution 
300 dpi
D [14/May/2014:12:17:31 -0500] [Job 44] Started filter gs (PID 2586)
D [14/May/2014:12:17:31 -0500] [Job 44] Started filter pstops (PID 2587)
D [14/May/2014:12:17:31 -0500] [Job 44] Page = 612x792; 18,36 to 594,756
D [14/May/2014:12:17:31 -0500] [Job 44] slow_collate=0, slow_duplex=0, 
slow_order=0
D [14/May/2014:12:17:31 -0500] [Job 44] Before copy_comments - 
%!PS-Adobe-3.0
D [14/May/2014:12:17:31 -0500] [Job 44] %!PS-Adobe-3.0
D [14/May/2014:12:17:31 -0500] [Job 44] %%BoundingBox: 0 0 612 792
D [14/May/2014:12:17:31 -0500] [Job 44] %%Creator: GPL Ghostscript 905 
(ps2write)
D [14/May/2014:12:17:31 -0500] [Job 44] %%LanguageLevel: 2
D [14/May/2014:12:17:31 -0500] [Job 44] %%CreationDate: 
D:20140514121731-05'00'
D [14/May/2014:12:17:31 -0500] [Job 44] %%Pages: 1
D [14/May/2014:12:17:31 -0500] [Job 44] %%EndComments
D [14/May/2014:12:17:31 -0500] [Job 44] Before copy_prolog - %%BeginProlog
D [14/May/2014:12:17:31 -0500] [Job 44] Filetype: PostScript
D [14/May/2014:12:17:31 -0500] [Job 44] Reading PostScript input ...
D [14/May/2014:12:17:31 -0500] [Job 44] --> This document is DSC-conforming!
D [14/May/2014:12:17:31 -0500] [Job 44] Found %RBINumCopies: 1
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] -----------
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%BeginProlog
D [14/May/2014:12:17:31 -0500] [Job 44] Inserting option code into 
"Prolog" section.
D [14/May/2014:12:17:31 -0500] [Job 44] Before copy_setup - %%Page: 1 1
D [14/May/2014:12:17:31 -0500] [Job 44] Before page loop - %%Page: 1 1
D [14/May/2014:12:17:31 -0500] [Job 44] Copying page 1...
D [14/May/2014:12:17:31 -0500] [Job 44] pagew = 576.0, pagel = 720.0
D [14/May/2014:12:17:31 -0500] [Job 44] bboxx = 0, bboxy = 0, bboxw = 
612, bboxl = 792
D [14/May/2014:12:17:31 -0500] [Job 44] PageLeft = 18.0, PageRight = 594.0
D [14/May/2014:12:17:31 -0500] [Job 44] PageTop = 756.0, PageBottom = 36.0
D [14/May/2014:12:17:31 -0500] [Job 44] PageWidth = 612.0, PageLength = 
792.0
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%EndProlog
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] -----------
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%BeginSetup
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%BeginFeature: 
*Resolution 300x300dpi
D [14/May/2014:12:17:31 -0500] [Job 44] Option: Resolution=300x300dpi
D [14/May/2014:12:17:31 -0500] [Job 44] --> Option will be set by 
PostScript interpreter
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%BeginFeature: *PageSize 
Letter
D [14/May/2014:12:17:31 -0500] [Job 44] Option: PageSize=Letter
D [14/May/2014:12:17:31 -0500] [Job 44] --> Option will be set by 
PostScript interpreter
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%BeginFeature: 
*InputSlot Default
D [14/May/2014:12:17:31 -0500] [Job 44] Option: InputSlot=Default
D [14/May/2014:12:17:31 -0500] [Job 44] --> Option will be set by 
PostScript interpreter
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%BeginFeature: *Duplex None
D [14/May/2014:12:17:31 -0500] [Job 44] Option: Duplex=None
D [14/May/2014:12:17:31 -0500] [Job 44] --> Option will be set by 
PostScript interpreter
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%EndSetup
D [14/May/2014:12:17:31 -0500] [Job 44] Inserting option code into 
"Setup" section.
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] -----------
D [14/May/2014:12:17:31 -0500] [Job 44] New page: %%Page: 1 1
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] Found: %%BeginPageSetup
D [14/May/2014:12:17:31 -0500] [Job 44] Inserting option code into 
"PageSetup" section.
D [14/May/2014:12:17:31 -0500] [Job 44] Wrote 1 pages...
D [14/May/2014:12:17:31 -0500] [Job 44] PID 2587 (pstops) exited with no 
errors.
D [14/May/2014:12:17:31 -0500] [Job 44] PID 2586 (gs) exited with no errors.
D [14/May/2014:12:17:31 -0500] [Job 44] Flushing FIFO.
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] Starting renderer with command: 
"cat"
D [14/May/2014:12:17:31 -0500] [Job 44] Starting process "kid3" 
(generation 1)
D [14/May/2014:12:17:31 -0500] [Job 44] Starting process "kid4" 
(generation 2)
D [14/May/2014:12:17:31 -0500] [Job 44] Starting process "renderer" 
(generation 2)
D [14/May/2014:12:17:31 -0500] [Job 44] JCL: %-12345X at PJL
D [14/May/2014:12:17:31 -0500] [Job 44] <job data>
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44]
D [14/May/2014:12:17:31 -0500] [Job 44] Closing renderer
D [14/May/2014:12:17:35 -0500] [Job 44] prtGeneralCurrentLocalization 
type is 0, expected 2!
D [14/May/2014:12:17:35 -0500] [Job 44] backendWaitLoop(snmp_fd=6, 
addr=0x7f52ee8ffec8, side_cb=0x7f52ee00a470)
D [14/May/2014:12:17:35 -0500] [Job 44] Connecting to 127.0.0.1:631
I [14/May/2014:12:17:35 -0500] [Job 44] Connecting to printer.
D [14/May/2014:12:17:35 -0500] [Job 44] Set job-printer-state-message to 
"Connecting to printer.", current level=INFO
D [14/May/2014:12:17:35 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:35 -0500] cupsdAcceptClient: 14 from localhost:631 
(IPv4)
D [14/May/2014:12:17:35 -0500] [Job 44] update_reasons(attr=0(), 
s="-cups-certificate-error")
D [14/May/2014:12:17:35 -0500] [Job 44] update_reasons(attr=0(), 
s="-connecting-to-device")
D [14/May/2014:12:17:35 -0500] [Job 44] STATE: -connecting-to-device
I [14/May/2014:12:17:35 -0500] [Job 44] Connected to printer.
D [14/May/2014:12:17:35 -0500] [Job 44] Set job-printer-state-message to 
"Connected to printer.", current level=INFO
D [14/May/2014:12:17:35 -0500] [Job 44] Connected to 127.0.0.1:631...
D [14/May/2014:12:17:35 -0500] [Job 44] renderer exited with status 0
D [14/May/2014:12:17:35 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:35 -0500] [Job 44] Getting supported attributes...
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Printing jobs and dirty 
files"
D [14/May/2014:12:17:35 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 2.0 
Get-Printer-Attributes 1
D [14/May/2014:12:17:35 -0500] Get-Printer-Attributes 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:35 -0500] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://127.0.0.1:631/printers/testremote) from 
localhost
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Active clients, printing jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] [Job 44] Get-Printer-Attributes: 
successful-ok (successful-ok)
D [14/May/2014:12:17:35 -0500] [Job 44] copies-supported=1-9999
D [14/May/2014:12:17:35 -0500] [Job 44] document-format-supported (32 
values)
D [14/May/2014:12:17:35 -0500] [Job 44] [0] = "application/octet-stream"
D [14/May/2014:12:17:35 -0500] [Job 44] [1] = "application/pdf"
D [14/May/2014:12:17:35 -0500] [Job 44] [2] = "application/postscript"
D [14/May/2014:12:17:35 -0500] [Job 44] [3] = 
"application/vnd.adobe-reader-postscript"
D [14/May/2014:12:17:35 -0500] [Job 44] [4] = "application/vnd.cups-command"
D [14/May/2014:12:17:35 -0500] [Job 44] [5] = "application/vnd.cups-pdf"
D [14/May/2014:12:17:35 -0500] [Job 44] [6] = 
"application/vnd.cups-pdf-banner"
D [14/May/2014:12:17:35 -0500] [Job 44] [7] = 
"application/vnd.cups-postscript"
D [14/May/2014:12:17:35 -0500] [Job 44] [8] = "application/vnd.cups-raw"
D [14/May/2014:12:17:35 -0500] [Job 44] [9] = "application/x-cshell"
D [14/May/2014:12:17:35 -0500] [Job 44] [10] = "application/x-csource"
D [14/May/2014:12:17:35 -0500] [Job 44] [11] = "application/x-perl"
D [14/May/2014:12:17:35 -0500] [Job 44] [12] = "application/x-shell"
D [14/May/2014:12:17:35 -0500] [Job 44] [13] = "image/gif"
D [14/May/2014:12:17:35 -0500] [Job 44] [14] = "image/jpeg"
D [14/May/2014:12:17:35 -0500] [Job 44] [15] = "image/png"
D [14/May/2014:12:17:35 -0500] [Job 44] [16] = "image/tiff"
D [14/May/2014:12:17:35 -0500] [Job 44] [17] = "image/urf"
D [14/May/2014:12:17:35 -0500] [Job 44] [18] = "image/x-bitmap"
D [14/May/2014:12:17:35 -0500] [Job 44] [19] = "image/x-photocd"
D [14/May/2014:12:17:35 -0500] [Job 44] [20] = "image/x-portable-anymap"
D [14/May/2014:12:17:35 -0500] [Job 44] [21] = "image/x-portable-bitmap"
D [14/May/2014:12:17:35 -0500] [Job 44] [22] = "image/x-portable-graymap"
D [14/May/2014:12:17:35 -0500] [Job 44] [23] = "image/x-portable-pixmap"
D [14/May/2014:12:17:35 -0500] [Job 44] [24] = "image/x-sgi-rgb"
D [14/May/2014:12:17:35 -0500] [Job 44] [25] = "image/x-sun-raster"
D [14/May/2014:12:17:35 -0500] [Job 44] [26] = "image/x-xbitmap"
D [14/May/2014:12:17:35 -0500] [Job 44] [27] = "image/x-xpixmap"
D [14/May/2014:12:17:35 -0500] [Job 44] [28] = "image/x-xwindowdump"
D [14/May/2014:12:17:35 -0500] [Job 44] [29] = "text/css"
D [14/May/2014:12:17:35 -0500] [Job 44] [30] = "text/html"
D [14/May/2014:12:17:35 -0500] [Job 44] [31] = "text/plain"
D [14/May/2014:12:17:35 -0500] [Job 44] media-col-supported (7 values)
D [14/May/2014:12:17:35 -0500] [Job 44] [0] = "media-bottom-margin"
D [14/May/2014:12:17:35 -0500] [Job 44] [1] = "media-left-margin"
D [14/May/2014:12:17:35 -0500] [Job 44] [2] = "media-right-margin"
D [14/May/2014:12:17:35 -0500] [Job 44] [3] = "media-size"
D [14/May/2014:12:17:35 -0500] [Job 44] [4] = "media-source"
D [14/May/2014:12:17:35 -0500] [Job 44] [5] = "media-top-margin"
D [14/May/2014:12:17:35 -0500] [Job 44] [6] = "media-type"
I [14/May/2014:12:17:35 -0500] [Job 44]
D [14/May/2014:12:17:35 -0500] [Job 44] Set job-printer-state-message to 
"Connected to printer.", current level=INFO
D [14/May/2014:12:17:35 -0500] [Job 44] update_reasons(attr=1(none), 
s="(null)")
D [14/May/2014:12:17:35 -0500] [Job 44] STATE: -none
D [14/May/2014:12:17:35 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:35 -0500] [Job 44] 
final_content_type="printer/testlocal", 
document_format="application/octet-stream"
D [14/May/2014:12:17:35 -0500] [Job 44] Validate-Job IPP/2.0
D [14/May/2014:12:17:35 -0500] [Job 44] 
printer-uri="ipp://127.0.0.1:631/printers/testremote"
D [14/May/2014:12:17:35 -0500] [Job 44] requesting-user-name="root"
D [14/May/2014:12:17:35 -0500] [Job 44] job-name="(stdin)"
D [14/May/2014:12:17:35 -0500] [Job 44] 
document-format="application/octet-stream"
D [14/May/2014:12:17:35 -0500] [Job 44] compression="gzip"
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Printing jobs and dirty 
files"
D [14/May/2014:12:17:35 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:35 -0500] cupsdAcceptClient: 17 from localhost:631 
(IPv4)
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 17 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 2.0 Validate-Job 1
D [14/May/2014:12:17:35 -0500] Validate-Job 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:35 -0500] Returning IPP successful-ok for 
Validate-Job (ipp://127.0.0.1:631/printers/testremote) from localhost
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:35 -0500] [Job 44] Validate-Job: successful-ok 
(successful-ok)
D [14/May/2014:12:17:35 -0500] [Job 44] Create-Job IPP/2.0
D [14/May/2014:12:17:35 -0500] [Job 44] 
printer-uri="ipp://127.0.0.1:631/printers/testremote"
D [14/May/2014:12:17:35 -0500] [Job 44] requesting-user-name="root"
D [14/May/2014:12:17:35 -0500] [Job 44] job-name="(stdin)"
D [14/May/2014:12:17:35 -0500] [Job 44] 
document-format="application/octet-stream"
D [14/May/2014:12:17:35 -0500] [Job 44] compression="gzip"
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 2.0 Create-Job 1
D [14/May/2014:12:17:35 -0500] Create-Job 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:35 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] add_job: requesting-user-name="root"
D [14/May/2014:12:17:35 -0500] Adding default job-sheets values 
"none,none"...
I [14/May/2014:12:17:35 -0500] [Job 45] Adding start banner page "none".
D [14/May/2014:12:17:35 -0500] Discarding unused job-created event...
I [14/May/2014:12:17:35 -0500] [Job 45] Queued on "testremote" by "root".
D [14/May/2014:12:17:35 -0500] Returning IPP successful-ok for 
Create-Job (ipp://127.0.0.1:631/printers/testremote) from localhost
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 17 2.0 
Get-Printer-Attributes 1
D [14/May/2014:12:17:35 -0500] Get-Printer-Attributes 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:35 -0500] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://127.0.0.1:631/printers/testremote) from 
localhost
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] [Job 44] Create-Job: successful-ok 
(successful-ok)
I [14/May/2014:12:17:35 -0500] [Job 44] Print file accepted - job ID 45.
D [14/May/2014:12:17:35 -0500] [Job 44] Set job-printer-state-message to 
"Print file accepted - job ID 45.", current level=INFO
D [14/May/2014:12:17:35 -0500] [Job 44] job-id=45
D [14/May/2014:12:17:35 -0500] [Job 44] Sending file 1 using chunking...
D [14/May/2014:12:17:35 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 2.0 Send-Document 1
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
I [14/May/2014:12:17:35 -0500] [Job 44]
D [14/May/2014:12:17:35 -0500] [Job 44] Set job-printer-state-message to 
"Print file accepted - job ID 45.", current level=INFO
D [14/May/2014:12:17:35 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:35 -0500] [Job 44] kid4 exited with status 0
D [14/May/2014:12:17:35 -0500] [Job 44] kid3 finished
D [14/May/2014:12:17:35 -0500] [Job 44] update_reasons(attr=1(none), 
s="(null)")
D [14/May/2014:12:17:35 -0500] [Job 44] Get-Printer-Attributes: 
successful-ok (successful-ok)
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 17 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:35 -0500] [Job 44] kid3 exited with status 0
D [14/May/2014:12:17:35 -0500] [Job 44] pdf-to-ps exited with status 0
D [14/May/2014:12:17:35 -0500] [Job 44]
D [14/May/2014:12:17:35 -0500] [Job 44] Closing foomatic-rip.
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 17 2.0 Get-Job-Attributes 1
D [14/May/2014:12:17:35 -0500] Get-Job-Attributes 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:35 -0500] Returning IPP successful-ok for 
Get-Job-Attributes (ipp://127.0.0.1:631/printers/testremote) from localhost
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] PID 2553 
(/usr/lib/cups/filter/foomatic-rip) exited with no errors.
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 17 WAITING Closing on EOF
D [14/May/2014:12:17:35 -0500] cupsdCloseClient: 17
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] [Job 44] Get-Job-Attributes: 
successful-ok (successful-ok)
D [14/May/2014:12:17:35 -0500] Send-Document 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:35 -0500] cupsdIsAuthorized: 
requesting-user-name="root"
D [14/May/2014:12:17:35 -0500] [Job 45] Auto-typing file...
D [14/May/2014:12:17:35 -0500] [Job 45] Request file type is 
application/postscript.
D [14/May/2014:12:17:35 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
I [14/May/2014:12:17:35 -0500] [Job 45] File of type 
application/postscript queued by "root".
I [14/May/2014:12:17:35 -0500] [Job 45] Adding end banner page "none".
D [14/May/2014:12:17:35 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:35 -0500] [Job 45] job-sheets=none,none
D [14/May/2014:12:17:35 -0500] [Job 45] argv[0]="testremote"
D [14/May/2014:12:17:35 -0500] [Job 45] argv[1]="45"
D [14/May/2014:12:17:35 -0500] [Job 45] argv[2]="root"
D [14/May/2014:12:17:35 -0500] [Job 45] argv[3]="(stdin)"
D [14/May/2014:12:17:35 -0500] [Job 45] argv[4]="1"
D [14/May/2014:12:17:35 -0500] [Job 45] argv[5]="compression=gzip 
job-uuid=urn:uuid:814c5df4-8200-3982-47b5-1c53cf63ddbd 
job-originating-host-name=localhost time-at-creation=1400087855 
time-at-processing=1400087855"
D [14/May/2014:12:17:35 -0500] [Job 45] argv[6]="/var/spool/cups/d00045-001"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[1]="CUPS_DATADIR=/usr/share/cups"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[7]="CUPS_STATEDIR=/var/run/cups"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[8]="HOME=/var/spool/cups/tmp"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[10]="SERVER_ADMIN=root at voyager"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[11]="SOFTWARE=CUPS/1.5.3"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[12]="TMPDIR=/var/spool/cups/tmp"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[13]="TZ=America/Chicago"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[14]="USER=root"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[16]="CUPS_ENCRYPTION=IfRequested"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[17]="IPP_PORT=631"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[18]="CHARSET=utf-8"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[19]="LANG=en_US.UTF-8"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[20]="PPD=/etc/cups/ppd/testremote.ppd"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[21]="RIP_MAX_CACHE=128m"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[22]="CONTENT_TYPE=application/postscript"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[23]="DEVICE_URI=file:/tmp/testremote.out"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[24]="PRINTER_INFO=testremote"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[25]="PRINTER_LOCATION="
D [14/May/2014:12:17:35 -0500] [Job 45] envp[26]="PRINTER=testremote"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[27]="PRINTER_STATE_REASONS=none"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[28]="CUPS_FILETYPE=document"
D [14/May/2014:12:17:35 -0500] [Job 45] 
envp[29]="FINAL_CONTENT_TYPE=printer/testremote"
D [14/May/2014:12:17:35 -0500] [Job 45] envp[30]="AUTH_I****"
I [14/May/2014:12:17:35 -0500] [Job 45] Started filter 
/usr/lib/cups/filter/pstopdf (PID 2595)
I [14/May/2014:12:17:35 -0500] [Job 45] Started filter 
/usr/lib/cups/filter/pdftopdf (PID 2596)
I [14/May/2014:12:17:35 -0500] [Job 45] Started filter 
/usr/lib/cups/filter/foomatic-rip (PID 2597)
D [14/May/2014:12:17:35 -0500] Discarding unused job-state-changed event...
D [14/May/2014:12:17:35 -0500] Returning IPP successful-ok for 
Send-Document (ipp://127.0.0.1:631/printers/testremote) from localhost
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Active clients, printing jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 WAITING Closing on EOF
D [14/May/2014:12:17:35 -0500] cupsdCloseClient: 14
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:35 -0500] [Job 45] pstopdf 6 args: 45 root (stdin) 
1 compression=gzip 
job-uuid=urn:uuid:814c5df4-8200-3982-47b5-1c53cf63ddbd 
job-originating-host-name=localhost time-at-creation=1400087855 
time-at-processing=1400087855 /var/spool/cups/d00045-001
D [14/May/2014:12:17:35 -0500] [Job 45] PPD: /etc/cups/ppd/testremote.ppd
D [14/May/2014:12:17:35 -0500] [Job 44] Send-Document: successful-ok 
(successful-ok)
I [14/May/2014:12:17:35 -0500] [Job 44] Waiting for job to complete.
D [14/May/2014:12:17:35 -0500] [Job 44] Set job-printer-state-message to 
"Waiting for job to complete.", current level=INFO
D [14/May/2014:12:17:35 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:35 -0500] cupsdAcceptClient: 14 from localhost:631 
(IPv4)
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Printing jobs and dirty 
files"
D [14/May/2014:12:17:35 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:35 -0500] cupsdReadClient: 14 2.0 Get-Job-Attributes 1
D [14/May/2014:12:17:35 -0500] Get-Job-Attributes 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:35 -0500] Returning IPP successful-ok for 
Get-Job-Attributes (ipp://127.0.0.1:631/printers/testremote) from localhost
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Active clients, printing jobs, and dirty files"
D [14/May/2014:12:17:35 -0500] [Job 44] Get-Job-Attributes: 
successful-ok (successful-ok)
D [14/May/2014:12:17:35 -0500] [Job 44] update_reasons(attr=0(), 
s="+cups-remote-processing")
D [14/May/2014:12:17:35 -0500] [Job 44] STATE: +cups-remote-processing
D [14/May/2014:12:17:35 -0500] cupsdMarkDirty(P-----)
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:35 -0500] [Job 44] PAGE: total 0
D [14/May/2014:12:17:35 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:35 -0500] [Job 45] Getting input from file
D [14/May/2014:12:17:35 -0500] [Job 45] foomatic-rip version 4.0.17.256 
running...
D [14/May/2014:12:17:35 -0500] [Job 45] Parsing PPD file ...
D [14/May/2014:12:17:35 -0500] [Job 45] Added option ColorSpace
D [14/May/2014:12:17:35 -0500] [Job 45] Added option PageSize
D [14/May/2014:12:17:35 -0500] [Job 45] CUPS page accounting disabled by 
driver.
D [14/May/2014:12:17:35 -0500] [Job 45] Added option ImageableArea
D [14/May/2014:12:17:35 -0500] [Job 45] Added option PaperDimension
D [14/May/2014:12:17:35 -0500] [Job 45] Added option InputSlot
D [14/May/2014:12:17:35 -0500] [Job 45] Added option Duplex
D [14/May/2014:12:17:35 -0500] [Job 45] Added option Resolution
D [14/May/2014:12:17:35 -0500] [Job 45] Added option Font
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] Parameter Summary
D [14/May/2014:12:17:35 -0500] [Job 45] -----------------
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] Spooler: cups
D [14/May/2014:12:17:35 -0500] [Job 45] Printer: testremote
D [14/May/2014:12:17:35 -0500] [Job 45] Shell: /bin/bash
D [14/May/2014:12:17:35 -0500] [Job 45] PPD file: 
/etc/cups/ppd/testremote.ppd
D [14/May/2014:12:17:35 -0500] [Job 45] ATTR file:
D [14/May/2014:12:17:35 -0500] [Job 45] Printer model: Generic 
PostScript Printer Foomatic/Postscript (recommended)
D [14/May/2014:12:17:35 -0500] [Job 45] Job title: stdin
D [14/May/2014:12:17:35 -0500] [Job 45] File(s) to be printed:
D [14/May/2014:12:17:35 -0500] [Job 45] <STDIN>
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] Ghostscript extra search path 
('GS_LIB'): /usr/share/cups/fonts
D [14/May/2014:12:17:35 -0500] [Job 45] Printing system options:
D [14/May/2014:12:17:35 -0500] [Job 45] Pondering option 'compression=gzip'
D [14/May/2014:12:17:35 -0500] [Job 45] Unknown option compression=gzip.
D [14/May/2014:12:17:35 -0500] [Job 45] Pondering option 
'job-uuid=urn:uuid:814c5df4-8200-3982-47b5-1c53cf63ddbd'
D [14/May/2014:12:17:35 -0500] [Job 45] Unknown option 
job-uuid=urn:uuid:814c5df4-8200-3982-47b5-1c53cf63ddbd.
D [14/May/2014:12:17:35 -0500] [Job 45] Pondering option 
'job-originating-host-name=localhost'
D [14/May/2014:12:17:35 -0500] [Job 45] Unknown option 
job-originating-host-name=localhost.
D [14/May/2014:12:17:35 -0500] [Job 45] Pondering option 
'time-at-creation=1400087855'
D [14/May/2014:12:17:35 -0500] [Job 45] Unknown option 
time-at-creation=1400087855.
D [14/May/2014:12:17:35 -0500] [Job 45] Pondering option 
'time-at-processing=1400087855'
D [14/May/2014:12:17:35 -0500] [Job 45] Unknown option 
time-at-processing=1400087855.
D [14/May/2014:12:17:35 -0500] [Job 45] Options from the PPD file:
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] 
================================================
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] File: <STDIN>
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] 
================================================
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] Resolution: 300x300
D [14/May/2014:12:17:35 -0500] [Job 45] Page size: Letter
D [14/May/2014:12:17:35 -0500] [Job 45] Width: 612, height: 792, 
absolute margins: 18, 36, 594, 756
D [14/May/2014:12:17:35 -0500] [Job 45] Relative margins: 18, 36, 18, 36
D [14/May/2014:12:17:35 -0500] [Job 45] PPD options: -r300 
-dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792
D [14/May/2014:12:17:35 -0500] [Job 45] PostScript to be injected:
D [14/May/2014:12:17:35 -0500] [Job 45] Running cat | /usr/bin/gs -q 
-dNOPAUSE -dBATCH -sDEVICE=pdfwrite -dCompatibilityLevel=1.3 
-dAutoRotatePages=/None -dAutoFilterColorImages=false 
-dNOPLATFONTS -dPARANOIDSAFER -dNOINTERPOLATE -sstdout=%stderr 
-dColorImageFilter=/FlateEncode                 -dPDFSETTINGS=/printer 
                -dColorConversionStrategy=/LeaveColorUnchanged 
-dDoNumCopies -r300 -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 
-sOutputFile=-  -c .setpdfwrite -f -
D [14/May/2014:12:17:35 -0500] PID 2595 (/usr/lib/cups/filter/pstopdf) 
exited with no errors.
D [14/May/2014:12:17:35 -0500] [Job 45] Filetype: PDF
D [14/May/2014:12:17:35 -0500] [Job 45] PostScript option found: 
PageSize=Letter: "<</PageSize[612 792]/ImagingBBox null>>setpagedevice"
D [14/May/2014:12:17:35 -0500] [Job 45] Driver does not understand PDF 
input, converting to PostScript
D [14/May/2014:12:17:35 -0500] [Job 45] Storing temporary files in 
/var/spool/cups/tmp
D [14/May/2014:12:17:35 -0500] PID 2596 (/usr/lib/cups/filter/pdftopdf) 
exited with no errors.
D [14/May/2014:12:17:35 -0500] [Job 45] Starting process "pdf-to-ps" 
(generation 1)
D [14/May/2014:12:17:35 -0500] [Job 45] Using image rendering resolution 
300 dpi
D [14/May/2014:12:17:35 -0500] [Job 45] Started filter gs (PID 2628)
D [14/May/2014:12:17:35 -0500] [Job 45] Started filter pstops (PID 2629)
D [14/May/2014:12:17:35 -0500] [Job 45] Page = 612x792; 18,36 to 594,756
D [14/May/2014:12:17:35 -0500] [Job 45] slow_collate=0, slow_duplex=0, 
slow_order=0
D [14/May/2014:12:17:35 -0500] [Job 45] Before copy_comments - 
%!PS-Adobe-3.0
D [14/May/2014:12:17:35 -0500] [Job 45] %!PS-Adobe-3.0
D [14/May/2014:12:17:35 -0500] [Job 45] %%BoundingBox: 0 0 612 792
D [14/May/2014:12:17:35 -0500] [Job 45] %%Creator: GPL Ghostscript 905 
(ps2write)
D [14/May/2014:12:17:35 -0500] [Job 45] %%LanguageLevel: 2
D [14/May/2014:12:17:35 -0500] [Job 45] %%CreationDate: 
D:20140514121735-05'00'
D [14/May/2014:12:17:35 -0500] [Job 45] %%Pages: 1
D [14/May/2014:12:17:35 -0500] [Job 45] %%EndComments
D [14/May/2014:12:17:35 -0500] [Job 45] Before copy_prolog - %%BeginProlog
D [14/May/2014:12:17:35 -0500] [Job 45] Filetype: PostScript
D [14/May/2014:12:17:35 -0500] [Job 45] Reading PostScript input ...
D [14/May/2014:12:17:35 -0500] [Job 45] --> This document is DSC-conforming!
D [14/May/2014:12:17:35 -0500] [Job 45] Found %RBINumCopies: 1
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] -----------
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%BeginProlog
D [14/May/2014:12:17:35 -0500] [Job 45] Inserting option code into 
"Prolog" section.
D [14/May/2014:12:17:35 -0500] [Job 45] Before copy_setup - %%Page: 1 1
D [14/May/2014:12:17:35 -0500] [Job 45] Before page loop - %%Page: 1 1
D [14/May/2014:12:17:35 -0500] [Job 45] Copying page 1...
D [14/May/2014:12:17:35 -0500] [Job 45] pagew = 576.0, pagel = 720.0
D [14/May/2014:12:17:35 -0500] [Job 45] bboxx = 0, bboxy = 0, bboxw = 
612, bboxl = 792
D [14/May/2014:12:17:35 -0500] [Job 45] PageLeft = 18.0, PageRight = 594.0
D [14/May/2014:12:17:35 -0500] [Job 45] PageTop = 756.0, PageBottom = 36.0
D [14/May/2014:12:17:35 -0500] [Job 45] PageWidth = 612.0, PageLength = 
792.0
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%EndProlog
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] -----------
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%BeginSetup
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%BeginFeature: 
*Resolution 300x300dpi
D [14/May/2014:12:17:35 -0500] [Job 45] Option: Resolution=300x300dpi
D [14/May/2014:12:17:35 -0500] [Job 45] --> Option will be set by 
PostScript interpreter
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%BeginFeature: *PageSize 
Letter
D [14/May/2014:12:17:35 -0500] [Job 45] Option: PageSize=Letter
D [14/May/2014:12:17:35 -0500] [Job 45] --> Option will be set by 
PostScript interpreter
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%BeginFeature: 
*InputSlot Default
D [14/May/2014:12:17:35 -0500] [Job 45] Option: InputSlot=Default
D [14/May/2014:12:17:35 -0500] [Job 45] --> Option will be set by 
PostScript interpreter
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%BeginFeature: *Duplex None
D [14/May/2014:12:17:35 -0500] [Job 45] Option: Duplex=None
D [14/May/2014:12:17:35 -0500] [Job 45] --> Option will be set by 
PostScript interpreter
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%EndSetup
D [14/May/2014:12:17:35 -0500] [Job 45] Inserting option code into 
"Setup" section.
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] -----------
D [14/May/2014:12:17:35 -0500] [Job 45] New page: %%Page: 1 1
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] Found: %%BeginPageSetup
D [14/May/2014:12:17:35 -0500] [Job 45] Inserting option code into 
"PageSetup" section.
D [14/May/2014:12:17:35 -0500] [Job 45] Wrote 1 pages...
D [14/May/2014:12:17:35 -0500] [Job 45] PID 2628 (gs) exited with no errors.
D [14/May/2014:12:17:35 -0500] [Job 45] PID 2629 (pstops) exited with no 
errors.
D [14/May/2014:12:17:35 -0500] [Job 45] Flushing FIFO.
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] Starting renderer with command: 
"cat"
D [14/May/2014:12:17:35 -0500] [Job 45] Starting process "kid3" 
(generation 1)
D [14/May/2014:12:17:35 -0500] [Job 45] Starting process "kid4" 
(generation 2)
D [14/May/2014:12:17:35 -0500] [Job 45] Starting process "renderer" 
(generation 2)
D [14/May/2014:12:17:35 -0500] [Job 45] JCL: %-12345X at PJL
D [14/May/2014:12:17:35 -0500] [Job 45] <job data>
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] Closing renderer
D [14/May/2014:12:17:35 -0500] [Job 45] renderer exited with status 0
D [14/May/2014:12:17:35 -0500] [Job 45] kid4 exited with status 0
D [14/May/2014:12:17:35 -0500] [Job 45] kid3 finished
D [14/May/2014:12:17:35 -0500] [Job 45] kid3 exited with status 0
D [14/May/2014:12:17:35 -0500] [Job 45] pdf-to-ps exited with status 0
D [14/May/2014:12:17:35 -0500] [Job 45]
D [14/May/2014:12:17:35 -0500] [Job 45] Closing foomatic-rip.
D [14/May/2014:12:17:35 -0500] PID 2597 
(/usr/lib/cups/filter/foomatic-rip) exited with no errors.
D [14/May/2014:12:17:35 -0500] Discarding unused job-completed event...
I [14/May/2014:12:17:35 -0500] [Job 45] Job completed.
D [14/May/2014:12:17:35 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:35 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:35 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:36 -0500] cupsdAcceptClient: 17 from localhost:631 
(IPv4)
D [14/May/2014:12:17:36 -0500] [Job 45] Unloading...
D [14/May/2014:12:17:36 -0500] cupsdAcceptClient: 18 from localhost:631 
(IPv4)
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 17 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Printing jobs and dirty 
files"
D [14/May/2014:12:17:36 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 14 WAITING Closing on EOF
D [14/May/2014:12:17:36 -0500] cupsdCloseClient: 14
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 18 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 18 2.0 Get-Job-Attributes 1
D [14/May/2014:12:17:36 -0500] Get-Job-Attributes 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:36 -0500] [Job 45] Loading attributes...
D [14/May/2014:12:17:36 -0500] Returning IPP successful-ok for 
Get-Job-Attributes (ipp://127.0.0.1:631/printers/testremote) from localhost
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 17 2.0 
Get-Printer-Attributes 1
D [14/May/2014:12:17:36 -0500] Get-Printer-Attributes 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:36 -0500] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://127.0.0.1:631/printers/testremote) from 
localhost
D [14/May/2014:12:17:36 -0500] [Job 44] Get-Job-Attributes: 
successful-ok (successful-ok)
D [14/May/2014:12:17:36 -0500] [Job 44] update_reasons(attr=0(), 
s="+cups-remote-completed")
D [14/May/2014:12:17:36 -0500] [Job 44] STATE: +cups-remote-completed
D [14/May/2014:12:17:36 -0500] cupsdMarkDirty(P-----)
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] [Job 44] STATE: -cups-remote-processing
D [14/May/2014:12:17:36 -0500] cupsdMarkDirty(P-----)
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] [Job 44] PAGE: total 0
D [14/May/2014:12:17:36 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:36 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 18 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 18 2.0 
Get-Printer-Attributes 1
D [14/May/2014:12:17:36 -0500] Get-Printer-Attributes 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:36 -0500] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://127.0.0.1:631/printers/testremote) from 
localhost
I [14/May/2014:12:17:36 -0500] [Job 44]
D [14/May/2014:12:17:36 -0500] [Job 44] Set job-printer-state-message to 
"Waiting for job to complete.", current level=INFO
D [14/May/2014:12:17:36 -0500] [Job 44] update_reasons(attr=1(none), 
s="(null)")
D [14/May/2014:12:17:36 -0500] [Job 44] Get-Printer-Attributes: 
successful-ok (successful-ok)
D [14/May/2014:12:17:36 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:36 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 17 POST 
/printers/testremote HTTP/1.1
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] cupsdAuthorize: No authentication data 
provided.
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Active 
clients, printing jobs, and dirty files", busy="Active clients, printing 
jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 17 2.0 Get-Job-Attributes 1
D [14/May/2014:12:17:36 -0500] Get-Job-Attributes 
ipp://127.0.0.1:631/printers/testremote
D [14/May/2014:12:17:36 -0500] Returning IPP successful-ok for 
Get-Job-Attributes (ipp://127.0.0.1:631/printers/testremote) from localhost
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Active clients, printing jobs, and dirty files"
D [14/May/2014:12:17:36 -0500] [Job 44] Get-Job-Attributes: 
successful-ok (successful-ok)
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 17 WAITING Closing on EOF
D [14/May/2014:12:17:36 -0500] cupsdCloseClient: 17
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
I [14/May/2014:12:17:36 -0500] [Job 44]
D [14/May/2014:12:17:36 -0500] [Job 44] update_reasons(attr=1(none), 
s="(null)")
D [14/May/2014:12:17:36 -0500] [Job 44] Get-Printer-Attributes: 
successful-ok (successful-ok)
D [14/May/2014:12:17:36 -0500] [Job 44] ATTR: auth-info-required=none
D [14/May/2014:12:17:36 -0500] load_ppd: Loading 
/var/cache/cups/testlocal.data...
D [14/May/2014:12:17:36 -0500] Calling DeleteDevice(cups-testlocal)
D [14/May/2014:12:17:36 -0500] failed to DeleteDevice: 
org.freedesktop.DBus.Error.InvalidArgs:Type of message, `(s)', does not 
match expected type `(o)'
D [14/May/2014:12:17:36 -0500] Using profile id of testlocal-Gray..
D [14/May/2014:12:17:36 -0500] Calling CreateProfile(testlocal-Gray..,temp)
W [14/May/2014:12:17:36 -0500] failed to CreateProfile: 
org.freedesktop.ColorManager.AlreadyExists:profile id 'testlocal-Gray..' 
already exists
D [14/May/2014:12:17:36 -0500] Using profile id of testlocal-RGB..
D [14/May/2014:12:17:36 -0500] Calling CreateProfile(testlocal-RGB..,temp)
W [14/May/2014:12:17:36 -0500] failed to CreateProfile: 
org.freedesktop.ColorManager.AlreadyExists:profile id 'testlocal-RGB..' 
already exists
I [14/May/2014:12:17:36 -0500] Registering ICC color profiles for 
"testlocal"
D [14/May/2014:12:17:36 -0500] Calling CreateDevice(cups-testlocal,temp)
W [14/May/2014:12:17:36 -0500] failed to CreateDevice: 
org.freedesktop.ColorManager.AlreadyExists:device id 'cups-testlocal' 
already exists
D [14/May/2014:12:17:36 -0500] 
cupsdRegisterPrinter(p=0x7fec06f105c0(testlocal))
D [14/May/2014:12:17:36 -0500] cupsdMarkDirty(P-----)
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
I [14/May/2014:12:17:36 -0500] [Job 44] Ready to print.
D [14/May/2014:12:17:36 -0500] [Job 44] Set job-printer-state-message to 
"Ready to print.", current level=INFO
D [14/May/2014:12:17:36 -0500] Discarding unused job-progress event...
D [14/May/2014:12:17:36 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:36 -0500] cupsdReadClient: 18 WAITING Closing on EOF
D [14/May/2014:12:17:36 -0500] cupsdCloseClient: 18
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:36 -0500] PID 2554 (/usr/lib/cups/backend/ipp) 
exited with no errors.
D [14/May/2014:12:17:36 -0500] cupsdMarkDirty(P-----)
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:36 -0500] Discarding unused job-completed event...
I [14/May/2014:12:17:36 -0500] [Job 44] Job completed.
D [14/May/2014:12:17:36 -0500] cupsdMarkDirty(----J-)
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:36 -0500] cupsdSetBusyState: newbusy="Printing jobs 
and dirty files", busy="Printing jobs and dirty files"
D [14/May/2014:12:17:36 -0500] Discarding unused printer-state-changed 
event...
D [14/May/2014:12:17:37 -0500] [Job 44] Unloading...

More information about the cups mailing list