Web lists-archives.com

cups "Filter failed" | filter rastertopdf stops with status 1 | local printing works; remote printing not




Hey!

i have a laptop and one remote server/computer. The remote server is bananian, i
hope that doesn't matter for this case.

I have  configured cups with hplip to print things on the remote server. That
means, i can go to https://remote-server/printers/printername in my laptop's
webbrowser and print a testpage there. However, when i visit
https://localhost:631 (on the laptop), add the printer of the remote-server
manually there (url is ipp://172.16.2.4:631/printers/HP_Officejet_6600) and
print e.g. the testpage, the job fails with "Filter failed".

What did i try:

* Interestingly, LogLevel debug doesn't contain the error, only LogLevel warn. However, i added both log files below.
* I found
https://thenumberzero.blogspot.com/2014/02/how-to-fix-hp-printer-filter-failed.html
- i did not complete what's suggested there
    * hp-check says, cups is not running or the package is missing (both on the
server as well as on my laptop), but i use the webinterface of cups
successfully. And i can even print from the remote server's 
 
* https://www.cups.org/doc/api-raster.html doesn't contain something status
related (the filter exited with status 1)
* googling "Unable to determine number of pages, page count" doesn't help. But i think that is only a result of the failed filter.
* I found https://lists.debian.org/debian-user/2017/03/msg00234.html but the filter fail for a different reason there.

used filters
------------

D [27/Jan/2019:20:38:14 +0100] [Job 13] 4 filters for job:
D [27/Jan/2019:20:38:14 +0100] [Job 13] rastertopwg (application/vnd.cups-raster to image/pwg-raster, cost 100)
D [27/Jan/2019:20:38:14 +0100] [Job 13] rastertopdf (image/pwg-raster to application/pdf, cost 32)
D [27/Jan/2019:20:38:14 +0100] [Job 13] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [27/Jan/2019:20:38:14 +0100] [Job 13] foomatic-rip (application/vnd.cups-pdf to printer/HP_Officejet_6600, cost 0)

failed filters
--------------

D [27/Jan/2019:20:38:14 +0100] [Job 13] PID 2562 (/usr/lib/cups/filter/rastertopdf) stopped with status 1.



lpstat -t on the remote server
------------------------------

# lpstat -t
scheduler is running
system default destination: HP_Officejet_6600
device for HP_Officejet_6600: hp:/usb/Officejet_6600?serial=CN48C9R1BQ05RN
HP_Officejet_6600 accepting requests since Sun 27 Jan 2019 06:22:03 PM CET
printer HP_Officejet_6600 is idle.  enabled since Sun 27 Jan 2019 06:22:03 PM
CET
HP_Officejet_6600-11    unknown         311296   Sun 27 Jan 2019 05:36:33 PM CET

lpstat -t on the laptop (contains also a local usb config)
---------------------

system default destination: Officejet-6600
device for Officejet-6600: hp:/usb/Officejet_6600?serial=CN48C9R1BQ05RN
device for remote_printer: ipp://172.16.2.4:631/printers/HP_Officejet_6600
Officejet-6600 accepting requests since Sat 19 Jan 2019 06:14:19 PM CET
remote_printer accepting requests since Sun 27 Jan 2019 05:36:29 PM CET
printer Officejet-6600 is idle.  enabled since Sat 19 Jan 2019 06:14:19 PM CET
printer remote_printer now printing remote_printer-32.  enabled since Sun 27 Jan
2019 05:36:29 PM CET
remote_printer-32       toogley           1024   Sun 27 Jan 2019 05:36:29 PM CET



/var/log/cups/error_log (LogLevel warn)
--------------------------------------

E [27/Jan/2019:20:38:14 +0100] [Job 13] Job stopped due to filter errors; please consult the error_log file for details.
D [27/Jan/2019:20:38:14 +0100] [Job 13] The following messages were recorded from 08:38:12 PM to 08:38:14 PM
D [27/Jan/2019:20:38:14 +0100] [Job 13] Adding start banner page "none".
D [27/Jan/2019:20:38:14 +0100] [Job 13] Queued on "HP_Officejet_6600" by "anonymous".
D [27/Jan/2019:20:38:14 +0100] [Job 13] File of type application/vnd.cups-raster queued by "anonymous".
D [27/Jan/2019:20:38:14 +0100] [Job 13] Adding end banner page "none".
D [27/Jan/2019:20:38:14 +0100] [Job 13] time-at-processing=1548617893
D [27/Jan/2019:20:38:14 +0100] [Job 13] 4 filters for job:
D [27/Jan/2019:20:38:14 +0100] [Job 13] rastertopwg (application/vnd.cups-raster to image/pwg-raster, cost 100)
D [27/Jan/2019:20:38:14 +0100] [Job 13] rastertopdf (image/pwg-raster to application/pdf, cost 32)
D [27/Jan/2019:20:38:14 +0100] [Job 13] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [27/Jan/2019:20:38:14 +0100] [Job 13] foomatic-rip (application/vnd.cups-pdf to printer/HP_Officejet_6600, cost 0)
D [27/Jan/2019:20:38:14 +0100] [Job 13] job-sheets=none,none
D [27/Jan/2019:20:38:14 +0100] [Job 13] argv[0]="HP_Officejet_6600"
D [27/Jan/2019:20:38:14 +0100] [Job 13] argv[1]="13"
D [27/Jan/2019:20:38:14 +0100] [Job 13] argv[2]="anonymous"
D [27/Jan/2019:20:38:14 +0100] [Job 13] argv[3]="Test Page"
D [27/Jan/2019:20:38:14 +0100] [Job 13] argv[4]="1"
D [27/Jan/2019:20:38:14 +0100] [Job 13] argv[5]="job-uuid=urn:uuid:5612d4e9-dbf9-30ad-462b-f47e9daab90a job-originating-host-name=172.16.2.7 date-time-at-creation= date-time-at-processing= time-at-creation=1548617892 time-at-processing=1548617893"
D [27/Jan/2019:20:38:14 +0100] [Job 13] argv[6]="/var/spool/cups/d00013-001"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[7]="CUPS_STATEDIR=/var/run/cups"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[8]="HOME=/var/spool/cups/tmp"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[10]="SERVER_ADMIN=root@bananapi"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[11]="SOFTWARE=CUPS/2.2.1"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[13]="TZ=Europe/Berlin"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[14]="USER=root"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[15]="CUPS_MAX_MESSAGE=2047"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[16]="CUPS_SERVER=/var/run/cups/cups.sock"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[17]="CUPS_ENCRYPTION=IfRequested"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[18]="IPP_PORT=631"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[19]="CHARSET=utf-8"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[20]="LANG=en_US.UTF-8"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[21]="PPD=/etc/cups/ppd/HP_Officejet_6600.ppd"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[22]="RIP_MAX_CACHE=128m"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[23]="CONTENT_TYPE=application/vnd.cups-raster"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[24]="DEVICE_URI=hp:/usb/Officejet_6600?serial=CN48C9R1BQ05RN"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[25]="PRINTER_INFO=remote printer - HP Officejet 6600"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[26]="PRINTER_LOCATION="
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[27]="PRINTER=HP_Officejet_6600"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[28]="PRINTER_STATE_REASONS=marker-supply-low-warning"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[29]="CUPS_FILETYPE=document"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[30]="FINAL_CONTENT_TYPE=application/vnd.cups-pdf"
D [27/Jan/2019:20:38:14 +0100] [Job 13] envp[31]="AUTH_I****"
D [27/Jan/2019:20:38:14 +0100] [Job 13] Started filter /usr/lib/cups/filter/rastertopwg (PID 2561)
D [27/Jan/2019:20:38:14 +0100] [Job 13] Started filter /usr/lib/cups/filter/rastertopdf (PID 2562)
D [27/Jan/2019:20:38:14 +0100] [Job 13] Started filter /usr/lib/cups/filter/pdftopdf (PID 2563)
D [27/Jan/2019:20:38:14 +0100] [Job 13] Started filter /usr/lib/cups/filter/foomatic-rip (PID 2564)
D [27/Jan/2019:20:38:14 +0100] [Job 13] Started backend /usr/lib/cups/backend/hp (PID 2565)
D [27/Jan/2019:20:38:14 +0100] [Job 13] PID 2561 (/usr/lib/cups/filter/rastertopwg) exited with no errors.
D [27/Jan/2019:20:38:14 +0100] [Job 13] PID 2562 (/usr/lib/cups/filter/rastertopdf) stopped with status 1.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Hint: Try setting the LogLevel to "debug" to find out more.
D [27/Jan/2019:20:38:14 +0100] [Job 13] PID 2563 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Color Manager: Calibration Mode/Off
D [27/Jan/2019:20:38:14 +0100] [Job 13] pdftopdf: Last filter determined by the PPD: foomatic-rip; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Calling FindDeviceById(cups-HP_Officejet_6600)
D [27/Jan/2019:20:38:14 +0100] [Job 13] Calling FindDeviceById(cups-HP_Officejet_6600)
D [27/Jan/2019:20:38:14 +0100] [Job 13] Found device /org/freedesktop/ColorManager/devices/cups_HP_Officejet_6600
D [27/Jan/2019:20:38:14 +0100] [Job 13] Calling org.freedesktop.ColorManager.Device.Get(ProfilingInhibitors)
D [27/Jan/2019:20:38:14 +0100] [Job 13] Found device /org/freedesktop/ColorManager/devices/cups_HP_Officejet_6600
D [27/Jan/2019:20:38:14 +0100] [Job 13] Calling org.freedesktop.ColorManager.Device.Get(ProfilingInhibitors)
D [27/Jan/2019:20:38:14 +0100] [Job 13] \'CM Color Calibration\' Mode in SPOOLER-LESS: Off
D [27/Jan/2019:20:38:14 +0100] [Job 13] Getting input from file 
D [27/Jan/2019:20:38:14 +0100] [Job 13] foomatic-rip version 1.11.6 running...
D [27/Jan/2019:20:38:14 +0100] [Job 13] Parsing PPD file ...
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option ColorSpace
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option Resolution
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option PageSize
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option Model
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option PrintoutMode
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option InputSlot
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option Duplex
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option DryTime
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option Quality
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option ImageableArea
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option PaperDimension
D [27/Jan/2019:20:38:14 +0100] [Job 13] Added option Font
D [27/Jan/2019:20:38:14 +0100] [Job 13] Parameter Summary
D [27/Jan/2019:20:38:14 +0100] [Job 13] -----------------
D [27/Jan/2019:20:38:14 +0100] [Job 13] Spooler: cups
D [27/Jan/2019:20:38:14 +0100] [Job 13] Printer: HP_Officejet_6600
D [27/Jan/2019:20:38:14 +0100] [Job 13] Shell: /bin/sh
D [27/Jan/2019:20:38:14 +0100] [Job 13] PPD file: /etc/cups/ppd/HP_Officejet_6600.ppd
D [27/Jan/2019:20:38:14 +0100] [Job 13] ATTR file: 
D [27/Jan/2019:20:38:14 +0100] [Job 13] Printer model: HP Officejet 6600 hpijs, 3.16.11
D [27/Jan/2019:20:38:14 +0100] [Job 13] Job title: Test Page
D [27/Jan/2019:20:38:14 +0100] [Job 13] File(s) to be printed:
D [27/Jan/2019:20:38:14 +0100] [Job 13] <STDIN>
D [27/Jan/2019:20:38:14 +0100] [Job 13] Ghostscript extra search path (\'GS_LIB\'): /usr/share/cups/fonts
D [27/Jan/2019:20:38:14 +0100] [Job 13] Printing system options:
D [27/Jan/2019:20:38:14 +0100] [Job 13] Pondering option \'job-uuid=urn:uuid:5612d4e9-dbf9-30ad-462b-f47e9daab90a\'
D [27/Jan/2019:20:38:14 +0100] [Job 13] Unknown option job-uuid=urn:uuid:5612d4e9-dbf9-30ad-462b-f47e9daab90a.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Pondering option \'job-originating-host-name=172.16.2.7\'
D [27/Jan/2019:20:38:14 +0100] [Job 13] Unknown option job-originating-host-name=172.16.2.7.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Pondering option \'date-time-at-creation=\'
D [27/Jan/2019:20:38:14 +0100] [Job 13] Unknown option date-time-at-creation=.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Pondering option \'date-time-at-processing=\'
D [27/Jan/2019:20:38:14 +0100] [Job 13] Unknown option date-time-at-processing=.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Pondering option \'time-at-creation=1548617892\'
D [27/Jan/2019:20:38:14 +0100] [Job 13] Unknown option time-at-creation=1548617892.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Pondering option \'time-at-processing=1548617893\'
D [27/Jan/2019:20:38:14 +0100] [Job 13] Unknown option time-at-processing=1548617893.
D [27/Jan/2019:20:38:14 +0100] [Job 13] CM Color Calibration Mode in CUPS: Off
D [27/Jan/2019:20:38:14 +0100] [Job 13] Options from the PPD file:
D [27/Jan/2019:20:38:14 +0100] [Job 13] ================================================
D [27/Jan/2019:20:38:14 +0100] [Job 13] File: <STDIN>
D [27/Jan/2019:20:38:14 +0100] [Job 13] ================================================
D [27/Jan/2019:20:38:14 +0100] [Job 13] Filetype: PDF
D [27/Jan/2019:20:38:14 +0100] [Job 13] Storing temporary files in /var/spool/cups/tmp
D [27/Jan/2019:20:38:14 +0100] [Job 13] Process is dying with \"Unable to determine number of pages, page count: -1
D [27/Jan/2019:20:38:14 +0100] [Job 13] \", exit stat 3
D [27/Jan/2019:20:38:14 +0100] [Job 13] Cleaning up...
D [27/Jan/2019:20:38:14 +0100] [Job 13] prnt/backend/hp.c 919: ERROR: null print job total=0
D [27/Jan/2019:20:38:14 +0100] [Job 13] PID 2565 (/usr/lib/cups/backend/hp) exited with no errors.
D [27/Jan/2019:20:38:14 +0100] [Job 13] PID 2564 (/usr/lib/cups/filter/foomatic-rip) stopped with status 3.
D [27/Jan/2019:20:38:14 +0100] [Job 13] Hint: Try setting the LogLevel to "debug" to find out more.
D [27/Jan/2019:20:38:14 +0100] [Job 13] End of messages
D [27/Jan/2019:20:38:14 +0100] [Job 13] printer-state=3(idle)
D [27/Jan/2019:20:38:14 +0100] [Job 13] printer-state-message="Filter failed"
D [27/Jan/2019:20:38:14 +0100] [Job 13] printer-state-reasons=marker-supply-low-warning



/var/log/cups/error_log (LogLevel debug)
--------------------------

I [27/Jan/2019:20:31:37 +0100] Saving subscriptions.conf...
D [27/Jan/2019:20:31:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
I [27/Jan/2019:20:31:38 +0100] Saving job.cache...
D [27/Jan/2019:20:31:38 +0100] [Job 11] Unloading...
D [27/Jan/2019:20:31:38 +0100] cupsdStopSelect()
I [27/Jan/2019:20:31:38 +0100] Listening to [v1.::1]:631 (IPv6)
I [27/Jan/2019:20:31:38 +0100] Listening to 127.0.0.1:631 (IPv4)
I [27/Jan/2019:20:31:38 +0100] Listening to 172.16.2.4:631 (IPv4)
I [27/Jan/2019:20:31:38 +0100] Listening to /var/run/cups/cups.sock (Domain)
I [27/Jan/2019:20:31:38 +0100] Remote access is enabled.
D [27/Jan/2019:20:31:38 +0100] Added auto ServerAlias bananapi
I [27/Jan/2019:20:31:38 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
D [27/Jan/2019:20:31:38 +0100] Using keychain "/etc/cups/ssl" for server name "bananapi".
I [27/Jan/2019:20:31:38 +0100] Using default TempDir of /var/spool/cups/tmp...
I [27/Jan/2019:20:31:38 +0100] Configured for up to 100 clients.
I [27/Jan/2019:20:31:38 +0100] Allowing up to 100 client connections per host.
I [27/Jan/2019:20:31:38 +0100] Using policy "default" as the default.
I [27/Jan/2019:20:31:38 +0100] Full reload is required.
I [27/Jan/2019:20:31:38 +0100] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 49 types, 84 filters...
D [27/Jan/2019:20:31:38 +0100] Loading printer HP_Officejet_6600...
D [27/Jan/2019:20:31:38 +0100] load_ppd: Loading /var/cache/cups/HP_Officejet_6600.data...
D [27/Jan/2019:20:31:38 +0100] cupsdRegisterPrinter(p=0xb7f5e140(HP_Officejet_6600))
I [27/Jan/2019:20:31:38 +0100] Loading job cache file "/var/cache/cups/job.cache"...
D [27/Jan/2019:20:31:38 +0100] [Job 4] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] [Job 5] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] [Job 6] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] [Job 7] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] [Job 8] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] [Job 9] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] [Job 10] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] [Job 11] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] [Job 11] Loading attributes...
D [27/Jan/2019:20:31:38 +0100] [Job 12] Loading from cache...
D [27/Jan/2019:20:31:38 +0100] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
D [27/Jan/2019:20:31:38 +0100] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
I [27/Jan/2019:20:31:38 +0100] Full reload complete.
D [27/Jan/2019:20:31:38 +0100] cupsdCleanFiles(path="/var/spool/cups/tmp", pattern="(null)")
I [27/Jan/2019:20:31:38 +0100] Cleaning out old files in "/var/spool/cups/tmp".
D [27/Jan/2019:20:31:38 +0100] cupsdCleanFiles(path="/var/cache/cups", pattern="*.ipp")
I [27/Jan/2019:20:31:38 +0100] Cleaning out old files in "/var/cache/cups".
D [27/Jan/2019:20:31:38 +0100] Calling FindDeviceById(cups-HP_Officejet_6600)
D [27/Jan/2019:20:31:38 +0100] FindDeviceById failed: org.freedesktop.ColorManager.NotFound:device id \'cups-HP_Officejet_6600\' does not exist
D [27/Jan/2019:20:31:38 +0100] Using profile ID "HP_Officejet_6600-Gray..".
D [27/Jan/2019:20:31:38 +0100] Calling CreateProfile(HP_Officejet_6600-Gray..,temp)
D [27/Jan/2019:20:31:38 +0100] Created profile "/org/freedesktop/ColorManager/profiles/HP_Officejet_6600_Gray__".
D [27/Jan/2019:20:31:38 +0100] Using profile ID "HP_Officejet_6600-RGB..".
D [27/Jan/2019:20:31:38 +0100] Calling CreateProfile(HP_Officejet_6600-RGB..,temp)
D [27/Jan/2019:20:31:38 +0100] Created profile "/org/freedesktop/ColorManager/profiles/HP_Officejet_6600_RGB__".
I [27/Jan/2019:20:31:38 +0100] Registering ICC color profiles for "HP_Officejet_6600".
D [27/Jan/2019:20:31:38 +0100] Calling CreateDevice(cups-HP_Officejet_6600,temp)
D [27/Jan/2019:20:31:38 +0100] Created device "/org/freedesktop/ColorManager/devices/cups_HP_Officejet_6600".
D [27/Jan/2019:20:31:38 +0100] Calling /org/freedesktop/ColorManager/devices/cups_HP_Officejet_6600:AddProfile(/org/freedesktop/ColorManager/profiles/HP_Officejet_6600_Gray__) [soft]
D [27/Jan/2019:20:31:38 +0100] Calling /org/freedesktop/ColorManager/devices/cups_HP_Officejet_6600:AddProfile(/org/freedesktop/ColorManager/profiles/HP_Officejet_6600_RGB__) [soft]
I [27/Jan/2019:20:31:38 +0100] Listening to [v1.::1]:631 on fd 9...
I [27/Jan/2019:20:31:38 +0100] Listening to 127.0.0.1:631 on fd 10...
I [27/Jan/2019:20:31:38 +0100] Listening to 172.16.2.4:631 on fd 11...
I [27/Jan/2019:20:31:38 +0100] Listening to /var/run/cups/cups.sock on fd 12...
I [27/Jan/2019:20:31:38 +0100] Resuming new connection processing...
D [27/Jan/2019:20:31:38 +0100] Avahi server connection now available, registering printers for Bonjour broadcasting.
D [27/Jan/2019:20:31:38 +0100] Registering "remote printer - HP Officejet 6600 @ bananapi" with DNS-SD type "_printer._tcp".
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-type=0x80901E
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-state=3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Duplex=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Color=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" TLS=1.2
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" UUID=4c9297cd-8ea2-3443-4ea2-8d9e3b7bab79
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" URF=DM3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" pdl=application/octet-stream,application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" product=(HP Officejet 6600 E-all-in-one Printer - h711a)
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" priority=100
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" adminurl=https://bananapi.local:631/printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" ty=HP Officejet 6600 hpijs, 3.16.11
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" rp=HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" qtotal=1
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" txtvers=1
D [27/Jan/2019:20:31:38 +0100] Registering "remote printer - HP Officejet 6600 @ bananapi" with DNS-SD type "_ipps._tcp".
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-type=0x80901E
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-state=3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Duplex=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Color=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" TLS=1.2
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" UUID=4c9297cd-8ea2-3443-4ea2-8d9e3b7bab79
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" URF=DM3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" pdl=application/octet-stream,application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" product=(HP Officejet 6600 E-all-in-one Printer - h711a)
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" priority=0
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" adminurl=https://bananapi.local:631/printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" ty=HP Officejet 6600 hpijs, 3.16.11
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" rp=printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" qtotal=1
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" txtvers=1
D [27/Jan/2019:20:31:38 +0100] Registering "remote printer - HP Officejet 6600 @ bananapi" with DNS-SD type "_ipp._tcp".
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-type=0x80901E
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-state=3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Duplex=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Color=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" TLS=1.2
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" UUID=4c9297cd-8ea2-3443-4ea2-8d9e3b7bab79
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" URF=DM3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" pdl=application/octet-stream,application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" product=(HP Officejet 6600 E-all-in-one Printer - h711a)
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" priority=0
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" adminurl=https://bananapi.local:631/printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" ty=HP Officejet 6600 hpijs, 3.16.11
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" rp=printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" qtotal=1
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" txtvers=1
I [27/Jan/2019:20:31:38 +0100] Unknown LPDConfigFile scheme!
I [27/Jan/2019:20:31:38 +0100] Unknown SMBConfigFile scheme!
D [27/Jan/2019:20:31:38 +0100] Registering "remote printer - HP Officejet 6600 @ bananapi" with DNS-SD type "_printer._tcp".
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-type=0x80901E
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-state=3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Duplex=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Color=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" TLS=1.2
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" UUID=4c9297cd-8ea2-3443-4ea2-8d9e3b7bab79
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" URF=DM3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" pdl=application/octet-stream,application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" product=(HP Officejet 6600 E-all-in-one Printer - h711a)
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" priority=100
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" adminurl=https://bananapi.local:631/printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" ty=HP Officejet 6600 hpijs, 3.16.11
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" rp=HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" qtotal=1
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" txtvers=1
D [27/Jan/2019:20:31:38 +0100] Registering "remote printer - HP Officejet 6600 @ bananapi" with DNS-SD type "_ipps._tcp".
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-type=0x80901E
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-state=3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Duplex=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Color=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" TLS=1.2
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" UUID=4c9297cd-8ea2-3443-4ea2-8d9e3b7bab79
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" URF=DM3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" pdl=application/octet-stream,application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" product=(HP Officejet 6600 E-all-in-one Printer - h711a)
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" priority=0
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" adminurl=https://bananapi.local:631/printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" ty=HP Officejet 6600 hpijs, 3.16.11
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" rp=printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" qtotal=1
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" txtvers=1
D [27/Jan/2019:20:31:38 +0100] Registering "remote printer - HP Officejet 6600 @ bananapi" with DNS-SD type "_ipp._tcp".
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-type=0x80901E
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" printer-state=3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Duplex=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" Color=T
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" TLS=1.2
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" UUID=4c9297cd-8ea2-3443-4ea2-8d9e3b7bab79
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" URF=DM3
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" pdl=application/octet-stream,application/pdf,application/postscript,image/jpeg,image/png,image/pwg-raster,image/urf
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" product=(HP Officejet 6600 E-all-in-one Printer - h711a)
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" priority=0
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" adminurl=https://bananapi.local:631/printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" ty=HP Officejet 6600 hpijs, 3.16.11
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" rp=printers/HP_Officejet_6600
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" qtotal=1
D [27/Jan/2019:20:31:38 +0100] DNS_SD "remote printer - HP Officejet 6600 @ bananapi" txtvers=1
D [27/Jan/2019:20:31:38 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [27/Jan/2019:20:31:38 +0100] cupsdAddCert: Adding certificate for PID 0
D [27/Jan/2019:20:31:38 +0100] Notifier dbus started - PID = 2371
D [27/Jan/2019:20:31:38 +0100] cupsdMarkDirty(----S)
D [27/Jan/2019:20:31:38 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Not busy"
D [27/Jan/2019:20:31:38 +0100] [Notifier] state=3
D [27/Jan/2019:20:31:38 +0100] Report: clients=0
D [27/Jan/2019:20:31:38 +0100] Report: jobs=9
D [27/Jan/2019:20:31:38 +0100] Report: jobs-active=1
D [27/Jan/2019:20:31:38 +0100] Report: printers=1
D [27/Jan/2019:20:31:38 +0100] Report: stringpool-string-count=2918
D [27/Jan/2019:20:31:38 +0100] Report: stringpool-alloc-bytes=10216
D [27/Jan/2019:20:31:38 +0100] Report: stringpool-total-bytes=55608
D [27/Jan/2019:20:31:38 +0100] [Notifier] Connected to D-BUS
D [27/Jan/2019:20:31:38 +0100] [Notifier] ServerStarted
D [27/Jan/2019:20:31:39 +0100] [Client 1] Server address is "172.16.2.4".
D [27/Jan/2019:20:31:39 +0100] [Client 1] Accepted from 172.16.2.3:48508 (IPv4)
D [27/Jan/2019:20:31:39 +0100] [Client 1] Waiting for request.
I [27/Jan/2019:20:31:39 +0100] Expiring subscriptions...
D [27/Jan/2019:20:31:39 +0100] [Client 1] POST /printers/HP_Officejet_6600 HTTP/1.1
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 1] Read: status=200
D [27/Jan/2019:20:31:39 +0100] [Client 1] No authentication data provided.
D [27/Jan/2019:20:31:39 +0100] cupsdIsAuthorized: Need upgrade to TLS...
D [27/Jan/2019:20:31:39 +0100] [Client 1] cupsdSendHeader: code=426, type="text/html", auth_type=0
D [27/Jan/2019:20:31:39 +0100] [Client 1] Closing connection.
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 2] Server address is "172.16.2.4".
D [27/Jan/2019:20:31:39 +0100] [Client 2] Accepted from 172.16.2.3:48510 (IPv4)
D [27/Jan/2019:20:31:39 +0100] [Client 2] Waiting for request.
D [27/Jan/2019:20:31:39 +0100] [Client 2] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [27/Jan/2019:20:31:39 +0100] [Client 2] Closing connection.
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 3] Server address is "172.16.2.4".
D [27/Jan/2019:20:31:39 +0100] [Client 3] Accepted from 172.16.2.3:48512 (IPv4)
D [27/Jan/2019:20:31:39 +0100] [Client 3] Waiting for request.
D [27/Jan/2019:20:31:39 +0100] [Client 3] OPTIONS * HTTP/1.1
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 3] Read: status=200
D [27/Jan/2019:20:31:39 +0100] [Client 3] No authentication data provided.
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdSendHeader: code=101, type="(null)", auth_type=0
D [27/Jan/2019:20:31:39 +0100] [Client 3] Connection now encrypted.
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 3] POST /printers/HP_Officejet_6600 HTTP/1.1
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 3] Read: status=200
D [27/Jan/2019:20:31:39 +0100] [Client 3] No authentication data provided.
D [27/Jan/2019:20:31:39 +0100] [Client 3] 2.0 Get-Printer-Attributes 7068
D [27/Jan/2019:20:31:39 +0100] Get-Printer-Attributes ipp://localhost/printers/HP_Officejet_6600
D [27/Jan/2019:20:31:39 +0100] [Client 3] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/HP_Officejet_6600) from 172.16.2.3
D [27/Jan/2019:20:31:39 +0100] [Client 3] Content-Length: 233
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=233, response=0xb7fb8be8(IPP_STATE_DATA), pipe_pid=0, file=-1
D [27/Jan/2019:20:31:39 +0100] [Client 3] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [27/Jan/2019:20:31:39 +0100] [Client 3] bytes=0, http_state=0, data_remaining=233
D [27/Jan/2019:20:31:39 +0100] [Client 3] Flushing write buffer.
D [27/Jan/2019:20:31:39 +0100] [Client 3] New state is HTTP_STATE_WAITING
D [27/Jan/2019:20:31:39 +0100] [Client 3] Waiting for request.
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 3] GET /printers/HP_Officejet_6600.ppd HTTP/1.1
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 3] Read: status=200
D [27/Jan/2019:20:31:39 +0100] [Client 3] No authentication data provided.
D [27/Jan/2019:20:31:39 +0100] [Client 3] Processing GET /printers/HP_Officejet_6600.ppd
D [27/Jan/2019:20:31:39 +0100] [Client 3] filename="/etc/cups/ppd/HP_Officejet_6600.ppd", type=application/vnd.cups-ppd
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdSendHeader: code=200, type="application/vnd.cups-ppd", auth_type=0
D [27/Jan/2019:20:31:39 +0100] [Client 3] Sending file.
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] con->http=0xb7fbedb8
D [27/Jan/2019:20:31:39 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=22516, response=(nil)(), pipe_pid=0, file=22
D [27/Jan/2019:20:31:39 +0100] [Client 3] Flushing write buffer.
D [27/Jan/2019:20:31:39 +0100] [Client 3] New state is HTTP_STATE_WAITING
D [27/Jan/2019:20:31:39 +0100] [Client 3] Waiting for request.
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [27/Jan/2019:20:31:39 +0100] [Client 3] Closing connection.
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [27/Jan/2019:20:31:39 +0100] [Client 3] Waiting for socket close.
D [27/Jan/2019:20:31:39 +0100] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [27/Jan/2019:20:31:39 +0100] [Client 3] Closing connection.
D [27/Jan/2019:20:31:39 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [27/Jan/2019:20:31:40 +0100] Expiring subscriptions...