Bug#771259: cups: Printing via a raw queue is broken

[Brian Potkin]

On Fri 28 Nov 2014 at 00:56:36 +0000, Brian Potkin wrote:

> Two logs are attached. Successful proceesing through a raw queue happens
> when the gziptoany filter is invoked.

The correct log-fail is attached to this message.

Forgetfully,

Brian.

D [27/Nov/2014:22:27:14 +0000] [Client 14] Accepted from localhost (Domain)
D [27/Nov/2014:22:27:14 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:27:14 +0000] [Client 14] POST / HTTP/1.1
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Active clients and 
dirty files", busy="Dirty files"
D [27/Nov/2014:22:27:14 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:27:14 +0000] [Client 14] 2.0 Get-Printer-Attributes 1
D [27/Nov/2014:22:27:14 +0000] Get-Printer-Attributes 
ipp://localhost:631/printers/test
D [27/Nov/2014:22:27:14 +0000] [Client 14] Returning IPP successful-ok for 
Get-Printer-Attributes (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:27:14 +0000] [Client 14] Content-Length: 731
D [27/Nov/2014:22:27:14 +0000] [Client 14] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=731, response=0xb9425f60(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:14 +0000] [Client 14] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:14 +0000] [Client 14] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:14 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Dirty files", 
busy="Active clients and dirty files"
D [27/Nov/2014:22:27:14 +0000] [Client 14] POST /printers/test HTTP/1.1
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Active clients and 
dirty files", busy="Dirty files"
D [27/Nov/2014:22:27:14 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:27:14 +0000] [Client 14] 2.0 Create-Job 2
D [27/Nov/2014:22:27:14 +0000] Create-Job ipp://localhost:631/printers/test
D [27/Nov/2014:22:27:14 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Active clients and 
dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:27:14 +0000] add_job: requesting-user-name="root"
I [27/Nov/2014:22:27:14 +0000] [Job 5] Adding start banner page "none".
D [27/Nov/2014:22:27:14 +0000] Discarding unused job-created event...
I [27/Nov/2014:22:27:14 +0000] [Job 5] Queued on "test" by "root".
D [27/Nov/2014:22:27:14 +0000] [Client 14] Returning IPP successful-ok for 
Create-Job (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:27:14 +0000] [Client 14] Content-Length: 181
D [27/Nov/2014:22:27:14 +0000] [Client 14] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=181, response=0xb9425fb8(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:14 +0000] [Client 14] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:14 +0000] [Client 14] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:14 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Dirty files", 
busy="Active clients and dirty files"
D [27/Nov/2014:22:27:14 +0000] [Client 14] POST /printers/test HTTP/1.1
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Active clients and 
dirty files", busy="Dirty files"
D [27/Nov/2014:22:27:14 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:27:14 +0000] [Client 14] 2.0 Send-Document 3
D [27/Nov/2014:22:27:14 +0000] Send-Document ipp://localhost:631/printers/test
D [27/Nov/2014:22:27:14 +0000] cupsdIsAuthorized: requesting-user-name="root"
D [27/Nov/2014:22:27:14 +0000] [Job 5] Auto-typing file...
D [27/Nov/2014:22:27:14 +0000] [Job 5] Request file type is text/plain.
D [27/Nov/2014:22:27:14 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Active clients and 
dirty files", busy="Active clients and dirty files"
I [27/Nov/2014:22:27:14 +0000] [Job 5] File of type text/plain queued by "root".
I [27/Nov/2014:22:27:14 +0000] [Job 5] Adding end banner page "none".
D [27/Nov/2014:22:27:14 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Active clients and 
dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:27:14 +0000] [Job 5] time-at-processing=1417127234
D [27/Nov/2014:22:27:14 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Active clients and 
dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Active clients and 
dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:27:14 +0000] Discarding unused printer-state-changed event...
D [27/Nov/2014:22:27:14 +0000] [Job 5] Sending job to queue tagged as raw...
D [27/Nov/2014:22:27:14 +0000] [Job 5] job-sheets=none,none
D [27/Nov/2014:22:27:14 +0000] [Job 5] argv[0]="test"
D [27/Nov/2014:22:27:14 +0000] [Job 5] argv[1]="5"
D [27/Nov/2014:22:27:14 +0000] [Job 5] argv[2]="root"
D [27/Nov/2014:22:27:14 +0000] [Job 5] argv[3]=".profile"
D [27/Nov/2014:22:27:14 +0000] [Job 5] argv[4]="1"
D [27/Nov/2014:22:27:14 +0000] [Job 5] argv[5]="finishings=3 number-up=1 
job-uuid=urn:uuid:ce84c32f-5eea-37fc-5b61-b70d1908f03e 
job-originating-host-name=localhost time-at-creation=1417127234 
time-at-processing=1417127234"
D [27/Nov/2014:22:27:14 +0000] [Job 5] argv[6]="/var/spool/cups/d00005-001"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [27/Nov/2014:22:27:14 +0000] [Job 5] 
envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [27/Nov/2014:22:27:14 +0000] [Job 5] 
envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [27/Nov/2014:22:27:14 +0000] [Job 5] 
envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[8]="HOME=/var/spool/cups/tmp"
D [27/Nov/2014:22:27:14 +0000] [Job 5] 
envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[10]="SERVER_ADMIN=root@jessie-b2"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[11]="SOFTWARE=CUPS/1.7.1"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[13]="TZ=Europe/London"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[14]="USER=root"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[15]="CUPS_MAX_MESSAGE=2047"
D [27/Nov/2014:22:27:14 +0000] [Job 5] 
envp[16]="CUPS_SERVER=/var/run/cups/cups.sock"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[17]="CUPS_ENCRYPTION=IfRequested"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[18]="IPP_PORT=631"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[19]="CHARSET=utf-8"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[20]="LANG=en_GB.UTF-8"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[21]="PPD=/etc/cups/ppd/test.ppd"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[22]="RIP_MAX_CACHE=128m"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[23]="CONTENT_TYPE=text/plain"
D [27/Nov/2014:22:27:14 +0000] [Job 5] 
envp[24]="DEVICE_URI=file:/home/brian/test"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[25]="PRINTER_INFO=test"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[26]="PRINTER_LOCATION="
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[27]="PRINTER=test"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[28]="PRINTER_STATE_REASONS=none"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[29]="CUPS_FILETYPE=document"
D [27/Nov/2014:22:27:14 +0000] [Job 5] envp[30]="AUTH_I****"
D [27/Nov/2014:22:27:14 +0000] Discarding unused job-state-changed event...
D [27/Nov/2014:22:27:14 +0000] [Client 14] Returning IPP successful-ok for 
Send-Document (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:27:14 +0000] [Client 14] Content-Length: 173
D [27/Nov/2014:22:27:14 +0000] [Client 14] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=173, response=0xb94460c8(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:14 +0000] [Client 14] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:14 +0000] [Client 14] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:14 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Printing jobs and 
dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:27:14 +0000] [Job 5] time-at-completed=1417127234
D [27/Nov/2014:22:27:14 +0000] Discarding unused job-completed event...
I [27/Nov/2014:22:27:14 +0000] [Job 5] Job completed.
D [27/Nov/2014:22:27:14 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Printing jobs and 
dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Printing jobs and 
dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:27:14 +0000] Discarding unused printer-state-changed event...
D [27/Nov/2014:22:27:14 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Printing jobs and 
dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:27:14 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Printing jobs and 
dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:27:14 +0000] [Client 14] HTTP_STATE_WAITING Closing on EOF
D [27/Nov/2014:22:27:14 +0000] [Client 14] Closing connection.
D [27/Nov/2014:22:27:14 +0000] cupsdSetBusyState: newbusy="Dirty files", 
busy="Printing jobs and dirty files"
D [27/Nov/2014:22:27:15 +0000] [Job 5] Unloading...
I [27/Nov/2014:22:27:17 +0000] Saving printers.conf...
I [27/Nov/2014:22:27:17 +0000] Saving job.cache...
D [27/Nov/2014:22:27:17 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Dirty files"
D [27/Nov/2014:22:27:22 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:22 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:22 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:22 +0000] [Client 15] 2.0 CUPS-Get-Printers 53
D [27/Nov/2014:22:27:22 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:27:22 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:27:22 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:27:22 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb945a3a0(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:22 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:22 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:22 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:22 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:22 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:22 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:22 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:22 +0000] [Client 15] 2.0 CUPS-Get-Default 54
D [27/Nov/2014:22:27:22 +0000] CUPS-Get-Default
D [27/Nov/2014:22:27:22 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:27:22 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:27:22 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:27:22 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb944abc8(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:22 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:22 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:22 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:22 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:23 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:23 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:23 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:23 +0000] [Client 15] 2.0 CUPS-Get-Printers 55
D [27/Nov/2014:22:27:23 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:27:23 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:27:23 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:27:23 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb9449f48(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:23 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:23 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:23 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:23 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:23 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:23 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:23 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:23 +0000] [Client 15] 2.0 CUPS-Get-Default 56
D [27/Nov/2014:22:27:23 +0000] CUPS-Get-Default
D [27/Nov/2014:22:27:23 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:27:23 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:27:23 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:27:23 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb945a230(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:23 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:23 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:23 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:23 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:26 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:26 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:26 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:26 +0000] [Client 15] 2.0 CUPS-Get-Printers 57
D [27/Nov/2014:22:27:26 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:27:26 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:27:26 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:27:26 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb9459798(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:26 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:26 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:26 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:26 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:26 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:26 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:26 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:26 +0000] [Client 15] 2.0 CUPS-Get-Default 58
D [27/Nov/2014:22:27:26 +0000] CUPS-Get-Default
D [27/Nov/2014:22:27:26 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:27:26 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:27:26 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:27:26 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb945a3a0(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:26 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:26 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:26 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:26 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:53 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:53 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:53 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:53 +0000] Report: clients=1
D [27/Nov/2014:22:27:53 +0000] Report: jobs=5
D [27/Nov/2014:22:27:53 +0000] Report: jobs-active=0
D [27/Nov/2014:22:27:53 +0000] Report: printers=10
D [27/Nov/2014:22:27:53 +0000] Report: stringpool-string-count=886
D [27/Nov/2014:22:27:53 +0000] Report: stringpool-alloc-bytes=8056
D [27/Nov/2014:22:27:53 +0000] Report: stringpool-total-bytes=17704
D [27/Nov/2014:22:27:53 +0000] [Client 15] 2.0 CUPS-Get-Printers 59
D [27/Nov/2014:22:27:53 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:27:53 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:27:53 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:27:53 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb944abc8(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:53 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:53 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:53 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:53 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:53 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:53 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:53 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:53 +0000] [Client 15] 2.0 CUPS-Get-Default 60
D [27/Nov/2014:22:27:53 +0000] CUPS-Get-Default
D [27/Nov/2014:22:27:53 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:27:53 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:27:53 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:27:53 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb9449f48(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:53 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:53 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:53 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:53 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:54 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:54 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:54 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:54 +0000] [Client 15] 2.0 CUPS-Get-Printers 61
D [27/Nov/2014:22:27:54 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:27:54 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:27:54 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:27:54 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb945a230(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:54 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:54 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:54 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:54 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:54 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:54 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:54 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:54 +0000] [Client 15] 2.0 CUPS-Get-Default 62
D [27/Nov/2014:22:27:54 +0000] CUPS-Get-Default
D [27/Nov/2014:22:27:54 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:27:54 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:27:54 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:27:54 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb9459798(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:54 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:54 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:54 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:54 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:57 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:57 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:57 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:57 +0000] [Client 15] 2.0 CUPS-Get-Printers 63
D [27/Nov/2014:22:27:57 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:27:57 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:27:57 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:27:57 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb945a3a0(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:57 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:57 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:57 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:57 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:27:57 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:27:57 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:27:57 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:27:57 +0000] [Client 15] 2.0 CUPS-Get-Default 64
D [27/Nov/2014:22:27:57 +0000] CUPS-Get-Default
D [27/Nov/2014:22:27:57 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:27:57 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:27:57 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:27:57 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb944abc8(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:27:57 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:27:57 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:27:57 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:27:57 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:28:23 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:28:23 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:28:23 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:28:23 +0000] [Client 15] 2.0 CUPS-Get-Printers 65
D [27/Nov/2014:22:28:23 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:28:23 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:28:23 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:28:23 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb9449f48(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:28:23 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:28:23 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:28:23 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:28:23 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:28:23 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:28:23 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:28:23 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:28:23 +0000] [Client 15] 2.0 CUPS-Get-Default 66
D [27/Nov/2014:22:28:23 +0000] CUPS-Get-Default
D [27/Nov/2014:22:28:23 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:28:23 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:28:23 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:28:23 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb945a230(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:28:23 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:28:23 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:28:23 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:28:23 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:28:24 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:28:24 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:28:24 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:28:24 +0000] [Client 15] 2.0 CUPS-Get-Printers 67
D [27/Nov/2014:22:28:24 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:28:24 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:28:24 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:28:24 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb9459798(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:28:24 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:28:24 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:28:24 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:28:24 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:28:24 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:28:24 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:28:24 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:28:24 +0000] [Client 15] 2.0 CUPS-Get-Default 68
D [27/Nov/2014:22:28:24 +0000] CUPS-Get-Default
D [27/Nov/2014:22:28:24 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:28:24 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:28:24 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:28:24 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb945a3a0(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:28:24 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:28:24 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:28:24 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:28:24 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:28:27 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:28:27 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:28:27 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:28:27 +0000] [Client 15] 2.0 CUPS-Get-Printers 69
D [27/Nov/2014:22:28:27 +0000] CUPS-Get-Printers
D [27/Nov/2014:22:28:27 +0000] [Client 15] Returning IPP successful-ok for 
CUPS-Get-Printers (no URI) from localhost
D [27/Nov/2014:22:28:27 +0000] [Client 15] Content-Length: 7877
D [27/Nov/2014:22:28:27 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=7877, response=0xb944abc8(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:28:27 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:28:27 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:28:27 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:28:27 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"
D [27/Nov/2014:22:28:27 +0000] [Client 15] POST / HTTP/1.1
D [27/Nov/2014:22:28:27 +0000] cupsdSetBusyState: newbusy="Active clients", 
busy="Not busy"
D [27/Nov/2014:22:28:27 +0000] [Client 15] No authentication data provided.
D [27/Nov/2014:22:28:27 +0000] [Client 15] 2.0 CUPS-Get-Default 70
D [27/Nov/2014:22:28:27 +0000] CUPS-Get-Default
D [27/Nov/2014:22:28:27 +0000] CUPS-Get-Default client-error-not-found: No 
default printer.
D [27/Nov/2014:22:28:27 +0000] [Client 15] Returning IPP client-error-not-found 
for CUPS-Get-Default (no URI) from localhost
D [27/Nov/2014:22:28:27 +0000] [Client 15] Content-Length: 113
D [27/Nov/2014:22:28:27 +0000] [Client 15] cupsdWriteClient error=0, used=0, 
state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, 
data_remaining=113, response=0xb9449f48(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:28:27 +0000] [Client 15] Writing IPP response, 
ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:28:27 +0000] [Client 15] bytes=0, http_state=0, 
data_remaining=0
D [27/Nov/2014:22:28:27 +0000] [Client 15] Waiting for request.
D [27/Nov/2014:22:28:27 +0000] cupsdSetBusyState: newbusy="Not busy", 
busy="Active clients"