Bug#808879: cups: fails to print anything on Samsung ML-1610 following upgrade

To: Debian Bug Tracking System <submit@bugs.debian.org>
Subject: Bug#808879: cups: fails to print anything on Samsung ML-1610 following upgrade
From: Julian Gilbey <jdg@debian.org>
Date: Thu, 24 Dec 2015 00:15:05 +0000
Message-id: <[🔎] 145091610567.20676.7502247393242527197.reportbug@erdos.d-and-j.net>
Reply-to: Julian Gilbey <jdg@debian.org>, 808879@bugs.debian.org

Package: cups-filters
Version: 1.4.0-1
Severity: important

Hello!

I upgrading my testing system today, and now I can't print anything to
my Samsung ML-1610.  (I printed several pages immediately prior to the
upgrade.)  It's quite an old printer, admittedly, but even so...  I
tried restarting cups, restarting my printer, all to no avail.

I upgraded cups-filters, cups-browsed, cups-filters-core-drivers,
libcupsfilters1, libfontembed1 from 1.3.0-1 to 1.4.0-1.

I've tried using the foomatic driver and the splix driver, neither of
which work.

I'm attaching the cups error_log file (with debugging) for an attempt
to print a test page.  The printer prints out a page which says

INTERNAL ERROR - FALSE

  POSITION : (some hex number which varies from run to run)
  SYSTEM   : various things beginning H6FWSIM/, after the slash has
             come gdi, os_hook and xl_image
  LINE     : 321, 1314, 605 respectively
  VERSION  : QPDL 1.26 04-14-2005

Unfortunately, even downgrading cups-filters back to 1.3.0-1 has not
restored the printer, so it might be some other package which is
causing the problem :(

Any ideas would be very gratefully appreciated - I'd love to be able
to print once again!

Thanks,

   Julian

-- System Information:
Debian Release: stretch/sid
  APT prefers testing
  APT policy: (500, 'testing'), (500, 'stable')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 4.3.0-1-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_GB.utf8, LC_CTYPE=en_GB.utf8 (charmap=UTF-8) (ignored: LC_ALL set to en_GB.UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages cups-filters depends on:
ii  bc                         1.06.95-9+b1
ii  cups-filters-core-drivers  1.4.0-1
ii  ghostscript                9.16~dfsg-2
ii  imagemagick                8:6.8.9.9-6
ii  libc6                      2.21-4
ii  libcups2                   2.1.2-1
ii  libcupsfilters1            1.4.0-1
ii  libcupsimage2              2.1.2-1
ii  libfontconfig1             2.11.0-6.3
ii  libfontembed1              1.4.0-1
ii  libgcc1                    1:5.3.1-3
ii  libijs-0.35                0.35-11
ii  liblouis-data              2.6.4-2
ii  liblouisutdml-bin          2.5.0-2
ii  libpoppler57               0.38.0-2
ii  libqpdf17                  6.0.0-2
ii  libstdc++6                 5.3.1-3
ii  poppler-utils              0.38.0-2

Versions of packages cups-filters recommends:
ii  colord  1.2.12-1

Versions of packages cups-filters suggests:
pn  antiword                                   <none>
ii  docx2txt                                   1.4-0.1
ii  foomatic-db-compressed-ppds [foomatic-db]  20150825-1

-- no debconf information

D [23/Dec/2015:23:48:36 +0000] [Client 119] Accepted from localhost:60156 (IPv6)
D [23/Dec/2015:23:48:36 +0000] [Client 119] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 119] POST /printers/HomePrinter HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [23/Dec/2015:23:48:36 +0000] [Client 119] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 119] Authorized as "root" using Basic.
D [23/Dec/2015:23:48:36 +0000] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc-root"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[10] = "SERVER_ADMIN=root@erdos"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[11] = "SOFTWARE=CUPS/2.1.2"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[13] = "USER=root"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[17] = "IPP_PORT=631"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[22] = "SERVER_NAME=localhost"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[23] = "SERVER_PORT=631"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[26] = "SCRIPT_NAME=/printers/HomePrinter"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc-root/printers/HomePrinter"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[28] = "PATH_INFO=/HomePrinter"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[29] = "REMOTE_USER=root"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=ff762005379484e59b8062e2cebe84d1"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Firefox/38.0 Iceweasel/38.5.0"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[33] = "HTTP_REFERER=http://localhost:631/printers/HomePrinter";
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[34] = "REQUEST_METHOD=POST"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[35] = "CONTENT_LENGTH=64"
D [23/Dec/2015:23:48:36 +0000] [CGI] envp[36] = "CONTENT_TYPE=application/x-www-form-urlencoded"
D [23/Dec/2015:23:48:36 +0000] cupsdAddCert: Adding certificate for PID 20533
D [23/Dec/2015:23:48:36 +0000] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 20533)
I [23/Dec/2015:23:48:36 +0000] [Client 119] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=20533, file=22)
D [23/Dec/2015:23:48:36 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:36 +0000] [Client 120] Accepted from localhost:60158 (IPv6)
D [23/Dec/2015:23:48:36 +0000] [Client 120] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [CGI] org.cups.sid cookie is \"ff762005379484e59b8062e2cebe84d1\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: org.cups.sid=\"ff762005379484e59b8062e2cebe84d1\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: OP=\"print-test-page\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"HomePrinter\"
D [23/Dec/2015:23:48:36 +0000] [Client 121] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 121] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 121] POST /printers/HomePrinter HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [23/Dec/2015:23:48:36 +0000] [Client 121] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 121] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 121] 2.0 Print-Job 1
D [23/Dec/2015:23:48:36 +0000] Print-Job ipp://localhost:631/printers/HomePrinter
D [23/Dec/2015:23:48:36 +0000] [Job ???] Auto-typing file...
I [23/Dec/2015:23:48:36 +0000] [Job ???] Request file type is application/vnd.cups-pdf-banner.
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [23/Dec/2015:23:48:36 +0000] add_job: requesting-user-name="root"
D [23/Dec/2015:23:48:36 +0000] Adding default job-sheets values "none,none"...
I [23/Dec/2015:23:48:36 +0000] [Job 1024] Adding start banner page "none".
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [23/Dec/2015:23:48:36 +0000] [Job 1024] Adding end banner page "none".
I [23/Dec/2015:23:48:36 +0000] [Job 1024] File of type application/vnd.cups-pdf-banner queued by "root".
D [23/Dec/2015:23:48:36 +0000] [Job 1024] hold_until=0
I [23/Dec/2015:23:48:36 +0000] [Job 1024] Queued on "HomePrinter" by "root".
D [23/Dec/2015:23:48:36 +0000] [Job 1024] time-at-processing=1450914516
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] 3 filters for job:
D [23/Dec/2015:23:48:36 +0000] [Job 1024] bannertopdf (application/vnd.cups-pdf-banner to application/pdf, cost 32)
D [23/Dec/2015:23:48:36 +0000] [Job 1024] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [23/Dec/2015:23:48:36 +0000] [Job 1024] foomatic-rip (application/vnd.cups-pdf to printer/HomePrinter, cost 0)
D [23/Dec/2015:23:48:36 +0000] [Job 1024] job-sheets=none,none
D [23/Dec/2015:23:48:36 +0000] [Job 1024] argv[0]="HomePrinter"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] argv[1]="1024"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] argv[2]="root"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] argv[3]="Test Page"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] argv[4]="1"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] argv[5]="job-uuid=urn:uuid:ed863eb3-4f2c-3bb8-5d69-e95f71a0d651 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1450914516 time-at-processing=1450914516"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] argv[6]="/var/spool/cups/d01024-001"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[8]="HOME=/var/spool/cups/tmp"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[10]="SERVER_ADMIN=root@erdos"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[11]="SOFTWARE=CUPS/2.1.2"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[13]="USER=root"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[14]="CUPS_MAX_MESSAGE=2047"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[17]="IPP_PORT=631"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[18]="CHARSET=utf-8"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[19]="LANG=en_GB.UTF-8"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[20]="PPD=/etc/cups/ppd/HomePrinter.ppd"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[21]="RIP_MAX_CACHE=128m"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[22]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[23]="DEVICE_URI=usb://Samsung/ML-1610?serial=3937BAFY504048V."
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[24]="PRINTER_INFO=Samsung ML-1610"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[25]="PRINTER_LOCATION="
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[26]="PRINTER=HomePrinter"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[27]="PRINTER_STATE_REASONS=none"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[28]="CUPS_FILETYPE=document"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] envp[30]="AUTH_I****"
I [23/Dec/2015:23:48:36 +0000] [Job 1024] Started filter /usr/lib/cups/filter/bannertopdf (PID 20534)
I [23/Dec/2015:23:48:36 +0000] [Job 1024] Started filter /usr/lib/cups/filter/pdftopdf (PID 20535)
I [23/Dec/2015:23:48:36 +0000] [Job 1024] Started filter /usr/lib/cups/filter/foomatic-rip (PID 20536)
I [23/Dec/2015:23:48:36 +0000] [Job 1024] Started backend /usr/lib/cups/backend/usb (PID 20537)
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 121] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/HomePrinter) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 121] Content-Length: 194
D [23/Dec/2015:23:48:36 +0000] [Client 121] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 121] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:36 +0000] [Client 121] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=194, response=0x55ab981a6150(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 121] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 121] bytes=0, http_state=0, data_remaining=194
D [23/Dec/2015:23:48:36 +0000] [Client 121] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 121] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 121] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] JobCreated
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] PrinterStateChanged
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] JobState
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetArray: job_uri[0]=\"/jobs/1024\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetArray: job_id[0]=\"1024\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetArray: job_state[0]=\"3\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetArray: job_state_message[0]=\"\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetArray: job_state_reasons[0]=\"none\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: refresh_page=\"2;URL=/printers/HomePrinter\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: TITLE=\"Print Test Page\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:36 +0000] [Client 119] CGI data ready to be sent.
D [23/Dec/2015:23:48:36 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"HomePrinter\"
D [23/Dec/2015:23:48:36 +0000] [Client 121] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:36 +0000] [Client 121] Closing connection.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:36 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=20533, file=22
D [23/Dec/2015:23:48:36 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:36 +0000] [Client 119] Script header: Content-Type: text/html;charset=utf-8
D [23/Dec/2015:23:48:36 +0000] [Client 119] Script header: 
D [23/Dec/2015:23:48:36 +0000] [Client 119] Sending status 200 for CGI.
D [23/Dec/2015:23:48:36 +0000] [Client 119] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [23/Dec/2015:23:48:36 +0000] PID 20533 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [23/Dec/2015:23:48:36 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:36 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20533, file=22
D [23/Dec/2015:23:48:36 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:36 +0000] [Client 119] CGI data ready to be sent.
D [23/Dec/2015:23:48:36 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:36 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20533, file=22
D [23/Dec/2015:23:48:36 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:36 +0000] [Client 119] Sending 0-length chunk.
D [23/Dec/2015:23:48:36 +0000] [Client 119] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 119] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 119] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Calling FindDeviceById(cups-HomePrinter)
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Loading USB quirks from \"/usr/share/cups/usb\".
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Loaded 119 quirks.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Printing on printer with URI: usb://Samsung/ML-1610?serial=3937BAFY504048V.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Found device /org/freedesktop/ColorManager/devices/cups_HomePrinter
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Calling org.freedesktop.ColorManager.Device.Get(ProfilingInhibitors)
D [23/Dec/2015:23:48:36 +0000] [Job 1024] PDF template file doesn\'t have form. It\'s okay.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] \'CM Color Calibration\' Mode in SPOOLER-LESS: Off
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Getting input from file 
D [23/Dec/2015:23:48:36 +0000] [Job 1024] foomatic-rip version 1.4.0 running...
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Parsing PPD file ...
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option ColorSpace
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option Manualfeed
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option Resolution
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option Economode
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option MediaType
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option RET
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option Copies
D [23/Dec/2015:23:48:36 +0000] [Job 1024] libusb_get_device_list=13
D [23/Dec/2015:23:48:36 +0000] [Job 1024] STATE: +connecting-to-device
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] PrinterStateChanged
D [23/Dec/2015:23:48:36 +0000] [Job 1024] STATE: -connecting-to-device
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] PrinterStateChanged
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option PageSize
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option ImageableArea
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option PaperDimension
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option Density
D [23/Dec/2015:23:48:36 +0000] [Job 1024] PID 20534 (/usr/lib/cups/filter/bannertopdf) exited with no errors.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option JamRecovery
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option AllowReprint
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option Altitude
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option PageTimeout
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option PowerSaving
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option PowerSaveTime
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option PageSizeJCL
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option PageSizePS
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Added option Font
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Parameter Summary
D [23/Dec/2015:23:48:36 +0000] [Job 1024] -----------------
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Spooler: cups
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Printer: HomePrinter
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Shell: /bin/sh
D [23/Dec/2015:23:48:36 +0000] [Job 1024] PPD file: /etc/cups/ppd/HomePrinter.ppd
D [23/Dec/2015:23:48:36 +0000] [Job 1024] ATTR file: 
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Printer model: Samsung ML-1610 Foomatic/gdi
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Job title: Test Page
D [23/Dec/2015:23:48:36 +0000] [Job 1024] File(s) to be printed:
D [23/Dec/2015:23:48:36 +0000] [Job 1024] <STDIN>
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Ghostscript extra search path (\'GS_LIB\'): /usr/share/cups/fonts
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Printing system options:
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Pondering option \'job-uuid=urn:uuid:ed863eb3-4f2c-3bb8-5d69-e95f71a0d651\'
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Unknown option job-uuid=urn:uuid:ed863eb3-4f2c-3bb8-5d69-e95f71a0d651.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Pondering option \'job-originating-host-name=localhost\'
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Unknown option job-originating-host-name=localhost.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Pondering option \'date-time-at-creation=\'
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Unknown option date-time-at-creation=.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Pondering option \'date-time-at-processing=\'
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Unknown option date-time-at-processing=.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Pondering option \'time-at-creation=1450914516\'
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Unknown option time-at-creation=1450914516.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Pondering option \'time-at-processing=1450914516\'
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Unknown option time-at-processing=1450914516.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] CM Color Calibration Mode in CUPS: Off
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Options from the PPD file:
D [23/Dec/2015:23:48:36 +0000] [Job 1024] ================================================
D [23/Dec/2015:23:48:36 +0000] [Job 1024] File: <STDIN>
D [23/Dec/2015:23:48:36 +0000] [Job 1024] ================================================
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Device protocol: 2
I [23/Dec/2015:23:48:36 +0000] [Job 1024] Sending data to printer.
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Set job-printer-state-message to "Sending data to printer.", current level=INFO
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Filetype: PDF
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Storing temporary files in /var/spool/cups/tmp
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] JobProgress
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] PrinterStateChanged
D [23/Dec/2015:23:48:36 +0000] [Job 1024] PID 20535 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] File contains 1 pages
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Starting renderer with command: gs -q -dBATCH -dPARANOIDSAFER -dQUIET -dNOPAUSE -dNOINTERPOLATE -sDEVICE=gdi -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -r600x600 -sOutputFile=- -f    /var/spool/cups/tmp/foomatic-TFxYst | perl -p -e \'s/PJL PAGE LETTER/PJL PAGE A4/; s/PJL PAGE (\\S*) AUTO/PJL PAGE $1 AUTO/; s/PJL SET TONERSAVE = OFF/PJL SET TONERSAVE = OFF\\r\\n\\@PJL SET ECONOMODE = OFF/; s/PJL SET PAPERTYPE = NORMAL/PJL SET PAPERTYPE = NORMAL/; s/PJL SET DENSITY = 1/PJL SET DENSITY = 3/; s/(\\@PJL ENTER LANGUAGE)/\\@PJL SET RET = OFF\\r\\n$1/; s/(\\@PJL ENTER LANGUAGE)/\\@PJL SET JAMRECOVERY = ON\\r\\n$1/; s/(\\@PJL ENTER LANGUAGE)/\\@PJL SET REPRINT = ON\\r\\n$1/; s/(\\@PJL ENTER LANGUAGE)/\\@PJL SET ALTITUDE = OFF\\r\\n$1/; s/PJL COPIES = 1/PJL COPIES = 1/; s/(\\@PJL ENTER LANGUAGE)/\\@PJL DEFAULT TIMEOUT = 15\\r\\n$1/; s/(\\@PJL ENTER LANGUAGE)/\\@PJL DEFAULT POWERSAVE = ON\\r\\n$1/; s/(\\@PJL ENTER LANGUAGE)/\\@PJL DEFAULT POWERSAV
 ETIME = 5\\r\\n$1/; \'
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Starting process \"kid3\" (generation 1)
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Starting process \"kid4\" (generation 2)
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Starting process \"renderer\" (generation 2)
D [23/Dec/2015:23:48:36 +0000] [Job 1024] JCL: \033%-12345X@PJL
D [23/Dec/2015:23:48:36 +0000] [Job 1024] <job data> 
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Read 8192 bytes of print data...
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Got USB pipe stalled during write.
D [23/Dec/2015:23:48:36 +0000] [Client 122] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 122] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 122] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 122] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 122] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 122] 2.0 Get-Notifications 124
D [23/Dec/2015:23:48:36 +0000] Get-Notifications /
D [23/Dec/2015:23:48:36 +0000] cupsdIsAuthorized: requesting-user-name="jdg"
D [23/Dec/2015:23:48:36 +0000] [Client 122] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 122] Content-Length: 3367
D [23/Dec/2015:23:48:36 +0000] [Client 122] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 122] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:36 +0000] [Client 122] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=3367, response=0x55ab98214420(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 122] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 122] bytes=0, http_state=0, data_remaining=3367
D [23/Dec/2015:23:48:36 +0000] [Client 122] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 122] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 122] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 122] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 122] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 122] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 122] 2.0 Get-Job-Attributes 125
D [23/Dec/2015:23:48:36 +0000] Get-Job-Attributes ipp://localhost/jobs/1024
D [23/Dec/2015:23:48:36 +0000] [Client 122] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/1024) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 122] Content-Length: 1018
D [23/Dec/2015:23:48:36 +0000] [Client 122] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 122] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:36 +0000] [Client 122] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1018, response=0x55ab981d5880(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 122] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 122] bytes=0, http_state=0, data_remaining=1018
D [23/Dec/2015:23:48:36 +0000] [Client 122] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 122] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 122] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 123] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 123] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 123] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 123] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 123] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 123] 2.0 Get-Printer-Attributes 126
D [23/Dec/2015:23:48:36 +0000] Get-Printer-Attributes 
D [23/Dec/2015:23:48:36 +0000] Get-Printer-Attributes client-error-not-found: The printer or class does not exist.
D [23/Dec/2015:23:48:36 +0000] [Client 123] Returning IPP client-error-not-found for Get-Printer-Attributes () from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 123] Content-Length: 130
D [23/Dec/2015:23:48:36 +0000] [Client 123] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 123] con->http=0x55ab981b4aa0
D [23/Dec/2015:23:48:36 +0000] [Client 123] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=130, response=0x55ab98214420(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 123] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 123] bytes=0, http_state=0, data_remaining=130
D [23/Dec/2015:23:48:36 +0000] [Client 123] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 123] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 123] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 123] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:36 +0000] [Client 123] Closing connection.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 124] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 124] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 124] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 124] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 124] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 124] 2.0 Get-Job-Attributes 127
D [23/Dec/2015:23:48:36 +0000] Get-Job-Attributes ipp://localhost/jobs/1024
D [23/Dec/2015:23:48:36 +0000] [Client 124] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/1024) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 124] Content-Length: 175
D [23/Dec/2015:23:48:36 +0000] [Client 124] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 124] con->http=0x55ab981b4aa0
D [23/Dec/2015:23:48:36 +0000] [Client 124] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=175, response=0x55ab98214420(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 124] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 124] bytes=0, http_state=0, data_remaining=175
D [23/Dec/2015:23:48:36 +0000] [Client 124] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 124] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 124] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 124] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:36 +0000] [Client 124] Closing connection.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Wrote 8192 bytes of print data...
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Read 8192 bytes of print data...
D [23/Dec/2015:23:48:36 +0000] [Client 125] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 125] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 125] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 125] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 125] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 125] 2.0 Get-Job-Attributes 128
D [23/Dec/2015:23:48:36 +0000] Get-Job-Attributes ipp://localhost/jobs/1024
D [23/Dec/2015:23:48:36 +0000] [Client 125] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/1024) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 125] Content-Length: 101
D [23/Dec/2015:23:48:36 +0000] [Client 125] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 125] con->http=0x55ab981b4aa0
D [23/Dec/2015:23:48:36 +0000] [Client 125] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x55ab9822dc40(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 125] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 125] bytes=0, http_state=0, data_remaining=101
D [23/Dec/2015:23:48:36 +0000] [Client 125] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 125] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 125] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 125] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:36 +0000] [Client 125] Closing connection.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 126] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 126] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 126] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 126] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 126] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 126] 2.0 Get-Job-Attributes 129
D [23/Dec/2015:23:48:36 +0000] Get-Job-Attributes ipp://localhost/jobs/1024
D [23/Dec/2015:23:48:36 +0000] [Client 126] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/1024) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 126] Content-Length: 101
D [23/Dec/2015:23:48:36 +0000] [Client 126] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 126] con->http=0x55ab981b4aa0
D [23/Dec/2015:23:48:36 +0000] [Client 126] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x55ab981d9d70(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 126] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 126] bytes=0, http_state=0, data_remaining=101
D [23/Dec/2015:23:48:36 +0000] [Client 126] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 126] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 126] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 126] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:36 +0000] [Client 126] Closing connection.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 127] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 127] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 127] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 127] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 127] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 127] 2.0 Get-Job-Attributes 130
D [23/Dec/2015:23:48:36 +0000] Get-Job-Attributes ipp://localhost/jobs/1024
D [23/Dec/2015:23:48:36 +0000] [Client 127] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/1024) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 127] Content-Length: 101
D [23/Dec/2015:23:48:36 +0000] [Client 127] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 127] con->http=0x55ab981b4aa0
D [23/Dec/2015:23:48:36 +0000] [Client 127] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x55ab9822dc40(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 127] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 127] bytes=0, http_state=0, data_remaining=101
D [23/Dec/2015:23:48:36 +0000] [Client 127] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 127] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 127] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 127] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:36 +0000] [Client 127] Closing connection.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 122] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:36 +0000] [Client 122] Closing connection.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Wrote 8192 bytes of print data...
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Read 8192 bytes of print data...
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Got USB pipe stalled during write.
E [23/Dec/2015:23:48:36 +0000] [Job 1024] Unable to send data to printer.
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Set job-printer-state-message to "Unable to send data to printer.", current level=ERROR
D [23/Dec/2015:23:48:36 +0000] [Job 1024] libusb write operation returned fffffff7.
D [23/Dec/2015:23:48:36 +0000] [Job 1024] Sent 16384 bytes...
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] JobProgress
D [23/Dec/2015:23:48:36 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:36 +0000] [Notifier] PrinterStateChanged
D [23/Dec/2015:23:48:36 +0000] [Client 128] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 128] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 128] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 128] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 128] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 128] 2.0 Get-Notifications 131
D [23/Dec/2015:23:48:36 +0000] Get-Notifications /
D [23/Dec/2015:23:48:36 +0000] cupsdIsAuthorized: requesting-user-name="jdg"
D [23/Dec/2015:23:48:36 +0000] [Client 128] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 128] Content-Length: 1073
D [23/Dec/2015:23:48:36 +0000] [Client 128] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 128] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:36 +0000] [Client 128] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1073, response=0x55ab981d5680(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 128] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 128] bytes=0, http_state=0, data_remaining=1073
D [23/Dec/2015:23:48:36 +0000] [Client 128] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 128] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 128] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 129] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:36 +0000] [Client 129] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] [Client 129] POST / HTTP/1.1
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:36 +0000] [Client 129] Read: status=200
D [23/Dec/2015:23:48:36 +0000] [Client 129] No authentication data provided.
D [23/Dec/2015:23:48:36 +0000] [Client 129] 2.0 Get-Job-Attributes 132
D [23/Dec/2015:23:48:36 +0000] Get-Job-Attributes ipp://localhost/jobs/1024
D [23/Dec/2015:23:48:36 +0000] [Client 129] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/1024) from localhost
D [23/Dec/2015:23:48:36 +0000] [Client 129] Content-Length: 101
D [23/Dec/2015:23:48:36 +0000] [Client 129] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:36 +0000] [Client 129] con->http=0x55ab981b4aa0
D [23/Dec/2015:23:48:36 +0000] [Client 129] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x55ab981d5850(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:36 +0000] [Client 129] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:36 +0000] [Client 129] bytes=0, http_state=0, data_remaining=101
D [23/Dec/2015:23:48:36 +0000] [Client 129] Flushing write buffer.
D [23/Dec/2015:23:48:36 +0000] [Client 129] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:36 +0000] [Client 129] Waiting for request.
D [23/Dec/2015:23:48:36 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:37 +0000] [Client 129] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:37 +0000] [Client 129] Closing connection.
D [23/Dec/2015:23:48:37 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:37 +0000] [Client 128] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:37 +0000] [Client 128] Closing connection.
D [23/Dec/2015:23:48:37 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:37 +0000] [Job 1024] Waiting for read thread to exit...
D [23/Dec/2015:23:48:38 +0000] [Client 119] GET /printers/HomePrinter HTTP/1.1
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:38 +0000] [Client 119] Read: status=200
D [23/Dec/2015:23:48:38 +0000] [Client 119] Authorized as "root" using Basic.
D [23/Dec/2015:23:48:38 +0000] [Client 119] Processing GET /printers/HomePrinter
D [23/Dec/2015:23:48:38 +0000] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc-root"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[10] = "SERVER_ADMIN=root@erdos"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[11] = "SOFTWARE=CUPS/2.1.2"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[13] = "USER=root"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[17] = "IPP_PORT=631"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[22] = "SERVER_NAME=localhost"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[23] = "SERVER_PORT=631"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[26] = "SCRIPT_NAME=/printers/HomePrinter"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc-root/printers/HomePrinter"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[28] = "PATH_INFO=/HomePrinter"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[29] = "REMOTE_USER=root"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=ff762005379484e59b8062e2cebe84d1"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Firefox/38.0 Iceweasel/38.5.0"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[33] = "HTTP_REFERER=http://localhost:631/printers/HomePrinter";
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[34] = "REQUEST_METHOD=GET"
D [23/Dec/2015:23:48:38 +0000] [CGI] envp[35] = "QUERY_STRING="
D [23/Dec/2015:23:48:38 +0000] cupsdAddCert: Adding certificate for PID 20550
D [23/Dec/2015:23:48:38 +0000] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 20550)
I [23/Dec/2015:23:48:38 +0000] [Client 119] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=20550, file=22)
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [CGI] org.cups.sid cookie is \"ff762005379484e59b8062e2cebe84d1\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [Client 130] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:38 +0000] [Client 130] Waiting for request.
D [23/Dec/2015:23:48:38 +0000] [Client 130] POST / HTTP/1.1
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:38 +0000] [Client 130] Read: status=200
D [23/Dec/2015:23:48:38 +0000] [Client 130] No authentication data provided.
D [23/Dec/2015:23:48:38 +0000] [Client 130] 2.0 CUPS-Get-Default 1
D [23/Dec/2015:23:48:38 +0000] CUPS-Get-Default
D [23/Dec/2015:23:48:38 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [23/Dec/2015:23:48:38 +0000] [Client 130] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [23/Dec/2015:23:48:38 +0000] [Client 130] Content-Length: 113
D [23/Dec/2015:23:48:38 +0000] [Client 130] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:38 +0000] [Client 130] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:38 +0000] [Client 130] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x55ab98231cc0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:38 +0000] [Client 130] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:38 +0000] [Client 130] bytes=0, http_state=0, data_remaining=113
D [23/Dec/2015:23:48:38 +0000] [Client 130] Flushing write buffer.
D [23/Dec/2015:23:48:38 +0000] [Client 130] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:38 +0000] [Client 130] Waiting for request.
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:38 +0000] [CGI] show_printer(http=0x55cc48e14970, printer=\"HomePrinter\")
D [23/Dec/2015:23:48:38 +0000] [Client 130] POST / HTTP/1.1
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:38 +0000] [Client 130] Read: status=200
D [23/Dec/2015:23:48:38 +0000] [Client 130] No authentication data provided.
D [23/Dec/2015:23:48:38 +0000] [Client 130] 2.0 Get-Printer-Attributes 2
D [23/Dec/2015:23:48:38 +0000] Get-Printer-Attributes ipp://localhost/printers/HomePrinter
D [23/Dec/2015:23:48:38 +0000] [Client 130] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HomePrinter) from localhost
D [23/Dec/2015:23:48:38 +0000] [Client 130] Content-Length: 655
D [23/Dec/2015:23:48:38 +0000] [Client 130] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:38 +0000] [Client 130] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:38 +0000] [Client 130] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=655, response=0x55ab981db690(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:38 +0000] [Client 130] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:38 +0000] [Client 130] bytes=0, http_state=0, data_remaining=655
D [23/Dec/2015:23:48:38 +0000] [Client 130] Flushing write buffer.
D [23/Dec/2015:23:48:38 +0000] [Client 130] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:38 +0000] [Client 130] Waiting for request.
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_is_shared[0]=\"1\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_state[0]=\"4\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_name[0]=\"HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_location[0]=\"\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_info[0]=\"Samsung ML-1610\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: device_uri[0]=\"usb://Samsung/ML-1610?serial=3937BAFY504048V.\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: color_supported[0]=\"0\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_make_and_model[0]=\"Samsung ML-1610 Foomatic/gdi\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: media_default[0]=\"iso_a4_210x297mm\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: sides_supported[0]=\"one-sided\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"1\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: refresh_page=\"10;URL=/printers/HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: TITLE=\"HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:38 +0000] [Client 119] CGI data ready to be sent.
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [Client 119] Script header: Content-Type: text/html;charset=utf-8
D [23/Dec/2015:23:48:38 +0000] [Client 119] Script header: 
D [23/Dec/2015:23:48:38 +0000] [Client 119] Sending status 200 for CGI.
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [23/Dec/2015:23:48:38 +0000] [CGI] Regular expression \".*Clean.*\"
D [23/Dec/2015:23:48:38 +0000] [CGI] matches[0].rm_so=0
D [23/Dec/2015:23:48:38 +0000] [CGI] matches[1].rm_so=-1
D [23/Dec/2015:23:48:38 +0000] [CGI] Regular expression \".*PrintSelfTestPage.*\"
D [23/Dec/2015:23:48:38 +0000] [CGI] matches[0].rm_so=0
D [23/Dec/2015:23:48:38 +0000] [CGI] matches[1].rm_so=-1
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [Client 119] CGI data ready to be sent.
D [23/Dec/2015:23:48:38 +0000] [Client 130] POST / HTTP/1.1
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:38 +0000] [Client 130] Read: status=200
D [23/Dec/2015:23:48:38 +0000] [Client 130] No authentication data provided.
D [23/Dec/2015:23:48:38 +0000] [Client 130] 2.0 Get-Jobs 3
D [23/Dec/2015:23:48:38 +0000] Get-Jobs ipp://localhost:631/printers/HomePrinter
D [23/Dec/2015:23:48:38 +0000] [Client 130] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HomePrinter) from localhost
D [23/Dec/2015:23:48:38 +0000] [Client 130] Content-Length: 356
D [23/Dec/2015:23:48:38 +0000] [Client 130] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [Client 130] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:38 +0000] [Client 130] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=356, response=0x55ab98231cc0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:38 +0000] [Client 130] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:38 +0000] [Client 130] bytes=0, http_state=0, data_remaining=356
D [23/Dec/2015:23:48:38 +0000] [Client 130] Flushing write buffer.
D [23/Dec/2015:23:48:38 +0000] [Client 130] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:38 +0000] [Client 130] Waiting for request.
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiClearVariables called.
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: ORDER=\"asc\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: TOTAL=\"1\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: job_printer_name[0]=\"HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: time_at_creation[0]=\"Wed 23 Dec 2015 23:48:36 GMT\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: time_at_processing[0]=\"Wed 23 Dec 2015 23:48:36 GMT\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: job_id[0]=\"1024\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: job_state[0]=\"5\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"0\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetArray: job_printer_state_message[0]=\"Unable to send data to printer.\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: THISURL=\"/printers/HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [CGI] cgiSetVariable: SEARCH_DEST=\"HomePrinter\"
D [23/Dec/2015:23:48:38 +0000] [Client 119] CGI data ready to be sent.
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [Client 119] CGI data ready to be sent.
D [23/Dec/2015:23:48:38 +0000] [Client 130] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:38 +0000] [Client 130] Closing connection.
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [Client 119] CGI data ready to be sent.
D [23/Dec/2015:23:48:38 +0000] PID 20550 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [23/Dec/2015:23:48:38 +0000] [Client 119] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:38 +0000] [Client 119] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20550, file=22
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for CGI data.
D [23/Dec/2015:23:48:38 +0000] [Client 119] Sending 0-length chunk.
D [23/Dec/2015:23:48:38 +0000] [Client 119] Flushing write buffer.
D [23/Dec/2015:23:48:38 +0000] [Client 119] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:38 +0000] [Client 119] Waiting for request.
D [23/Dec/2015:23:48:38 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [23/Dec/2015:23:48:41 +0000] [Client 120] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:41 +0000] [Client 120] Closing connection.
D [23/Dec/2015:23:48:41 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:44 +0000] [Job 1024] Read thread still active, aborting the pending read...
D [23/Dec/2015:23:48:45 +0000] [Job 1024] Resetting printer.
D [23/Dec/2015:23:48:45 +0000] [Job 1024] PID 20537 (/usr/lib/cups/backend/usb) stopped with status 1.
D [23/Dec/2015:23:48:45 +0000] [Job 1024] renderer exited with status 141
D [23/Dec/2015:23:48:45 +0000] [Job 1024] A filter used in addition to the renderer itself may have failed.Kid3 exit status: 1
D [23/Dec/2015:23:48:45 +0000] [Job 1024] PID 20536 (/usr/lib/cups/filter/foomatic-rip) stopped with status 9.
I [23/Dec/2015:23:48:45 +0000] [Job 1024] Backend returned status 1 (failed)
D [23/Dec/2015:23:48:45 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [23/Dec/2015:23:48:45 +0000] [Job 1024] Printer stopped due to backend errors; please consult the error_log file for details.
D [23/Dec/2015:23:48:45 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:45 +0000] cupsdMarkDirty(----S)
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:45 +0000] cupsdMarkDirty(P----)
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:45 +0000] cupsdRegisterPrinter(p=0x55ab98129800(HomePrinter))
D [23/Dec/2015:23:48:45 +0000] Registering "Samsung ML-1610 @ erdos" with DNS-SD type "_printer._tcp".
D [23/Dec/2015:23:48:45 +0000] Registering "Samsung ML-1610 @ erdos" with DNS-SD type "_ipps._tcp".
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" printer-type=0x801006
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" printer-state=5
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" TLS=1.2
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" UUID=854f6b01-5d5d-371e-5936-e574c0250243
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" URF=DM3
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" pdl=application/octet-stream,application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" product=(ML-1610)
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" priority=0
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" note=
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" adminurl=https://erdos.local:631/printers/HomePrinter
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" ty=Samsung ML-1610 Foomatic/gdi
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" rp=printers/HomePrinter
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" qtotal=1
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" txtvers=1
D [23/Dec/2015:23:48:45 +0000] Registering "Samsung ML-1610 @ erdos" with DNS-SD type "_ipp._tcp".
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" printer-type=0x801006
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" printer-state=5
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" TLS=1.2
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" UUID=854f6b01-5d5d-371e-5936-e574c0250243
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" URF=DM3
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" pdl=application/octet-stream,application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" product=(ML-1610)
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" priority=0
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" note=
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" adminurl=https://erdos.local:631/printers/HomePrinter
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" ty=Samsung ML-1610 Foomatic/gdi
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" rp=printers/HomePrinter
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" qtotal=1
D [23/Dec/2015:23:48:45 +0000] DNS_SD "Samsung ML-1610 @ erdos" txtvers=1
D [23/Dec/2015:23:48:45 +0000] cupsdMarkDirty(P----)
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:45 +0000] cupsdMarkDirty(---J-)
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:45 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:45 +0000] [Notifier] JobState
D [23/Dec/2015:23:48:45 +0000] [Notifier] state=3
D [23/Dec/2015:23:48:45 +0000] [Notifier] PrinterStopped
D [23/Dec/2015:23:48:45 +0000] [Client 131] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:45 +0000] [Client 131] Waiting for request.
D [23/Dec/2015:23:48:45 +0000] [Client 131] POST / HTTP/1.1
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
D [23/Dec/2015:23:48:45 +0000] [Client 131] Read: status=200
D [23/Dec/2015:23:48:45 +0000] [Client 131] No authentication data provided.
D [23/Dec/2015:23:48:45 +0000] [Client 131] 2.0 Get-Notifications 133
D [23/Dec/2015:23:48:45 +0000] Get-Notifications /
D [23/Dec/2015:23:48:45 +0000] cupsdIsAuthorized: requesting-user-name="jdg"
D [23/Dec/2015:23:48:45 +0000] [Client 131] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [23/Dec/2015:23:48:45 +0000] [Client 131] Content-Length: 1131
D [23/Dec/2015:23:48:45 +0000] [Client 131] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:45 +0000] [Client 131] con->http=0x55ab981f9c80
D [23/Dec/2015:23:48:45 +0000] [Client 131] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1131, response=0x55ab981314b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:45 +0000] [Client 131] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:45 +0000] [Client 131] bytes=0, http_state=0, data_remaining=1131
D [23/Dec/2015:23:48:45 +0000] [Client 131] Flushing write buffer.
D [23/Dec/2015:23:48:45 +0000] [Client 131] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:45 +0000] [Client 131] Waiting for request.
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:45 +0000] [Client 132] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:45 +0000] [Client 132] Waiting for request.
D [23/Dec/2015:23:48:45 +0000] [Client 132] POST / HTTP/1.1
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:45 +0000] [Client 132] Read: status=200
D [23/Dec/2015:23:48:45 +0000] [Client 132] No authentication data provided.
D [23/Dec/2015:23:48:45 +0000] [Client 132] 2.0 Get-Job-Attributes 134
D [23/Dec/2015:23:48:45 +0000] Get-Job-Attributes ipp://localhost/jobs/1024
D [23/Dec/2015:23:48:45 +0000] [Client 132] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/1024) from localhost
D [23/Dec/2015:23:48:45 +0000] [Client 132] Content-Length: 101
D [23/Dec/2015:23:48:45 +0000] [Client 132] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:45 +0000] [Client 132] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:45 +0000] [Client 132] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x55ab98131470(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:45 +0000] [Client 132] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:45 +0000] [Client 132] bytes=0, http_state=0, data_remaining=101
D [23/Dec/2015:23:48:45 +0000] [Client 132] Flushing write buffer.
D [23/Dec/2015:23:48:45 +0000] [Client 132] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:45 +0000] [Client 132] Waiting for request.
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:45 +0000] [Client 132] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:45 +0000] [Client 132] Closing connection.
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:45 +0000] [Client 131] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:45 +0000] [Client 131] Closing connection.
D [23/Dec/2015:23:48:45 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 119] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:48 +0000] [Client 119] Closing connection.
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 133] Accepted from localhost:60160 (IPv6)
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for request.
D [23/Dec/2015:23:48:48 +0000] [Client 134] Accepted from localhost:60162 (IPv6)
D [23/Dec/2015:23:48:48 +0000] [Client 134] Waiting for request.
D [23/Dec/2015:23:48:48 +0000] [Client 133] GET /printers/HomePrinter HTTP/1.1
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 133] Read: status=200
D [23/Dec/2015:23:48:48 +0000] [Client 133] Authorized as "root" using Basic.
D [23/Dec/2015:23:48:48 +0000] [Client 133] Processing GET /printers/HomePrinter
D [23/Dec/2015:23:48:48 +0000] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/printers.cgi"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc-root"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[7] = "CUPS_STATEDIR=/var/run/cups"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[10] = "SERVER_ADMIN=root@erdos"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[11] = "SOFTWARE=CUPS/2.1.2"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[13] = "USER=root"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[15] = "CUPS_SERVER=/var/run/cups/cups.sock"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[17] = "IPP_PORT=631"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[22] = "SERVER_NAME=localhost"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[23] = "SERVER_PORT=631"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[26] = "SCRIPT_NAME=/printers/HomePrinter"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc-root/printers/HomePrinter"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[28] = "PATH_INFO=/HomePrinter"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[29] = "REMOTE_USER=root"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[30] = "SERVER_PROTOCOL=HTTP/1.1"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[31] = "HTTP_COOKIE=org.cups.sid=ff762005379484e59b8062e2cebe84d1"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[32] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Firefox/38.0 Iceweasel/38.5.0"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[33] = "REQUEST_METHOD=GET"
D [23/Dec/2015:23:48:48 +0000] [CGI] envp[34] = "QUERY_STRING="
D [23/Dec/2015:23:48:48 +0000] cupsdAddCert: Adding certificate for PID 20557
D [23/Dec/2015:23:48:48 +0000] [CGI] Started /usr/lib/cups/cgi-bin/printers.cgi (PID 20557)
I [23/Dec/2015:23:48:48 +0000] [Client 133] Started "/usr/lib/cups/cgi-bin/printers.cgi" (pid=20557, file=22)
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [CGI] org.cups.sid cookie is \"ff762005379484e59b8062e2cebe84d1\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: REFRESH_PAGE=\"\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [Client 135] Accepted from localhost (Domain)
D [23/Dec/2015:23:48:48 +0000] [Client 135] Waiting for request.
D [23/Dec/2015:23:48:48 +0000] [Client 135] POST / HTTP/1.1
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 135] Read: status=200
D [23/Dec/2015:23:48:48 +0000] [Client 135] No authentication data provided.
D [23/Dec/2015:23:48:48 +0000] [Client 135] 2.0 CUPS-Get-Default 1
D [23/Dec/2015:23:48:48 +0000] CUPS-Get-Default
D [23/Dec/2015:23:48:48 +0000] CUPS-Get-Default client-error-not-found: No default printer.
D [23/Dec/2015:23:48:48 +0000] [Client 135] Returning IPP client-error-not-found for CUPS-Get-Default (no URI) from localhost
D [23/Dec/2015:23:48:48 +0000] [Client 135] Content-Length: 113
D [23/Dec/2015:23:48:48 +0000] [Client 135] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:48 +0000] [Client 135] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:48 +0000] [Client 135] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=113, response=0x55ab981d5680(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:48 +0000] [Client 135] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:48 +0000] [Client 135] bytes=0, http_state=0, data_remaining=113
D [23/Dec/2015:23:48:48 +0000] [Client 135] Flushing write buffer.
D [23/Dec/2015:23:48:48 +0000] [Client 135] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:48 +0000] [Client 135] Waiting for request.
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:48 +0000] [CGI] show_printer(http=0x557e08d7e970, printer=\"HomePrinter\")
D [23/Dec/2015:23:48:48 +0000] [Client 135] POST / HTTP/1.1
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 135] Read: status=200
D [23/Dec/2015:23:48:48 +0000] [Client 135] No authentication data provided.
D [23/Dec/2015:23:48:48 +0000] [Client 135] 2.0 Get-Printer-Attributes 2
D [23/Dec/2015:23:48:48 +0000] Get-Printer-Attributes ipp://localhost/printers/HomePrinter
D [23/Dec/2015:23:48:48 +0000] [Client 135] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HomePrinter) from localhost
D [23/Dec/2015:23:48:48 +0000] [Client 135] Content-Length: 655
D [23/Dec/2015:23:48:48 +0000] [Client 135] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:48 +0000] [Client 135] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:48 +0000] [Client 135] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=655, response=0x55ab9822a9b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:48 +0000] [Client 135] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:48 +0000] [Client 135] bytes=0, http_state=0, data_remaining=655
D [23/Dec/2015:23:48:48 +0000] [Client 135] Flushing write buffer.
D [23/Dec/2015:23:48:48 +0000] [Client 135] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:48 +0000] [Client 135] Waiting for request.
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_is_accepting_jobs[0]=\"1\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_is_shared[0]=\"1\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_state[0]=\"5\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: admin_uri[0]=\"/admin/\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_uri_supported[0]=\"/printers/HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_name[0]=\"HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_location[0]=\"\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_info[0]=\"Samsung ML-1610\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: job_sheets_default[0]=\"none, none\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: device_uri[0]=\"usb://Samsung/ML-1610?serial=3937BAFY504048V.\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: color_supported[0]=\"0\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_make_and_model[0]=\"Samsung ML-1610 Foomatic/gdi\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: media_default[0]=\"iso_a4_210x297mm\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: sides_supported[0]=\"one-sided\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: sides_default[0]=\"one-sided\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: printer_commands[0]=\"AutoConfigure, Clean, PrintSelfTestPage\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: server_is_sharing_printers[0]=\"1\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: TITLE=\"HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:48 +0000] [Client 133] CGI data ready to be sent.
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [Client 133] Script header: Content-Type: text/html;charset=utf-8
D [23/Dec/2015:23:48:48 +0000] [Client 133] Script header: 
D [23/Dec/2015:23:48:48 +0000] [Client 133] Sending status 200 for CGI.
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [23/Dec/2015:23:48:48 +0000] [CGI] Regular expression \".*Clean.*\"
D [23/Dec/2015:23:48:48 +0000] [CGI] matches[0].rm_so=0
D [23/Dec/2015:23:48:48 +0000] [CGI] matches[1].rm_so=-1
D [23/Dec/2015:23:48:48 +0000] [CGI] Regular expression \".*PrintSelfTestPage.*\"
D [23/Dec/2015:23:48:48 +0000] [CGI] matches[0].rm_so=0
D [23/Dec/2015:23:48:48 +0000] [CGI] matches[1].rm_so=-1
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [Client 133] CGI data ready to be sent.
D [23/Dec/2015:23:48:48 +0000] [Client 135] POST / HTTP/1.1
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 135] Read: status=200
D [23/Dec/2015:23:48:48 +0000] [Client 135] No authentication data provided.
D [23/Dec/2015:23:48:48 +0000] [Client 135] 2.0 Get-Jobs 3
D [23/Dec/2015:23:48:48 +0000] Get-Jobs ipp://localhost:631/printers/HomePrinter
D [23/Dec/2015:23:48:48 +0000] [Client 135] Returning IPP successful-ok for Get-Jobs (ipp://localhost:631/printers/HomePrinter) from localhost
D [23/Dec/2015:23:48:48 +0000] [Client 135] Content-Length: 356
D [23/Dec/2015:23:48:48 +0000] [Client 135] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [Client 135] con->http=0x55ab981acdb0
D [23/Dec/2015:23:48:48 +0000] [Client 135] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=356, response=0x55ab981959d0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [23/Dec/2015:23:48:48 +0000] [Client 135] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [23/Dec/2015:23:48:48 +0000] [Client 135] bytes=0, http_state=0, data_remaining=356
D [23/Dec/2015:23:48:48 +0000] [Client 135] Flushing write buffer.
D [23/Dec/2015:23:48:48 +0000] [Client 135] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:48 +0000] [Client 135] Waiting for request.
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiClearVariables called.
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: ORDER=\"asc\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: SECTION=\"printers\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: TOTAL=\"1\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: SERVER_NAME=\"localhost\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: REMOTE_USER=\"root\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: CUPS_VERSION=\"CUPS v2.1.2\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: job_printer_name[0]=\"HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: job_printer_uri[0]=\"/printers/HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: time_at_completed[0]=\"novalue\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: time_at_creation[0]=\"Wed 23 Dec 2015 23:48:36 GMT\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: time_at_processing[0]=\"Wed 23 Dec 2015 23:48:36 GMT\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: job_id[0]=\"1024\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: job_state[0]=\"3\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: job_media_sheets_completed[0]=\"0\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: job_k_octets[0]=\"1\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetArray: job_printer_state_message[0]=\"Unable to send data to printer.\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: PRINTER_NAME=\"HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: PRINTER_URI_SUPPORTED=\"/printers/HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: THISURL=\"/printers/HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [CGI] cgiSetVariable: SEARCH_DEST=\"HomePrinter\"
D [23/Dec/2015:23:48:48 +0000] [Client 133] CGI data ready to be sent.
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [Client 133] CGI data ready to be sent.
D [23/Dec/2015:23:48:48 +0000] [Client 135] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:48 +0000] [Client 135] Closing connection.
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] PID 20557 (/usr/lib/cups/cgi-bin/printers.cgi) exited with no errors.
D [23/Dec/2015:23:48:48 +0000] [Client 133] CGI data ready to be sent.
D [23/Dec/2015:23:48:48 +0000] [Client 133] con->http=0x55ab982040a0
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=20557, file=22
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for CGI data.
D [23/Dec/2015:23:48:48 +0000] [Client 133] Sending 0-length chunk.
D [23/Dec/2015:23:48:48 +0000] [Client 133] Flushing write buffer.
D [23/Dec/2015:23:48:48 +0000] [Client 133] New state is HTTP_STATE_WAITING
D [23/Dec/2015:23:48:48 +0000] [Client 133] Waiting for request.
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 133] GET /cups.css HTTP/1.1
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:48 +0000] [Client 133] Read: status=200
D [23/Dec/2015:23:48:48 +0000] [Client 133] Authorized as "root" using Basic.
D [23/Dec/2015:23:48:48 +0000] [Client 133] Processing GET /cups.css
D [23/Dec/2015:23:48:48 +0000] [Client 133] filename="/usr/share/cups/doc-root/cups.css", type=text/css
D [23/Dec/2015:23:48:48 +0000] [Client 133] cupsdSendHeader: code=304, type="(null)", auth_type=0
D [23/Dec/2015:23:48:48 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [23/Dec/2015:23:48:53 +0000] [Client 134] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:53 +0000] [Client 134] Closing connection.
D [23/Dec/2015:23:48:53 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [23/Dec/2015:23:48:59 +0000] [Client 133] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [23/Dec/2015:23:48:59 +0000] [Client 133] Closing connection.
D [23/Dec/2015:23:48:59 +0000] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"

Reply to:

Prev by Date: foomatic-filters_4.0.17-1+deb7u1_amd64.changes ACCEPTED into oldstable-proposed-updates->oldstable-new
Next by Date: Bug#662780: marked as done (cups: new version causes printer to hang for ages, then only print a blank page)
Previous by thread: foomatic-filters_4.0.17-1+deb7u1_amd64.changes ACCEPTED into oldstable-proposed-updates->oldstable-new
Next by thread: Bug#662780: marked as done (cups: new version causes printer to hang for ages, then only print a blank page)
Index(es):
- Date
- Thread