[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

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



Package: cups
Version: 1.7.5-8
Severity: normal



  root@jessie-b2:~# dpkg -l cups | grep "ii"
  ii  cups           1.7.5-8      i386         Common UNIX Printing System(tm) - PPD/driver support, web interface

  root@jessie-b2:~# lpinfo -m | grep -i raw
  raw Raw Queue

  root@jessie-b2:~# lpadmin -p test -v file:/home/brian/test -E -m raw
  root@jessie-b2:~#

  root@jessie-b2:~# rm /home/brian/test
  rm: cannot remove ‘/home/brian/test’: No such file or directory

  root@jessie-b2:~# lp -d test /etc/services
  request id is test-7 (1 file(s))

  root@jessie-b2:~# ls -l /home/brian/test
  ls: cannot access /home/brian/test: No such file or directory

This doesn't happen on Wheezy; a file "test" is always produced. The
same outcome is obtained with

  lpadmin -p test -v file:/home/brian/test -E -m drv:///sample.drv/generic.ppd

and

  lp -d test -o raw /etc/services

Using snapshot.debian.org the last version of cups which behaved
correctly would appear to be 1.7.0-2. 1.7.1-1, 1.7.5-3 and 1.7.5-7 also
behave as above.

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

There is an unresolved report at

  https://www.cups.org/str.php?L4430

which appears to be a similar issue.

Regards,

Brian.
D [27/Nov/2014:22:33:40 +0000] [Client 14] Accepted from localhost (Domain)
D [27/Nov/2014:22:33:40 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:33:40 +0000] [Client 14] POST / HTTP/1.1
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:33:40 +0000] [Client 14] 2.0 Get-Printer-Attributes 1
D [27/Nov/2014:22:33:40 +0000] Get-Printer-Attributes ipp://localhost:631/printers/test
D [27/Nov/2014:22:33:40 +0000] [Client 14] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:33:40 +0000] [Client 14] Content-Length: 731
D [27/Nov/2014:22:33:40 +0000] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=731, response=0xb83b4838(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:33:40 +0000] [Client 14] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] bytes=0, http_state=0, data_remaining=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] POST /printers/test HTTP/1.1
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:33:40 +0000] [Client 14] 2.0 Create-Job 2
D [27/Nov/2014:22:33:40 +0000] Create-Job ipp://localhost:631/printers/test
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] add_job: requesting-user-name="root"
I [27/Nov/2014:22:33:40 +0000] [Job 3] Adding start banner page "none".
D [27/Nov/2014:22:33:40 +0000] Discarding unused job-created event...
I [27/Nov/2014:22:33:40 +0000] [Job 3] Queued on "test" by "root".
D [27/Nov/2014:22:33:40 +0000] [Client 14] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:33:40 +0000] [Client 14] Content-Length: 181
D [27/Nov/2014:22:33:40 +0000] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=181, response=0xb83b4710(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:33:40 +0000] [Client 14] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] bytes=0, http_state=0, data_remaining=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] POST /printers/test HTTP/1.1
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:33:40 +0000] [Client 14] 2.0 Send-Document 3
D [27/Nov/2014:22:33:40 +0000] Send-Document ipp://localhost:631/printers/test
D [27/Nov/2014:22:33:40 +0000] cupsdIsAuthorized: requesting-user-name="root"
D [27/Nov/2014:22:33:40 +0000] [Job 3] Auto-typing file...
D [27/Nov/2014:22:33:40 +0000] [Job 3] Request file type is text/plain.
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [27/Nov/2014:22:33:40 +0000] [Job 3] File of type text/plain queued by "root".
I [27/Nov/2014:22:33:40 +0000] [Job 3] Adding end banner page "none".
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Job 3] time-at-processing=1417127620
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] Discarding unused printer-state-changed event...
D [27/Nov/2014:22:33:40 +0000] [Job 3] Sending job to queue tagged as raw...
D [27/Nov/2014:22:33:40 +0000] [Job 3] job-sheets=none,none
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[0]="test"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[1]="3"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[2]="root"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[3]=".profile"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[4]="1"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[5]="finishings=3 number-up=1 job-uuid=urn:uuid:ca221cae-2804-3288-590b-102adfbacd92 job-originating-host-name=localhost time-at-creation=1417127620 time-at-processing=1417127620"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[6]="/var/spool/cups/d00003-001"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[8]="HOME=/var/spool/cups/tmp"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[10]="SERVER_ADMIN=root@jessie-b2"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[11]="SOFTWARE=CUPS/1.7.0"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[13]="TZ=Europe/London"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[14]="USER=root"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[15]="CUPS_MAX_MESSAGE=2047"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[16]="CUPS_SERVER=/var/run/cups/cups.sock"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[17]="CUPS_ENCRYPTION=IfRequested"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[18]="IPP_PORT=631"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[19]="CHARSET=utf-8"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[20]="LANG=en_GB.UTF-8"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[21]="PPD=/etc/cups/ppd/test.ppd"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[22]="RIP_MAX_CACHE=128m"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[23]="CONTENT_TYPE=text/plain"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[24]="DEVICE_URI=file:/home/brian/test"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[25]="PRINTER_INFO=test"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[26]="PRINTER_LOCATION="
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[27]="PRINTER=test"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[28]="PRINTER_STATE_REASONS=none"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[29]="CUPS_FILETYPE=document"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[30]="AUTH_I****"
I [27/Nov/2014:22:33:40 +0000] [Job 3] Started filter /usr/lib/cups/filter/gziptoany (PID 5006)
D [27/Nov/2014:22:33:40 +0000] Discarding unused job-state-changed event...
D [27/Nov/2014:22:33:40 +0000] [Client 14] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:33:40 +0000] [Client 14] Content-Length: 173
D [27/Nov/2014:22:33:40 +0000] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=173, response=0xb83b4868(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:33:40 +0000] [Client 14] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] bytes=0, http_state=0, data_remaining=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] HTTP_STATE_WAITING Closing on EOF
D [27/Nov/2014:22:33:40 +0000] [Client 14] Closing connection.
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Job 3] PAGE: 1 1
D [27/Nov/2014:22:33:40 +0000] Discarding unused job-progress event...
D [27/Nov/2014:22:33:40 +0000] [Job 3] PID 5006 (/usr/lib/cups/filter/gziptoany) exited with no errors.
D [27/Nov/2014:22:33:40 +0000] [Job 3] time-at-completed=1417127620
D [27/Nov/2014:22:33:40 +0000] Discarding unused job-completed event...
I [27/Nov/2014:22:33:40 +0000] [Job 3] Job completed.
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] Discarding unused printer-state-changed event...
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:41 +0000] [Job 3] Unloading...
I [27/Nov/2014:22:34:03 +0000] Saving printers.conf...
I [27/Nov/2014:22:34:03 +0000] Generating printcap /var/run/cups/printcap...
I [27/Nov/2014:22:34:03 +0000] Saving job.cache...
D [27/Nov/2014:22:34:03 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] Accepted from localhost (Domain)
D [27/Nov/2014:22:33:40 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:33:40 +0000] [Client 14] POST / HTTP/1.1
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:33:40 +0000] [Client 14] 2.0 Get-Printer-Attributes 1
D [27/Nov/2014:22:33:40 +0000] Get-Printer-Attributes ipp://localhost:631/printers/test
D [27/Nov/2014:22:33:40 +0000] [Client 14] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:33:40 +0000] [Client 14] Content-Length: 731
D [27/Nov/2014:22:33:40 +0000] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=731, response=0xb83b4838(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:33:40 +0000] [Client 14] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] bytes=0, http_state=0, data_remaining=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] POST /printers/test HTTP/1.1
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:33:40 +0000] [Client 14] 2.0 Create-Job 2
D [27/Nov/2014:22:33:40 +0000] Create-Job ipp://localhost:631/printers/test
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] add_job: requesting-user-name="root"
I [27/Nov/2014:22:33:40 +0000] [Job 3] Adding start banner page "none".
D [27/Nov/2014:22:33:40 +0000] Discarding unused job-created event...
I [27/Nov/2014:22:33:40 +0000] [Job 3] Queued on "test" by "root".
D [27/Nov/2014:22:33:40 +0000] [Client 14] Returning IPP successful-ok for Create-Job (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:33:40 +0000] [Client 14] Content-Length: 181
D [27/Nov/2014:22:33:40 +0000] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=181, response=0xb83b4710(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:33:40 +0000] [Client 14] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] bytes=0, http_state=0, data_remaining=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] POST /printers/test HTTP/1.1
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] No authentication data provided.
D [27/Nov/2014:22:33:40 +0000] [Client 14] 2.0 Send-Document 3
D [27/Nov/2014:22:33:40 +0000] Send-Document ipp://localhost:631/printers/test
D [27/Nov/2014:22:33:40 +0000] cupsdIsAuthorized: requesting-user-name="root"
D [27/Nov/2014:22:33:40 +0000] [Job 3] Auto-typing file...
D [27/Nov/2014:22:33:40 +0000] [Job 3] Request file type is text/plain.
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [27/Nov/2014:22:33:40 +0000] [Job 3] File of type text/plain queued by "root".
I [27/Nov/2014:22:33:40 +0000] [Job 3] Adding end banner page "none".
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Job 3] time-at-processing=1417127620
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] Discarding unused printer-state-changed event...
D [27/Nov/2014:22:33:40 +0000] [Job 3] Sending job to queue tagged as raw...
D [27/Nov/2014:22:33:40 +0000] [Job 3] job-sheets=none,none
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[0]="test"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[1]="3"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[2]="root"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[3]=".profile"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[4]="1"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[5]="finishings=3 number-up=1 job-uuid=urn:uuid:ca221cae-2804-3288-590b-102adfbacd92 job-originating-host-name=localhost time-at-creation=1417127620 time-at-processing=1417127620"
D [27/Nov/2014:22:33:40 +0000] [Job 3] argv[6]="/var/spool/cups/d00003-001"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[8]="HOME=/var/spool/cups/tmp"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[10]="SERVER_ADMIN=root@jessie-b2"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[11]="SOFTWARE=CUPS/1.7.0"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[13]="TZ=Europe/London"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[14]="USER=root"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[15]="CUPS_MAX_MESSAGE=2047"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[16]="CUPS_SERVER=/var/run/cups/cups.sock"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[17]="CUPS_ENCRYPTION=IfRequested"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[18]="IPP_PORT=631"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[19]="CHARSET=utf-8"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[20]="LANG=en_GB.UTF-8"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[21]="PPD=/etc/cups/ppd/test.ppd"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[22]="RIP_MAX_CACHE=128m"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[23]="CONTENT_TYPE=text/plain"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[24]="DEVICE_URI=file:/home/brian/test"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[25]="PRINTER_INFO=test"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[26]="PRINTER_LOCATION="
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[27]="PRINTER=test"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[28]="PRINTER_STATE_REASONS=none"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[29]="CUPS_FILETYPE=document"
D [27/Nov/2014:22:33:40 +0000] [Job 3] envp[30]="AUTH_I****"
I [27/Nov/2014:22:33:40 +0000] [Job 3] Started filter /usr/lib/cups/filter/gziptoany (PID 5006)
D [27/Nov/2014:22:33:40 +0000] Discarding unused job-state-changed event...
D [27/Nov/2014:22:33:40 +0000] [Client 14] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/test) from localhost
D [27/Nov/2014:22:33:40 +0000] [Client 14] Content-Length: 173
D [27/Nov/2014:22:33:40 +0000] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=173, response=0xb83b4868(IPP_IDLE), pipe_pid=0, file=-1
D [27/Nov/2014:22:33:40 +0000] [Client 14] Writing IPP response, ipp_state=DATA, old wused=0, new wused=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] bytes=0, http_state=0, data_remaining=0
D [27/Nov/2014:22:33:40 +0000] [Client 14] Waiting for request.
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Client 14] HTTP_STATE_WAITING Closing on EOF
D [27/Nov/2014:22:33:40 +0000] [Client 14] Closing connection.
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] [Job 3] PAGE: 1 1
D [27/Nov/2014:22:33:40 +0000] Discarding unused job-progress event...
D [27/Nov/2014:22:33:40 +0000] [Job 3] PID 5006 (/usr/lib/cups/filter/gziptoany) exited with no errors.
D [27/Nov/2014:22:33:40 +0000] [Job 3] time-at-completed=1417127620
D [27/Nov/2014:22:33:40 +0000] Discarding unused job-completed event...
I [27/Nov/2014:22:33:40 +0000] [Job 3] Job completed.
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] Discarding unused printer-state-changed event...
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:40 +0000] cupsdMarkDirty(---J-)
D [27/Nov/2014:22:33:40 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [27/Nov/2014:22:33:41 +0000] [Job 3] Unloading...
I [27/Nov/2014:22:34:03 +0000] Saving printers.conf...
I [27/Nov/2014:22:34:03 +0000] Generating printcap /var/run/cups/printcap...
I [27/Nov/2014:22:34:03 +0000] Saving job.cache...
D [27/Nov/2014:22:34:03 +0000] cupsdSetBusyState: newbusy="Not busy", busy="Printing jobs and dirty files"

Reply to: