[cups] compression=gzip between cups 1.5 and 1.4

Thu May 15 08:13:20 PDT 2014

Steve,

The CUPS IPP backend did not support automatic compression of driver data until 1.7.0. Prior to that, compression was only used when sending jobs as-is (like for a shared printer without a local PPD).

On May 14, 2014, at 10:53 AM, Steve Bergman <sbergman27 at gmail.com> wrote:

> 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...
> _______________________________________________
> cups mailing list
> cups at cups.org
> https://www.cups.org/mailman/listinfo/cups

_________________________________________________________
Michael Sweet, Senior Printing System Engineer, PWG Chair