Cannot print after upgrading to Ubuntu 18.04

Asked by Kevin O'Shea on 2018-10-22

My printer HP LaserJet Professional m1217nfw MFP was printing fine over the network on Ubuntu 16.04. After upgrading to 18.04 I can no longer print.

I have tried over the network and now also by USB connection, but does not work. Attached are the logs from hp-logcapture

Question information

Language:
English Edit question
Status:
Solved
For:
HPLIP Edit question
Assignee:
No assignee Edit question
Solved by:
Kevin O'Shea
Solved:
2018-10-22
Last query:
2018-10-22
Last reply:
2018-10-22

hp-check:
hp-check[3103]: info: :
hp-check[3103]: info: :[01mHP Linux Imaging and Printing System (ver. 3.18.9)[0m
hp-check[3103]: info: :[01mDependency/Version Check Utility ver. 15.1[0m
hp-check[3103]: info: :
hp-check[3103]: info: :Copyright (c) 2001-15 HP Development Company, LP
hp-check[3103]: info: :This software comes with ABSOLUTELY NO WARRANTY.
hp-check[3103]: info: :This is free software, and you are welcome to distribute it
hp-check[3103]: info: :under certain conditions. See COPYING file for more details.
hp-check[3103]: info: :
hp-check[3103]: info: :[01mNote: hp-check can be run in three modes:[0m
hp-check[3103]: info: :1. Compile-time check mode (-c or --compile): Use this mode before compiling the
hp-check[3103]: info: :HPLIP supplied tarball (.tar.gz or .run) to determine if the proper dependencies
hp-check[3103]: info: :are installed to successfully compile HPLIP.
hp-check[3103]: info: :2. Run-time check mode (-r or --run): Use this mode to determine if a distro
hp-check[3103]: info: :supplied package (.deb, .rpm, etc) or an already built HPLIP supplied tarball
hp-check[3103]: info: :has the proper dependencies installed to successfully run.
hp-check[3103]: info: :3. Both compile- and run-time check mode (-b or --both) (Default): This mode
hp-check[3103]: info: :will check both of the above cases (both compile- and run-time dependencies).
hp-check[3103]: info: :
hp-check[3103]: info: :Check types:
hp-check[3103]: info: :a. EXTERNALDEP - External Dependencies
hp-check[3103]: info: :b. GENERALDEP - General Dependencies (required both at compile and run time)
hp-check[3103]: info: :c. COMPILEDEP - Compile time Dependencies
hp-check[3103]: info: :d. [All are run-time checks]
hp-check[3103]: info: :PYEXT SCANCONF QUEUES PERMISSION
hp-check[3103]: info: :
hp-check[3103]: info: :Status Types:
hp-check[3103]: info: : OK
hp-check[3103]: info: : MISSING - Missing Dependency or Permission or Plug-in
hp-check[3103]: info: : INCOMPAT - Incompatible dependency-version or Plugin-version
hp-check[3103]: info: :
hp-check[3103]: info: :
hp-check[3103]: info: :---------------
hp-check[3103]: info: :| SYSTEM INFO |
hp-check[3103]: info: :---------------
hp-check[3103]: info: :
hp-check[3103]: info: : Kernel: 4.15.0-36-generic #39-Ubuntu SMP Mon Sep 24 16:19:09 UTC 2018 GNU/Linux
 Host: quebec
 Proc: 4.15.0-36-generic #39-Ubuntu SMP Mon Sep 24 16:19:09 UTC 2018 GNU/Linux
 Distribution: 12 18.04
hp-check[3103]: info: : Bitness: 64 bit

hp-check[3103]: info: :
hp-check[3103]: info: :-----------------------
hp-check[3103]: info: :| HPLIP CONFIGURATION |
hp-check[3103]: info: :-----------------------
hp-check[3103]: info: :
hp-check[3103]: info: :HPLIP-Version: HPLIP 3.18.9
hp-check[3103]: info: :HPLIP-Home: /usr/share/hplip
hp-check[3103]: info: :HPLIP-Installation: Auto installation is supported for ubuntu distro 18.04 version
hp-check[3103]: info: :
hp-check[3103]: info: :[01mCurrent contents of '/etc/hp/hplip.conf' file:[0m
hp-check[3103]: info: :# hplip.conf. Generated from hplip.conf.in by configure.

[hplip]
version=3.18.9

[dirs]
home=/usr/share/hplip
run=/var/run
ppd=/usr/share/ppd/HP
ppdbase=/usr/share/ppd
doc=/usr/share/doc/hplip-3.18.9
html=/usr/share/doc/hplip-3.18.9
icon=/usr/share/applications
cupsbackend=/usr/lib/cups/backend
cupsfilter=/usr/lib/cups/filter
drv=/usr/share/cups/drv/hp
bin=/usr/bin
apparmor=/etc/apparmor.d
# Following values are determined at configure time and cannot be changed.
[configure]
network-build=yes
libusb01-build=no
pp-build=no
gui-build=yes
scanner-build=yes
fax-build=yes
dbus-build=yes
cups11-build=no
doc-build=yes
shadow-build=no
hpijs-install=no
foomatic-drv-install=no
foomatic-ppd-install=no
foomatic-rip-hplip-install=no
hpcups-install=yes
cups-drv-install=yes
cups-ppd-install=no
internal-tag=3.18.9
restricted-build=no
ui-toolkit=qt4
qt3=no
qt4=yes
qt5=no
policy-kit=no
lite-build=no
udev_sysfs_rules=no
hpcups-only-build=no
hpijs-only-build=no
apparmor_build=yes
class-driver=no

hp-check[3103]: info: :
hp-check[3103]: info: :[01mCurrent contents of '/var/lib/hp/hplip.state' file:[0m
hp-check[3103]: info: :[plugin]
installed = 1
eula = 1
version = 3.18.9

hp-check[3103]: info: :
hp-check[3103]: info: :[01mCurrent contents of '~/.hplip/hplip.conf' file:[0m
hp-check[3103]: info: :[upgrade]
notify_upgrade=true
last_upgraded_time=1540168154
pending_upgrade_time=0
latest_available_version=3.17.10

[settings]
systray_visible=0
systray_messages=0

[last_used]
device_uri="hp:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a"
printer_name=HP_LaserJet_Professional_M1217nfw_MFP
working_dir=.

[commands]
scan=/usr/bin/xsane -V %SANE_URI%

[refresh]
rate=30
enable=false
type=1

[polling]
enable=false
interval=5
device_list=

[fax]
voice_phone=
email_address=

[installation]
date_time=2018-10-21 20:40:40
version=3.18.9

hp-check[3103]: info: : <Package-name> <Package-Desc> <Required/Optional> <Min-Version> <Installed-Version> <Status> <Comment>
hp-check[3103]: info: :
hp-check[3103]: info: :--------------
hp-check[3103]: info: :| COMPILEDEP |
hp-check[3103]: info: :--------------
hp-check[3103]: info: :
hp-check[3103]: info: : gcc gcc - GNU Project C and C++ Compiler REQUIRED - 7.3.0 OK -
hp-check[3103]: info: : make make - GNU make utility to maintain groups of programs REQUIRED 3.0 4.1 OK -
hp-check[3103]: info: : libtool libtool - Library building support services REQUIRED - 2.4.6 OK -
hp-check[3103]: info: :
hp-check[3103]: info: :------------------------
hp-check[3103]: info: :| General Dependencies |
hp-check[3103]: info: :------------------------
hp-check[3103]: info: :
hp-check[3103]: info: : libcrypto libcrypto - OpenSSL cryptographic library REQUIRED - 1.1.0 OK -
hp-check[3103]: info: : python-xml Python XML libraries REQUIRED - 2.2.5 OK -
hp-check[3103]: info: : libnetsnmp-devel libnetsnmp-devel - SNMP networking library development files REQUIRED 5.0.9 5.7.3 OK -
hp-check[3103]: info: : sane-devel SANE - Scanning library development files REQUIRED - - OK -
hp-check[3103]: info: : pil PIL - Python Imaging Library (required for commandline scanning with hp-scan) OPTIONAL - 1.1.7 OK -
hp-check[3103]: info: : pyqt4-dbus PyQt 4 DBus - DBus Support for PyQt4 REQUIRED 4.0 4.12.1 OK -
hp-check[3103]: info: : libpthread libpthread - POSIX threads library REQUIRED - 2.27 OK -
hp-check[3103]: info: : python-devel Python devel - Python development files REQUIRED 2.2 2.7.15 OK -
hp-check[3103]: info: : cups-devel CUPS devel- Common Unix Printing System development files REQUIRED - 2.2.7 OK -
hp-check[3103]: info: : python-dbus Python DBus - Python bindings for DBus REQUIRED 0.80.0 1.2.6 OK -
hp-check[3103]: info: : cups-ddk CUPS DDK - CUPS driver development kit OPTIONAL - - OK -
hp-check[3103]: info: : reportlab Reportlab - PDF library for Python OPTIONAL 2.0 3.4.0 OK -
hp-check[3103]: info: : pyqt4 PyQt 4- Qt interface for Python (for Qt version 4.x) REQUIRED 4.0 4.12.1 OK -
hp-check[3103]: info: : libusb libusb - USB library REQUIRED - 1.0 OK -
hp-check[3103]: info: : cups-image CUPS image - CUPS image development files REQUIRED - 2.2.7 OK -
hp-check[3103]: info: : python2X Python 2.2 or greater - Python programming language REQUIRED 2.2 2.7.15 OK -
hp-check[3103]: info: : python-notify Python libnotify - Python bindings for the libnotify Desktop notifications OPTIONAL - - OK -
hp-check[3103]: info: : libjpeg libjpeg - JPEG library REQUIRED - - OK -
hp-check[3103]: info: : sane SANE - Scanning library REQUIRED - - OK -
hp-check[3103]: info: :
hp-check[3103]: info: :----------------------
hp-check[3103]: info: :| Scan Configuration |
hp-check[3103]: info: :----------------------
hp-check[3103]: info: :
hp-check[3103]: info: : scanext Scan-SANE-Extension REQUIRED - 3.18.9 OK -
hp-check[3103]: info: : hpaio HPLIP-SANE-Backend REQUIRED - 3.18.9 OK 'hpaio found in /etc/sane.d/dll.conf'
hp-check[3103]: info: :
hp-check[3103]: info: :-------------------------
hp-check[3103]: info: :| External Dependencies |
hp-check[3103]: info: :-------------------------
hp-check[3103]: info: :
hp-check[3103]: info: : gs GhostScript - PostScript and PDF language interpreter and previewer REQUIRED 7.05 9.25 OK -
hp-check[3103]: info: : scanimage scanimage - Shell scanning program OPTIONAL 1.0 1.0.27 OK -
hp-check[3103]: info: : cups CUPS - Common Unix Printing System REQUIRED 1.1 2.2.7 OK 'CUPS Scheduler is running'
hp-check[3103]: info: : network network -wget OPTIONAL - 1.19.4 OK -
hp-check[3103]: info: : policykit PolicyKit - Administrative policy framework OPTIONAL - 0.105 OK -
hp-check[3103]: info: : xsane xsane - Graphical scanner frontend for SANE OPTIONAL 0.9 0.999 OK -
hp-check[3103]: info: : dbus DBus - Message bus system REQUIRED - 1.12.2 OK -
hp-check[3103]: info: : avahi-utils avahi-utils OPTIONAL - 0.7 OK -
hp-check[3103]: info: :
hp-check[3103]: info: :---------------------
hp-check[3103]: info: :| Python Extentions |
hp-check[3103]: info: :---------------------
hp-check[3103]: info: :
hp-check[3103]: info: : hpmudext IO-Extension REQUIRED - 3.18.9 OK -
hp-check[3103]: info: : cupsext CUPS-Extension REQUIRED - 3.18.9 OK -
hp-check[3103]: info: :
hp-check[3103]: info: :------------------------------
hp-check[3103]: info: :| DISCOVERED SCANNER DEVICES |
hp-check[3103]: info: :------------------------------
hp-check[3103]: info: :
hp-check[3103]: info: :device `hpaio:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a' is a Hewlett-Packard HP_LaserJet_Professional_M1217nfw_MFP all-in-one

hp-check[3103]: info: :
hp-check[3103]: info: :--------------------------
hp-check[3103]: info: :| DISCOVERED USB DEVICES |
hp-check[3103]: info: :--------------------------
hp-check[3103]: info: :
hp-check[3103]: info: : Device URI Model
hp-check[3103]: info: : -------------------------------- --------------------------------
hp-check[3103]: info: : hp:/usb/HP_LaserJet_Professional HP LaserJet Professional
  _M1217nfw_MFP?serial=000000000T2 M1217nfw MFP
  40C69PR1a
hp-check[3103]: info: :
hp-check[3103]: info: :---------------------------------
hp-check[3103]: info: :| INSTALLED CUPS PRINTER QUEUES |
hp-check[3103]: info: :---------------------------------
hp-check[3103]: info: :
hp-check[3103]: info: :
hp-check[3103]: info: :[01mHP-LaserJet-Professional-M1217nfw-MFP[0m
hp-check[3103]: info: :[01m-------------------------------------[0m
hp-check[3103]: info: :Type: Printer
hp-check[3103]: info: :Device URI: hp:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a
hp-check[3103]: info: :PPD: /etc/cups/ppd/HP-LaserJet-Professional-M1217nfw-MFP.ppd
hp-check[3103]: info: :PPD Description: HP LaserJet Professional m1217nfw MFP, hpcups 3.18.9, requires proprietary plugin
hp-check[3103]: info: :Printer status: printer HP-LaserJet-Professional-M1217nfw-MFP is idle. enabled since Sun 21 Oct 2018 08:52:44 PM EDT
 Filter failed
hp-check[3103]: info: :Required plug-in status: Installed
hp-check[3103]: info: :Communication status: Good
hp-check[3103]: info: :
hp-check[3103]: info: :[01mHP-LaserJet-Professional-M1217nfw-MFP-Fax-3[0m
hp-check[3103]: info: :[01m-------------------------------------------[0m
hp-check[3103]: info: :Type: Fax
hp-check[3103]: info: :Device URI: hpfax:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a
hp-check[3103]: info: :PPD: /etc/cups/ppd/HP-LaserJet-Professional-M1217nfw-MFP-Fax-3.ppd
hp-check[3103]: info: :PPD Description: HP Fax3 hpcups
hp-check[3103]: info: :Printer status: printer HP-LaserJet-Professional-M1217nfw-MFP-Fax-3 is idle. enabled since Sun 21 Oct 2018 08:31:56 PM EDT
hp-check[3103]: info: :Required plug-in status: Installed
hp-check[3103]: info: :Communication status: Good
hp-check[3103]: info: :
hp-check[3103]: info: :[01mHP_LaserJet_Professional_M1217nfw_MFP[0m
hp-check[3103]: info: :[01m-------------------------------------[0m
hp-check[3103]: info: :Type: Printer
hp-check[3103]: info: :Device URI: hp:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a
hp-check[3103]: info: :PPD: /etc/cups/ppd/HP_LaserJet_Professional_M1217nfw_MFP.ppd
hp-check[3103]: info: :PPD Description: HP LaserJet Professional m1217nfw MFP, hpcups 3.17.10, requires proprietary plugin
hp-check[3103]: info: :Printer status: printer HP_LaserJet_Professional_M1217nfw_MFP is idle. enabled since Sun 21 Oct 2018 08:31:36 PM EDT
hp-check[3103]: info: :Required plug-in status: Installed
hp-check[3103]: info: :Communication status: Good
hp-check[3103]: info: :
hp-check[3103]: info: :[01mHP_LaserJet_Professional_M1217nfw_MFP_fax[0m
hp-check[3103]: info: :[01m-----------------------------------------[0m
hp-check[3103]: info: :Type: Fax
hp-check[3103]: info: :Device URI: hpfax:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a
hp-check[3103]: info: :PPD: /etc/cups/ppd/HP_LaserJet_Professional_M1217nfw_MFP_fax.ppd
hp-check[3103]: info: :PPD Description: HP Fax3 hpcups
hp-check[3103]: info: :Printer status: printer HP_LaserJet_Professional_M1217nfw_MFP_fax is idle. enabled since Sun 21 Oct 2018 08:36:54 PM EDT
hp-check[3103]: info: :Required plug-in status: Installed
hp-check[3103]: info: :Communication status: Good
hp-check[3103]: info: :
hp-check[3103]: info: :
hp-check[3103]: info: :--------------
hp-check[3103]: info: :| PERMISSION |
hp-check[3103]: info: :--------------
hp-check[3103]: info: :
hp-check[3103]: info: :USB HP-LaserJet-Professional-M1217nfw-MFP Required - - OK Node:'/dev/bus/usb/001/003' Perm:' root lp rw- rw- rw- rw- r--'
hp-check[3103]: info: :[32;01mNo errors or warnings.[0m
hp-check[3103]: info: :
hp-check[3103]: info: :Done.

syslog
Oct 21 20:52:07 quebec colord[919]: message repeated 4 times: [ failed to get session [pid 2937]: No data available]
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Activating service name='org.gnome.ControlCenter.SearchProvider' requested by ':1.25' (uid=1000 pid=1640 comm="/usr/bin/gnome-shell " label="unconfined")
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Activating service name='org.gnome.Nautilus' requested by ':1.25' (uid=1000 pid=1640 comm="/usr/bin/gnome-shell " label="unconfined")
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Activating service name='org.gnome.Calculator.SearchProvider' requested by ':1.25' (uid=1000 pid=1640 comm="/usr/bin/gnome-shell " label="unconfined")
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Activating service name='org.gnome.Calendar' requested by ':1.25' (uid=1000 pid=1640 comm="/usr/bin/gnome-shell " label="unconfined")
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Activating service name='org.gnome.seahorse.Application' requested by ':1.25' (uid=1000 pid=1640 comm="/usr/bin/gnome-shell " label="unconfined")
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Successfully activated service 'org.gnome.Calculator.SearchProvider'
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Successfully activated service 'org.gnome.ControlCenter.SearchProvider'
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Successfully activated service 'org.gnome.Nautilus'
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Successfully activated service 'org.gnome.seahorse.Application'
Oct 21 20:52:33 quebec dbus-daemon[1479]: [session uid=1000 pid=1479] Successfully activated service 'org.gnome.Calendar'
Oct 21 20:52:36 quebec PackageKit: resolve transaction /831_abebdaaa from uid 1000 finished with success after 667ms
Oct 21 20:52:44 quebec hpcups[3088]: prnt/hpcups/HPCupsFilter.cpp 539: argv[0] = HP-LaserJet-Professional-M1217nfw-MFP
Oct 21 20:52:44 quebec hpcups[3088]: prnt/hpcups/HPCupsFilter.cpp 539: argv[1] = 474
Oct 21 20:52:44 quebec hpcups[3088]: prnt/hpcups/HPCupsFilter.cpp 539: argv[2] = ubu
Oct 21 20:52:44 quebec hpcups[3088]: prnt/hpcups/HPCupsFilter.cpp 539: argv[3] = Untitled Document 1
Oct 21 20:52:44 quebec hpcups[3088]: prnt/hpcups/HPCupsFilter.cpp 539: argv[4] = 1
Oct 21 20:52:44 quebec hpcups[3088]: prnt/hpcups/HPCupsFilter.cpp 539: argv[5] = InputSlot=Auto number-up=1 PageSize=Letter MediaType=Plain noCollate OutputMode=Normal job-uuid=urn:uuid:0150f1c2-7171-3dfd-6c8f-57d64fd77aab job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1540169564 time-at-processing=1540169564
Oct 21 20:52:44 quebec hpcups[3088]: prnt/hpcups/HPCupsFilter.cpp 569: cupsRasterOpen failed, fd = 0
Oct 21 20:52:44 quebec hp[3089]: prnt/backend/hp.c 919: ERROR: null print job total=0
Oct 21 20:52:56 quebec zeitgeist-datah[2088]: zeitgeist-datahub.vala:210: Error during inserting events: GDBus.Error:org.gnome.zeitgeist.EngineError.InvalidArgument: Incomplete event: interpretation, manifestation and actor are required
Oct 21 20:53:04 quebec scanimage: io/hpmud/pp.c 627: unable to read device-id ret=-1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 427: Found interface conf=0, iface=0, altset=0, index=1
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 389: Active kernel driver on interface=0 ret=0
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 535: claimed 7/1/2 interface
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=182
Oct 21 20:53:14 quebec python: io/hpmud/musb.c 561: released 7/1/2 interface
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "bind"
Oct 21 20:53:14 quebec upowerd[1102]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:02.1/usb1/1-6/1-6:1.0
Oct 21 20:53:14 quebec baloo_file.desktop[1854]: UdevQt: unhandled device action "unbind"
Oct 21 20:53:15 quebec python: io/hpmud/musb.c 2189: [3103] hpmud_make_usb_uri() bus=001 dev=003
Oct 21 20:53:15 quebec python: io/hpmud/musb.c 2287: hpmud_make_usb_uri() uri=hp:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a bytes_read=73

cups_error_log
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [21/Oct/2018:20:52:38 -0400] [Client 10] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:38 -0400] [Client 10] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:38 -0400] [Client 10] Waiting for request.
I [21/Oct/2018:20:52:38 -0400] Saving printers.conf...
I [21/Oct/2018:20:52:38 -0400] Generating printcap /run/cups/printcap...
I [21/Oct/2018:20:52:38 -0400] Saving subscriptions.conf...
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients and dirty files"
I [21/Oct/2018:20:52:38 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:38 -0400] [Client 11] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:38 -0400] [Client 11] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:38 -0400] [Client 11] Waiting for request.
D [21/Oct/2018:20:52:38 -0400] [Client 10] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:38 -0400] [Client 10] Closing connection.
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:38 -0400] [Client 11] POST / HTTP/1.1
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=200, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] No authentication data provided.
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 11] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:38 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:38 -0400] [Client 11] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:38 -0400] [Client 11] Content-Length: 4661
D [21/Oct/2018:20:52:38 -0400] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:38 -0400] [Client 11] con->http=0x559ac8856520
D [21/Oct/2018:20:52:38 -0400] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8848ef0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:38 -0400] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:38 -0400] [Client 11] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:38 -0400] [Client 11] Flushing write buffer.
D [21/Oct/2018:20:52:38 -0400] [Client 11] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:38 -0400] [Client 11] Waiting for request.
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:38 -0400] [Client 12] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:38 -0400] [Client 12] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:38 -0400] [Client 12] Waiting for request.
D [21/Oct/2018:20:52:38 -0400] [Client 11] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:38 -0400] [Client 11] Closing connection.
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:38 -0400] [Client 12] GET /printers/HP-LaserJet-Professional-M1217nfw-MFP.ppd HTTP/1.1
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:38 -0400] [Client 12] Read: status=200, state=3
D [21/Oct/2018:20:52:38 -0400] [Client 12] No authentication data provided.
D [21/Oct/2018:20:52:38 -0400] [Client 12] Processing GET /printers/HP-LaserJet-Professional-M1217nfw-MFP.ppd
D [21/Oct/2018:20:52:38 -0400] [Client 12] filename="/etc/cups/ppd/HP-LaserJet-Professional-M1217nfw-MFP.ppd", type=application/vnd.cups-ppd
D [21/Oct/2018:20:52:38 -0400] [Client 12] cupsdSendHeader: code=200, type="application/vnd.cups-ppd", auth_type=0
D [21/Oct/2018:20:52:38 -0400] [Client 12] Sending file.
D [21/Oct/2018:20:52:38 -0400] [Client 12] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:38 -0400] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11124, response=(nil)(), pipe_pid=0, file=24
D [21/Oct/2018:20:52:38 -0400] [Client 12] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:38 -0400] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11124, response=(nil)(), pipe_pid=0, file=24
D [21/Oct/2018:20:52:38 -0400] [Client 12] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:38 -0400] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11124, response=(nil)(), pipe_pid=0, file=24
D [21/Oct/2018:20:52:38 -0400] [Client 12] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:38 -0400] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11124, response=(nil)(), pipe_pid=0, file=24
D [21/Oct/2018:20:52:38 -0400] [Client 12] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:38 -0400] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11124, response=(nil)(), pipe_pid=0, file=24
D [21/Oct/2018:20:52:38 -0400] [Client 12] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:38 -0400] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_GET_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11124, response=(nil)(), pipe_pid=0, file=24
D [21/Oct/2018:20:52:38 -0400] [Client 12] Flushing write buffer.
D [21/Oct/2018:20:52:38 -0400] [Client 12] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:38 -0400] [Client 12] Waiting for request.
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:38 -0400] [Client 12] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:38 -0400] [Client 12] Closing connection.
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:38 -0400] [Client 13] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:38 -0400] [Client 13] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:38 -0400] [Client 13] Waiting for request.
D [21/Oct/2018:20:52:38 -0400] [Client 13] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:38 -0400] [Client 13] Closing connection.
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:38 -0400] [Client 14] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:38 -0400] [Client 14] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:38 -0400] [Client 14] Waiting for request.
D [21/Oct/2018:20:52:38 -0400] [Client 14] POST / HTTP/1.1
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=200, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] No authentication data provided.
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] Read: status=100, state=6
D [21/Oct/2018:20:52:38 -0400] [Client 14] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:38 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:38 -0400] [Client 14] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:38 -0400] [Client 14] Content-Length: 4661
D [21/Oct/2018:20:52:38 -0400] [Client 14] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:38 -0400] [Client 14] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:38 -0400] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac88425c0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:38 -0400] [Client 14] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:38 -0400] [Client 14] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:38 -0400] [Client 14] Flushing write buffer.
D [21/Oct/2018:20:52:38 -0400] [Client 14] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:38 -0400] [Client 14] Waiting for request.
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:38 -0400] [Client 14] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:38 -0400] [Client 14] Closing connection.
D [21/Oct/2018:20:52:38 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 15] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 15] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 15] Waiting for request.
I [21/Oct/2018:20:52:39 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 16] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 16] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 16] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] [Client 15] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 15] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 16] POST / HTTP/1.1
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=200, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] No authentication data provided.
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] Read: status=100, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 16] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:39 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:39 -0400] [Client 16] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:39 -0400] [Client 16] Content-Length: 4661
D [21/Oct/2018:20:52:39 -0400] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:39 -0400] [Client 16] con->http=0x559ac8856520
D [21/Oct/2018:20:52:39 -0400] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883daf0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:39 -0400] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:39 -0400] [Client 16] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:39 -0400] [Client 16] Flushing write buffer.
D [21/Oct/2018:20:52:39 -0400] [Client 16] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:39 -0400] [Client 16] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 16] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 16] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 17] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 17] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 17] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 18] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 18] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 18] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] [Client 17] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 17] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 18] POST / HTTP/1.1
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 18] Read: status=200, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 18] No authentication data provided.
D [21/Oct/2018:20:52:39 -0400] [Client 18] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:39 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:39 -0400] [Client 18] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:39 -0400] [Client 18] Content-Length: 4661
D [21/Oct/2018:20:52:39 -0400] [Client 18] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:39 -0400] [Client 18] con->http=0x559ac8856520
D [21/Oct/2018:20:52:39 -0400] [Client 18] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8822900(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:39 -0400] [Client 18] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:39 -0400] [Client 18] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:39 -0400] [Client 18] Flushing write buffer.
D [21/Oct/2018:20:52:39 -0400] [Client 18] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:39 -0400] [Client 18] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 18] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 18] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 19] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 19] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 19] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 20] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 20] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 20] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] [Client 19] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 19] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 20] POST / HTTP/1.1
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 20] Read: status=200, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 20] No authentication data provided.
D [21/Oct/2018:20:52:39 -0400] [Client 20] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:39 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:39 -0400] [Client 20] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:39 -0400] [Client 20] Content-Length: 4661
D [21/Oct/2018:20:52:39 -0400] [Client 20] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:39 -0400] [Client 20] con->http=0x559ac8856520
D [21/Oct/2018:20:52:39 -0400] [Client 20] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8843220(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:39 -0400] [Client 20] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:39 -0400] [Client 20] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:39 -0400] [Client 20] Flushing write buffer.
D [21/Oct/2018:20:52:39 -0400] [Client 20] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:39 -0400] [Client 20] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 20] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 20] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 21] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 21] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 21] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] [Client 21] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 21] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 22] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 22] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 22] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] [Client 22] POST / HTTP/1.1
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 22] Read: status=200, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 22] No authentication data provided.
D [21/Oct/2018:20:52:39 -0400] [Client 22] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:39 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:39 -0400] [Client 22] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:39 -0400] [Client 22] Content-Length: 4661
D [21/Oct/2018:20:52:39 -0400] [Client 22] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:39 -0400] [Client 22] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:39 -0400] [Client 22] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883daf0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:39 -0400] [Client 22] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:39 -0400] [Client 22] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:39 -0400] [Client 22] Flushing write buffer.
D [21/Oct/2018:20:52:39 -0400] [Client 22] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:39 -0400] [Client 22] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 22] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 22] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 23] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 23] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 23] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 24] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:39 -0400] [Client 24] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:39 -0400] [Client 24] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] [Client 23] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 23] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 24] POST / HTTP/1.1
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:39 -0400] [Client 24] Read: status=200, state=6
D [21/Oct/2018:20:52:39 -0400] [Client 24] No authentication data provided.
D [21/Oct/2018:20:52:39 -0400] [Client 24] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:39 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:39 -0400] [Client 24] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:39 -0400] [Client 24] Content-Length: 4661
D [21/Oct/2018:20:52:39 -0400] [Client 24] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:39 -0400] [Client 24] con->http=0x559ac8856520
D [21/Oct/2018:20:52:39 -0400] [Client 24] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:39 -0400] [Client 24] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:39 -0400] [Client 24] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:39 -0400] [Client 24] Flushing write buffer.
D [21/Oct/2018:20:52:39 -0400] [Client 24] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:39 -0400] [Client 24] Waiting for request.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:39 -0400] [Client 24] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:39 -0400] [Client 24] Closing connection.
D [21/Oct/2018:20:52:39 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 25] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 25] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 25] Waiting for request.
I [21/Oct/2018:20:52:40 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 26] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 26] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 26] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] [Client 25] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 25] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 26] POST / HTTP/1.1
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 26] Read: status=200, state=6
D [21/Oct/2018:20:52:40 -0400] [Client 26] No authentication data provided.
D [21/Oct/2018:20:52:40 -0400] [Client 26] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:40 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:40 -0400] [Client 26] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:40 -0400] [Client 26] Content-Length: 4661
D [21/Oct/2018:20:52:40 -0400] [Client 26] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:40 -0400] [Client 26] con->http=0x559ac8856520
D [21/Oct/2018:20:52:40 -0400] [Client 26] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8822900(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:40 -0400] [Client 26] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:40 -0400] [Client 26] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:40 -0400] [Client 26] Flushing write buffer.
D [21/Oct/2018:20:52:40 -0400] [Client 26] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:40 -0400] [Client 26] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 26] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 26] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 27] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 27] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 27] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 28] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 28] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 28] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] [Client 27] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 27] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 28] POST / HTTP/1.1
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 28] Read: status=200, state=6
D [21/Oct/2018:20:52:40 -0400] [Client 28] No authentication data provided.
D [21/Oct/2018:20:52:40 -0400] [Client 28] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:40 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:40 -0400] [Client 28] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:40 -0400] [Client 28] Content-Length: 4661
D [21/Oct/2018:20:52:40 -0400] [Client 28] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:40 -0400] [Client 28] con->http=0x559ac8856520
D [21/Oct/2018:20:52:40 -0400] [Client 28] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883bab0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:40 -0400] [Client 28] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:40 -0400] [Client 28] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:40 -0400] [Client 28] Flushing write buffer.
D [21/Oct/2018:20:52:40 -0400] [Client 28] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:40 -0400] [Client 28] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 28] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 28] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 29] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 29] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 29] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 30] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 30] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 30] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] [Client 29] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 29] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 30] POST / HTTP/1.1
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 30] Read: status=200, state=6
D [21/Oct/2018:20:52:40 -0400] [Client 30] No authentication data provided.
D [21/Oct/2018:20:52:40 -0400] [Client 30] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:40 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:40 -0400] [Client 30] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:40 -0400] [Client 30] Content-Length: 4661
D [21/Oct/2018:20:52:40 -0400] [Client 30] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:40 -0400] [Client 30] con->http=0x559ac8856520
D [21/Oct/2018:20:52:40 -0400] [Client 30] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:40 -0400] [Client 30] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:40 -0400] [Client 30] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:40 -0400] [Client 30] Flushing write buffer.
D [21/Oct/2018:20:52:40 -0400] [Client 30] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:40 -0400] [Client 30] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 30] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 30] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 31] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 31] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 31] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 32] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 32] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 32] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] [Client 31] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 31] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 32] POST / HTTP/1.1
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 32] Read: status=200, state=6
D [21/Oct/2018:20:52:40 -0400] [Client 32] No authentication data provided.
D [21/Oct/2018:20:52:40 -0400] [Client 32] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:40 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:40 -0400] [Client 32] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:40 -0400] [Client 32] Content-Length: 4661
D [21/Oct/2018:20:52:40 -0400] [Client 32] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:40 -0400] [Client 32] con->http=0x559ac8856520
D [21/Oct/2018:20:52:40 -0400] [Client 32] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8822900(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:40 -0400] [Client 32] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:40 -0400] [Client 32] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:40 -0400] [Client 32] Flushing write buffer.
D [21/Oct/2018:20:52:40 -0400] [Client 32] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:40 -0400] [Client 32] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 32] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 32] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 33] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 33] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 33] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 34] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:40 -0400] [Client 34] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:40 -0400] [Client 34] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] [Client 33] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 33] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 34] POST / HTTP/1.1
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:40 -0400] [Client 34] Read: status=200, state=6
D [21/Oct/2018:20:52:40 -0400] [Client 34] No authentication data provided.
D [21/Oct/2018:20:52:40 -0400] [Client 34] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:40 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:40 -0400] [Client 34] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:40 -0400] [Client 34] Content-Length: 4661
D [21/Oct/2018:20:52:40 -0400] [Client 34] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:40 -0400] [Client 34] con->http=0x559ac8856520
D [21/Oct/2018:20:52:40 -0400] [Client 34] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883bab0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:40 -0400] [Client 34] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:40 -0400] [Client 34] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:40 -0400] [Client 34] Flushing write buffer.
D [21/Oct/2018:20:52:40 -0400] [Client 34] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:40 -0400] [Client 34] Waiting for request.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:40 -0400] [Client 34] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:40 -0400] [Client 34] Closing connection.
D [21/Oct/2018:20:52:40 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 35] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 35] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 35] Waiting for request.
I [21/Oct/2018:20:52:41 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 36] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 36] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 36] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] [Client 35] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 35] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 36] POST / HTTP/1.1
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 36] Read: status=200, state=6
D [21/Oct/2018:20:52:41 -0400] [Client 36] No authentication data provided.
D [21/Oct/2018:20:52:41 -0400] [Client 36] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:41 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:41 -0400] [Client 36] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:41 -0400] [Client 36] Content-Length: 4661
D [21/Oct/2018:20:52:41 -0400] [Client 36] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:41 -0400] [Client 36] con->http=0x559ac8856520
D [21/Oct/2018:20:52:41 -0400] [Client 36] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:41 -0400] [Client 36] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:41 -0400] [Client 36] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:41 -0400] [Client 36] Flushing write buffer.
D [21/Oct/2018:20:52:41 -0400] [Client 36] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:41 -0400] [Client 36] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 36] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 36] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 37] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 37] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 37] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 38] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 38] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 38] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] [Client 37] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 37] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 38] POST / HTTP/1.1
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 38] Read: status=200, state=6
D [21/Oct/2018:20:52:41 -0400] [Client 38] No authentication data provided.
D [21/Oct/2018:20:52:41 -0400] [Client 38] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:41 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:41 -0400] [Client 38] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:41 -0400] [Client 38] Content-Length: 4661
D [21/Oct/2018:20:52:41 -0400] [Client 38] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:41 -0400] [Client 38] con->http=0x559ac8856520
D [21/Oct/2018:20:52:41 -0400] [Client 38] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8822900(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:41 -0400] [Client 38] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:41 -0400] [Client 38] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:41 -0400] [Client 38] Flushing write buffer.
D [21/Oct/2018:20:52:41 -0400] [Client 38] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:41 -0400] [Client 38] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 38] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 38] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 39] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 39] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 39] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 40] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 40] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 40] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] [Client 39] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 39] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 40] POST / HTTP/1.1
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 40] Read: status=200, state=6
D [21/Oct/2018:20:52:41 -0400] [Client 40] No authentication data provided.
D [21/Oct/2018:20:52:41 -0400] [Client 40] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:41 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:41 -0400] [Client 40] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:41 -0400] [Client 40] Content-Length: 4661
D [21/Oct/2018:20:52:41 -0400] [Client 40] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:41 -0400] [Client 40] con->http=0x559ac8856520
D [21/Oct/2018:20:52:41 -0400] [Client 40] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883bab0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:41 -0400] [Client 40] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:41 -0400] [Client 40] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:41 -0400] [Client 40] Flushing write buffer.
D [21/Oct/2018:20:52:41 -0400] [Client 40] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:41 -0400] [Client 40] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 40] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 40] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 41] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 41] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 41] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 42] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 42] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 42] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] [Client 41] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 41] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 42] POST / HTTP/1.1
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 42] Read: status=200, state=6
D [21/Oct/2018:20:52:41 -0400] [Client 42] No authentication data provided.
D [21/Oct/2018:20:52:41 -0400] [Client 42] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:41 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:41 -0400] [Client 42] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:41 -0400] [Client 42] Content-Length: 4661
D [21/Oct/2018:20:52:41 -0400] [Client 42] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:41 -0400] [Client 42] con->http=0x559ac8856520
D [21/Oct/2018:20:52:41 -0400] [Client 42] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:41 -0400] [Client 42] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:41 -0400] [Client 42] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:41 -0400] [Client 42] Flushing write buffer.
D [21/Oct/2018:20:52:41 -0400] [Client 42] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:41 -0400] [Client 42] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 42] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 42] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 43] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 43] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 43] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 44] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:41 -0400] [Client 44] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:41 -0400] [Client 44] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] [Client 43] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 43] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 44] POST / HTTP/1.1
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:41 -0400] [Client 44] Read: status=200, state=6
D [21/Oct/2018:20:52:41 -0400] [Client 44] No authentication data provided.
D [21/Oct/2018:20:52:41 -0400] [Client 44] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:41 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:41 -0400] [Client 44] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:41 -0400] [Client 44] Content-Length: 4661
D [21/Oct/2018:20:52:41 -0400] [Client 44] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:41 -0400] [Client 44] con->http=0x559ac8856520
D [21/Oct/2018:20:52:41 -0400] [Client 44] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8822900(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:41 -0400] [Client 44] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:41 -0400] [Client 44] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:41 -0400] [Client 44] Flushing write buffer.
D [21/Oct/2018:20:52:41 -0400] [Client 44] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:41 -0400] [Client 44] Waiting for request.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:41 -0400] [Client 44] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:41 -0400] [Client 44] Closing connection.
D [21/Oct/2018:20:52:41 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 45] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 45] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 45] Waiting for request.
I [21/Oct/2018:20:52:42 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 46] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 46] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 46] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] [Client 45] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 45] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 46] POST / HTTP/1.1
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 46] Read: status=200, state=6
D [21/Oct/2018:20:52:42 -0400] [Client 46] No authentication data provided.
D [21/Oct/2018:20:52:42 -0400] [Client 46] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:42 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:42 -0400] [Client 46] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:42 -0400] [Client 46] Content-Length: 4661
D [21/Oct/2018:20:52:42 -0400] [Client 46] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:42 -0400] [Client 46] con->http=0x559ac8856520
D [21/Oct/2018:20:52:42 -0400] [Client 46] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883bab0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:42 -0400] [Client 46] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:42 -0400] [Client 46] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:42 -0400] [Client 46] Flushing write buffer.
D [21/Oct/2018:20:52:42 -0400] [Client 46] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:42 -0400] [Client 46] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 46] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 46] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 47] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 47] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 47] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 48] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 48] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 48] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] [Client 47] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 47] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 48] POST / HTTP/1.1
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 48] Read: status=200, state=6
D [21/Oct/2018:20:52:42 -0400] [Client 48] No authentication data provided.
D [21/Oct/2018:20:52:42 -0400] [Client 48] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:42 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:42 -0400] [Client 48] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:42 -0400] [Client 48] Content-Length: 4661
D [21/Oct/2018:20:52:42 -0400] [Client 48] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:42 -0400] [Client 48] con->http=0x559ac8856520
D [21/Oct/2018:20:52:42 -0400] [Client 48] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:42 -0400] [Client 48] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:42 -0400] [Client 48] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:42 -0400] [Client 48] Flushing write buffer.
D [21/Oct/2018:20:52:42 -0400] [Client 48] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:42 -0400] [Client 48] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 48] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 48] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 49] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 49] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 49] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 50] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 50] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 50] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] [Client 49] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 49] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 50] POST / HTTP/1.1
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 50] Read: status=200, state=6
D [21/Oct/2018:20:52:42 -0400] [Client 50] No authentication data provided.
D [21/Oct/2018:20:52:42 -0400] [Client 50] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:42 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:42 -0400] [Client 50] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:42 -0400] [Client 50] Content-Length: 4661
D [21/Oct/2018:20:52:42 -0400] [Client 50] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:42 -0400] [Client 50] con->http=0x559ac8856520
D [21/Oct/2018:20:52:42 -0400] [Client 50] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8822900(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:42 -0400] [Client 50] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:42 -0400] [Client 50] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:42 -0400] [Client 50] Flushing write buffer.
D [21/Oct/2018:20:52:42 -0400] [Client 50] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:42 -0400] [Client 50] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 50] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 50] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 51] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 51] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 51] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 52] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 52] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 52] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] [Client 51] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 51] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 52] POST / HTTP/1.1
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 52] Read: status=200, state=6
D [21/Oct/2018:20:52:42 -0400] [Client 52] No authentication data provided.
D [21/Oct/2018:20:52:42 -0400] [Client 52] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:42 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:42 -0400] [Client 52] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:42 -0400] [Client 52] Content-Length: 4661
D [21/Oct/2018:20:52:42 -0400] [Client 52] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:42 -0400] [Client 52] con->http=0x559ac8856520
D [21/Oct/2018:20:52:42 -0400] [Client 52] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883bab0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:42 -0400] [Client 52] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:42 -0400] [Client 52] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:42 -0400] [Client 52] Flushing write buffer.
D [21/Oct/2018:20:52:42 -0400] [Client 52] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:42 -0400] [Client 52] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 52] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 52] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 53] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 53] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 53] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 54] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:42 -0400] [Client 54] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:42 -0400] [Client 54] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] [Client 53] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 53] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 54] POST / HTTP/1.1
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:42 -0400] [Client 54] Read: status=200, state=6
D [21/Oct/2018:20:52:42 -0400] [Client 54] No authentication data provided.
D [21/Oct/2018:20:52:42 -0400] [Client 54] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:42 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:42 -0400] [Client 54] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:42 -0400] [Client 54] Content-Length: 4661
D [21/Oct/2018:20:52:42 -0400] [Client 54] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:42 -0400] [Client 54] con->http=0x559ac8856520
D [21/Oct/2018:20:52:42 -0400] [Client 54] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:42 -0400] [Client 54] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:42 -0400] [Client 54] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:42 -0400] [Client 54] Flushing write buffer.
D [21/Oct/2018:20:52:42 -0400] [Client 54] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:42 -0400] [Client 54] Waiting for request.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:42 -0400] [Client 54] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:42 -0400] [Client 54] Closing connection.
D [21/Oct/2018:20:52:42 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 55] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 55] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 55] Waiting for request.
I [21/Oct/2018:20:52:43 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 56] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 56] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 56] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] [Client 55] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 55] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 56] POST / HTTP/1.1
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 56] Read: status=200, state=6
D [21/Oct/2018:20:52:43 -0400] [Client 56] No authentication data provided.
D [21/Oct/2018:20:52:43 -0400] [Client 56] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:43 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:43 -0400] [Client 56] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:43 -0400] [Client 56] Content-Length: 4661
D [21/Oct/2018:20:52:43 -0400] [Client 56] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:43 -0400] [Client 56] con->http=0x559ac8856520
D [21/Oct/2018:20:52:43 -0400] [Client 56] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8822900(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:43 -0400] [Client 56] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:43 -0400] [Client 56] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:43 -0400] [Client 56] Flushing write buffer.
D [21/Oct/2018:20:52:43 -0400] [Client 56] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:43 -0400] [Client 56] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 56] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 56] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 57] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 57] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 57] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 58] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 58] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 58] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] [Client 57] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 57] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 58] POST / HTTP/1.1
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 58] Read: status=200, state=6
D [21/Oct/2018:20:52:43 -0400] [Client 58] No authentication data provided.
D [21/Oct/2018:20:52:43 -0400] [Client 58] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:43 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:43 -0400] [Client 58] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:43 -0400] [Client 58] Content-Length: 4661
D [21/Oct/2018:20:52:43 -0400] [Client 58] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:43 -0400] [Client 58] con->http=0x559ac8856520
D [21/Oct/2018:20:52:43 -0400] [Client 58] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883bab0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:43 -0400] [Client 58] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:43 -0400] [Client 58] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:43 -0400] [Client 58] Flushing write buffer.
D [21/Oct/2018:20:52:43 -0400] [Client 58] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:43 -0400] [Client 58] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 58] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 58] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 59] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 59] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 59] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 60] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 60] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 60] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] [Client 59] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 59] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 60] POST / HTTP/1.1
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 60] Read: status=200, state=6
D [21/Oct/2018:20:52:43 -0400] [Client 60] No authentication data provided.
D [21/Oct/2018:20:52:43 -0400] [Client 60] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:43 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:43 -0400] [Client 60] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:43 -0400] [Client 60] Content-Length: 4661
D [21/Oct/2018:20:52:43 -0400] [Client 60] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:43 -0400] [Client 60] con->http=0x559ac8856520
D [21/Oct/2018:20:52:43 -0400] [Client 60] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:43 -0400] [Client 60] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:43 -0400] [Client 60] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:43 -0400] [Client 60] Flushing write buffer.
D [21/Oct/2018:20:52:43 -0400] [Client 60] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:43 -0400] [Client 60] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 60] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 60] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 61] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 61] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 61] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 62] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 62] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 62] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] [Client 61] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 61] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 62] POST / HTTP/1.1
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 62] Read: status=200, state=6
D [21/Oct/2018:20:52:43 -0400] [Client 62] No authentication data provided.
D [21/Oct/2018:20:52:43 -0400] [Client 62] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:43 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:43 -0400] [Client 62] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:43 -0400] [Client 62] Content-Length: 4661
D [21/Oct/2018:20:52:43 -0400] [Client 62] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:43 -0400] [Client 62] con->http=0x559ac8856520
D [21/Oct/2018:20:52:43 -0400] [Client 62] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac8822900(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:43 -0400] [Client 62] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:43 -0400] [Client 62] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:43 -0400] [Client 62] Flushing write buffer.
D [21/Oct/2018:20:52:43 -0400] [Client 62] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:43 -0400] [Client 62] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 62] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 62] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 63] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 63] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 63] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 64] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:43 -0400] [Client 64] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:43 -0400] [Client 64] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] [Client 63] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 63] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 64] POST / HTTP/1.1
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:43 -0400] [Client 64] Read: status=200, state=6
D [21/Oct/2018:20:52:43 -0400] [Client 64] No authentication data provided.
D [21/Oct/2018:20:52:43 -0400] [Client 64] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:52:43 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:43 -0400] [Client 64] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:43 -0400] [Client 64] Content-Length: 4661
D [21/Oct/2018:20:52:43 -0400] [Client 64] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:43 -0400] [Client 64] con->http=0x559ac8856520
D [21/Oct/2018:20:52:43 -0400] [Client 64] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=4661, response=0x559ac883bab0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:43 -0400] [Client 64] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:43 -0400] [Client 64] bytes=0, http_state=0, data_remaining=4661
D [21/Oct/2018:20:52:43 -0400] [Client 64] Flushing write buffer.
D [21/Oct/2018:20:52:43 -0400] [Client 64] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:43 -0400] [Client 64] Waiting for request.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:52:43 -0400] [Client 64] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:43 -0400] [Client 64] Closing connection.
D [21/Oct/2018:20:52:43 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:52:44 -0400] [Client 65] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:44 -0400] [Client 65] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:44 -0400] [Client 65] Waiting for request.
I [21/Oct/2018:20:52:44 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:44 -0400] [Client 65] POST /printers/HP-LaserJet-Professional-M1217nfw-MFP HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 65] 2.1 Print-Job 1
D [21/Oct/2018:20:52:44 -0400] Print-Job ipp://localhost:631/printers/HP-LaserJet-Professional-M1217nfw-MFP
D [21/Oct/2018:20:52:44 -0400] [Job ???] Auto-typing file...
I [21/Oct/2018:20:52:44 -0400] [Job ???] Request file type is application/pdf.
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(---J-)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [21/Oct/2018:20:52:44 -0400] [Job 474] Applying default options...
D [21/Oct/2018:20:52:44 -0400] add_job: requesting-user-name="ubu"
I [21/Oct/2018:20:52:44 -0400] [Job 474] Adding start banner page "none".
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(----S)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(---J-)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [21/Oct/2018:20:52:44 -0400] [Job 474] Adding end banner page "none".
I [21/Oct/2018:20:52:44 -0400] [Job 474] File of type application/pdf queued by "ubu".
D [21/Oct/2018:20:52:44 -0400] [Job 474] hold_until=0
I [21/Oct/2018:20:52:44 -0400] [Job 474] Queued on "HP-LaserJet-Professional-M1217nfw-MFP" by "ubu".
D [21/Oct/2018:20:52:44 -0400] [Job 474] time-at-processing=1540169564
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(---J-)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(----S)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Job 474] 3 filters for job:
D [21/Oct/2018:20:52:44 -0400] [Job 474] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [21/Oct/2018:20:52:44 -0400] [Job 474] gstoraster (application/vnd.cups-pdf to application/vnd.cups-raster, cost 99)
D [21/Oct/2018:20:52:44 -0400] [Job 474] hpcups (application/vnd.cups-raster to printer/HP-LaserJet-Professional-M1217nfw-MFP, cost 0)
D [21/Oct/2018:20:52:44 -0400] [Job 474] job-sheets=none,none
D [21/Oct/2018:20:52:44 -0400] [Job 474] argv[0]="HP-LaserJet-Professional-M1217nfw-MFP"
D [21/Oct/2018:20:52:44 -0400] [Job 474] argv[1]="474"
D [21/Oct/2018:20:52:44 -0400] [Job 474] argv[2]="ubu"
D [21/Oct/2018:20:52:44 -0400] [Job 474] argv[3]="Untitled Document 1"
D [21/Oct/2018:20:52:44 -0400] [Job 474] argv[4]="1"
D [21/Oct/2018:20:52:44 -0400] [Job 474] argv[5]="InputSlot=Auto number-up=1 PageSize=Letter MediaType=Plain noCollate OutputMode=Normal job-uuid=urn:uuid:0150f1c2-7171-3dfd-6c8f-57d64fd77aab job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1540169564 time-at-processing=1540169564"
D [21/Oct/2018:20:52:44 -0400] [Job 474] argv[6]="/var/spool/cups/d00474-001"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc-root"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[7]="CUPS_STATEDIR=/run/cups"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[8]="HOME=/var/spool/cups/tmp"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[10]="SERVER_ADMIN=root@quebec"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[11]="SOFTWARE=CUPS/2.2.7"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[13]="USER=root"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[14]="CUPS_MAX_MESSAGE=2047"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[17]="IPP_PORT=631"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[18]="CHARSET=utf-8"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[19]="LANG=en_CA.UTF-8"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[20]="PPD=/etc/cups/ppd/HP-LaserJet-Professional-M1217nfw-MFP.ppd"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[21]="RIP_MAX_CACHE=128m"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[22]="CONTENT_TYPE=application/pdf"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[23]="DEVICE_URI=hp:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[24]="PRINTER_INFO=Hewlett-Packard HP LaserJet Professional M1217nfw MFP"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[25]="PRINTER_LOCATION=quebec"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[26]="PRINTER=HP-LaserJet-Professional-M1217nfw-MFP"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[27]="PRINTER_STATE_REASONS=none"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[28]="CUPS_FILETYPE=document"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-raster"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[30]="AUTH_I****"
I [21/Oct/2018:20:52:44 -0400] [Job 474] Started filter /usr/lib/cups/filter/pdftopdf (PID 3086)
I [21/Oct/2018:20:52:44 -0400] [Job 474] Started filter /usr/lib/cups/filter/gstoraster (PID 3087)
I [21/Oct/2018:20:52:44 -0400] [Job 474] Started filter /usr/lib/cups/filter/hpcups (PID 3088)
I [21/Oct/2018:20:52:44 -0400] [Job 474] Started backend /usr/lib/cups/backend/hp (PID 3089)
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(----S)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 65] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/HP-LaserJet-Professional-M1217nfw-MFP) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 65] Content-Length: 193
D [21/Oct/2018:20:52:44 -0400] [Client 65] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 65] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:44 -0400] [Client 65] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=193, response=0x559ac884aab0(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 65] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 65] bytes=0, http_state=0, data_remaining=193
D [21/Oct/2018:20:52:44 -0400] [Client 65] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 65] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 65] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] JobCreated
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] PrinterStateChanged
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Client 6] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 6] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 6] 2.0 Get-Notifications 18
D [21/Oct/2018:20:52:44 -0400] Get-Notifications /printers/
D [21/Oct/2018:20:52:44 -0400] cupsdIsAuthorized: requesting-user-name="ubu"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 6] Content-Length: 1774
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] JobState
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Client 6] con->http=0x559ac884d5f0
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1774, response=0x559ac8854e60(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] bytes=0, http_state=0, data_remaining=1774
D [21/Oct/2018:20:52:44 -0400] [Client 6] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 6] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 6] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 66] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:44 -0400] [Client 66] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:44 -0400] [Client 66] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] [Client 65] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:44 -0400] [Client 65] Closing connection.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 66] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 66] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 66] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 66] 2.0 Get-Job-Attributes 19
D [21/Oct/2018:20:52:44 -0400] Get-Job-Attributes ipp://localhost/jobs/474
D [21/Oct/2018:20:52:44 -0400] [Client 66] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/474) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 66] Content-Length: 109
D [21/Oct/2018:20:52:44 -0400] [Client 66] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 66] con->http=0x559ac885c740
D [21/Oct/2018:20:52:44 -0400] [Client 66] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=109, response=0x559ac88558d0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 66] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 66] bytes=0, http_state=0, data_remaining=109
D [21/Oct/2018:20:52:44 -0400] [Client 66] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 66] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 66] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 66] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:44 -0400] [Client 66] Closing connection.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 67] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:44 -0400] [Client 67] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:44 -0400] [Client 67] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] [Client 67] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 67] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 67] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 67] 2.0 Get-Job-Attributes 20
D [21/Oct/2018:20:52:44 -0400] Get-Job-Attributes ipp://localhost/jobs/474
D [21/Oct/2018:20:52:44 -0400] [Client 67] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/474) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 67] Content-Length: 109
D [21/Oct/2018:20:52:44 -0400] [Client 67] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 67] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:44 -0400] [Client 67] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=109, response=0x559ac88557e0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 67] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 67] bytes=0, http_state=0, data_remaining=109
D [21/Oct/2018:20:52:44 -0400] [Client 67] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 67] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 67] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 67] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:44 -0400] [Client 67] Closing connection.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Job 474] OUTFORMAT=\"(null)\", so output format will be CUPS/PWG Raster
D [21/Oct/2018:20:52:44 -0400] [Job 474] pdftopdf: Last filter determined by the PPD: hpcups; FINAL_CONTENT_TYPE: application/vnd.cups-raster => pdftopdf will not log pages in page_log.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 68] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:44 -0400] [Client 68] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:44 -0400] [Client 68] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] [Client 68] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 68] 2.0 CUPS-Get-Printers 57
D [21/Oct/2018:20:52:44 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:44 -0400] [Client 68] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 68] Content-Length: 2255
D [21/Oct/2018:20:52:44 -0400] [Client 68] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 68] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:44 -0400] [Client 68] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac88557e0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 68] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 68] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:52:44 -0400] [Client 68] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 68] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 68] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Job 474] prnt/hpcups/HPCupsFilter.cpp 539: argv[0] = HP-LaserJet-Professional-M1217nfw-MFP
D [21/Oct/2018:20:52:44 -0400] [Job 474] prnt/hpcups/HPCupsFilter.cpp 539: argv[1] = 474
D [21/Oct/2018:20:52:44 -0400] [Job 474] prnt/hpcups/HPCupsFilter.cpp 539: argv[2] = ubu
D [21/Oct/2018:20:52:44 -0400] [Job 474] prnt/hpcups/HPCupsFilter.cpp 539: argv[3] = Untitled Document 1
D [21/Oct/2018:20:52:44 -0400] [Job 474] prnt/hpcups/HPCupsFilter.cpp 539: argv[4] = 1
D [21/Oct/2018:20:52:44 -0400] [Job 474] prnt/hpcups/HPCupsFilter.cpp 539: argv[5] = InputSlot=Auto number-up=1 PageSize=Letter MediaType=Plain noCollate OutputMode=Normal job-uuid=urn:uuid:0150f1c2-7171-3dfd-6c8f-57d64fd77aab job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1540169564 time-at-processing=1540169564
D [21/Oct/2018:20:52:44 -0400] [Job 474] PID 3086 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [21/Oct/2018:20:52:44 -0400] [Job 474] Color Manager: Calibration Mode/Off
D [21/Oct/2018:20:52:44 -0400] [Job 474] Calling FindDeviceById(cups-HP-LaserJet-Professional-M1217nfw-MFP)
D [21/Oct/2018:20:52:44 -0400] [Job 474] Found device /org/freedesktop/ColorManager/devices/cups_HP_LaserJet_Professional_M1217nfw_MFP
D [21/Oct/2018:20:52:44 -0400] [Job 474] Calling org.freedesktop.ColorManager.Device.Get(ProfilingInhibitors)
D [21/Oct/2018:20:52:44 -0400] [Job 474] Calling FindDeviceById(cups-HP-LaserJet-Professional-M1217nfw-MFP)
D [21/Oct/2018:20:52:44 -0400] [Job 474] Found device /org/freedesktop/ColorManager/devices/cups_HP_LaserJet_Professional_M1217nfw_MFP
D [21/Oct/2018:20:52:44 -0400] [Job 474] Calling GetProfileForQualifiers(Gray.Plain....)
D [21/Oct/2018:20:52:44 -0400] [Client 6] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 6] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 6] 2.0 Get-Notifications 21
D [21/Oct/2018:20:52:44 -0400] Get-Notifications /printers/
D [21/Oct/2018:20:52:44 -0400] cupsdIsAuthorized: requesting-user-name="ubu"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 6] Content-Length: 127
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] con->http=0x559ac884d5f0
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x559ac885bc10(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] bytes=0, http_state=0, data_remaining=127
D [21/Oct/2018:20:52:44 -0400] [Client 6] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 6] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 6] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Job 474] Found profile /org/freedesktop/ColorManager/profiles/HP_LaserJet_Professional_M1217nfw_MFP_Gray__
D [21/Oct/2018:20:52:44 -0400] [Job 474] Calling org.freedesktop.ColorManager.Profile.Get(Filename)
D [21/Oct/2018:20:52:44 -0400] [Client 6] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 6] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 6] 2.0 Get-Notifications 22
D [21/Oct/2018:20:52:44 -0400] Get-Notifications /printers/
D [21/Oct/2018:20:52:44 -0400] cupsdIsAuthorized: requesting-user-name="ubu"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 6] Content-Length: 127
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] con->http=0x559ac884d5f0
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x559ac88557e0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] bytes=0, http_state=0, data_remaining=127
D [21/Oct/2018:20:52:44 -0400] [Client 6] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 6] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 6] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Job 474] Use profile filename: \'\'
D [21/Oct/2018:20:52:44 -0400] [Job 474] Color Manager: ICC Profile:
D [21/Oct/2018:20:52:44 -0400] [Job 474] Ghostscript using Any-Part-of-Pixel method to fill paths.
D [21/Oct/2018:20:52:44 -0400] [Job 474] Ghostscript command line: gs -dQUIET -dPARANOIDSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dShowAcroForm -sstdout=%stderr -sOutputFile=%stdout -sDEVICE=cups -sMediaType=Plain -sOutputType=0 -r600x600 -dMediaPosition=7 -dDEVICEWIDTHPOINTS=612 -dDEVICEHEIGHTPOINTS=792 -dcupsBitsPerColor=1 -dcupsColorOrder=0 -dcupsColorSpace=3 -dcupsRowCount=1 -dcupsRowStep=2 -dcupsInteger0=2 -scupsPageSizeName=Letter -I/usr/share/cups/fonts -c \'<</.HWMargins[12.000000 12.000000 12.000000 12.000000] /Margins[0 0]>>setpagedevice\' -f -_
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[0]=\"CUPS_CACHEDIR=/var/cache/cups\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[1]=\"CUPS_DATADIR=/usr/share/cups\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[2]=\"CUPS_DOCROOT=/usr/share/cups/doc-root\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[3]=\"CUPS_FONTPATH=/usr/share/cups/fonts\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[4]=\"CUPS_REQUESTROOT=/var/spool/cups\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[5]=\"CUPS_SERVERBIN=/usr/lib/cups\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[6]=\"CUPS_SERVERROOT=/etc/cups\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[7]=\"CUPS_STATEDIR=/run/cups\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[8]=\"HOME=/var/spool/cups/tmp\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[9]=\"PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[10]=\"SERVER_ADMIN=root@quebec\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[11]=\"SOFTWARE=CUPS/2.2.7\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[12]=\"USER=root\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[13]=\"CUPS_MAX_MESSAGE=2047\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[14]=\"CUPS_SERVER=/var/run/cups/cups.sock\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[15]=\"CUPS_ENCRYPTION=IfRequested\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[16]=\"IPP_PORT=631\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[17]=\"CHARSET=utf-8\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[18]=\"LANG=en_CA.UTF-8\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[19]=\"PPD=/etc/cups/ppd/HP-LaserJet-Professional-M1217nfw-MFP.ppd\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[20]=\"RIP_MAX_CACHE=128m\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[21]=\"CONTENT_TYPE=application/pdf\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[22]=\"DEVICE_URI=hp:/usb/HP_LaserJet_Professional_M1217nfw_MFP?serial=000000000T240C69PR1a\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[23]=\"PRINTER_INFO=Hewlett-Packard HP LaserJet Professional M1217nfw MFP\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[24]=\"PRINTER_LOCATION=quebec\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[25]=\"PRINTER=HP-LaserJet-Professional-M1217nfw-MFP\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[26]=\"PRINTER_STATE_REASONS=none\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[27]=\"CUPS_FILETYPE=document\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[28]=\"FINAL_CONTENT_TYPE=application/vnd.cups-raster\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] envp[29]=\"AUTH_INFO_REQUIRED=none\"
D [21/Oct/2018:20:52:44 -0400] [Job 474] ./base/gsicc_manage.c:1244: gsicc_open_search(): Could not find default_gray.icc
D [21/Oct/2018:20:52:44 -0400] [Job 474] | ./base/gsicc_manage.c:2025: gsicc_set_device_profile(): cannot find device profile
D [21/Oct/2018:20:52:44 -0400] [Job 474] Unrecoverable error: rangecheck in .putdeviceprops
D [21/Oct/2018:20:52:44 -0400] [Job 474] Operand stack:
D [21/Oct/2018:20:52:44 -0400] [Job 474] true
D [21/Oct/2018:20:52:44 -0400] [Job 474] prnt/hpcups/HPCupsFilter.cpp 569: cupsRasterOpen failed, fd = 0
D [21/Oct/2018:20:52:44 -0400] [Job 474] prnt/backend/hp.c 919: ERROR: null print job total=0
D [21/Oct/2018:20:52:44 -0400] [Job 474] PID 3088 (/usr/lib/cups/filter/hpcups) stopped with status 1.
D [21/Oct/2018:20:52:44 -0400] [Job 474] PID 3087 (/usr/lib/cups/filter/gstoraster) stopped with status 1.
D [21/Oct/2018:20:52:44 -0400] [Job 474] PID 3089 (/usr/lib/cups/backend/hp) exited with no errors.
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(----S)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
E [21/Oct/2018:20:52:44 -0400] [Job 474] Job stopped due to filter errors; please consult the error_log file for details.
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(---J-)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(----S)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdMarkDirty(---J-)
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 68] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Printing jobs and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] Read: status=100, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 68] 2.0 CUPS-Get-Printers 58
D [21/Oct/2018:20:52:44 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:52:44 -0400] [Client 68] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 68] Content-Length: 2255
D [21/Oct/2018:20:52:44 -0400] [Client 68] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 68] con->http=0x559ac8850b70
D [21/Oct/2018:20:52:44 -0400] [Client 68] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac885d950(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 68] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 68] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:52:44 -0400] [Client 68] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 68] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 68] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] JobState
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] PrinterStateChanged
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Notifier] state=3
D [21/Oct/2018:20:52:44 -0400] [Client 6] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 6] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 6] 2.0 Get-Notifications 23
D [21/Oct/2018:20:52:44 -0400] Get-Notifications /printers/
D [21/Oct/2018:20:52:44 -0400] cupsdIsAuthorized: requesting-user-name="ubu"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 6] Content-Length: 1268
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] con->http=0x559ac884d5f0
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1268, response=0x559ac885e090(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] bytes=0, http_state=0, data_remaining=1268
D [21/Oct/2018:20:52:44 -0400] [Client 6] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 6] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 6] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 69] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:44 -0400] [Client 69] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:44 -0400] [Client 69] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] [Client 69] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 69] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 69] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 69] 2.0 Get-Job-Attributes 24
D [21/Oct/2018:20:52:44 -0400] Get-Job-Attributes ipp://localhost/jobs/474
D [21/Oct/2018:20:52:44 -0400] [Client 69] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/474) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 69] Content-Length: 109
D [21/Oct/2018:20:52:44 -0400] [Client 69] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 69] con->http=0x559ac885e960
D [21/Oct/2018:20:52:44 -0400] [Client 69] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=109, response=0x559ac8861d10(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 69] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 69] bytes=0, http_state=0, data_remaining=109
D [21/Oct/2018:20:52:44 -0400] [Client 69] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 69] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 69] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 69] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:44 -0400] [Client 69] Closing connection.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 6] POST / HTTP/1.1
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Read: status=200, state=6
D [21/Oct/2018:20:52:44 -0400] [Client 6] No authentication data provided.
D [21/Oct/2018:20:52:44 -0400] [Client 6] 2.0 Get-Notifications 25
D [21/Oct/2018:20:52:44 -0400] Get-Notifications /printers/
D [21/Oct/2018:20:52:44 -0400] cupsdIsAuthorized: requesting-user-name="ubu"
D [21/Oct/2018:20:52:44 -0400] [Client 6] Returning IPP successful-ok for Get-Notifications (/printers/) from localhost
D [21/Oct/2018:20:52:44 -0400] [Client 6] Content-Length: 127
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] con->http=0x559ac884d5f0
D [21/Oct/2018:20:52:44 -0400] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=127, response=0x559ac8861de0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:52:44 -0400] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:52:44 -0400] [Client 6] bytes=0, http_state=0, data_remaining=127
D [21/Oct/2018:20:52:44 -0400] [Client 6] Flushing write buffer.
D [21/Oct/2018:20:52:44 -0400] [Client 6] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:52:44 -0400] [Client 6] Waiting for request.
D [21/Oct/2018:20:52:44 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [21/Oct/2018:20:52:45 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:45 -0400] [Job 474] Unloading...
D [21/Oct/2018:20:52:58 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [21/Oct/2018:20:52:58 -0400] [Client 70] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:52:58 -0400] [Client 70] Accepted from localhost (Domain)
D [21/Oct/2018:20:52:58 -0400] [Client 70] Waiting for request.
I [21/Oct/2018:20:52:58 -0400] Expiring subscriptions...
D [21/Oct/2018:20:52:58 -0400] [Client 70] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:52:58 -0400] [Client 70] Closing connection.
D [21/Oct/2018:20:52:58 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [21/Oct/2018:20:52:59 -0400] Expiring subscriptions...
D [21/Oct/2018:20:53:03 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [21/Oct/2018:20:53:03 -0400] [Client 71] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:53:03 -0400] [Client 71] Accepted from localhost (Domain)
D [21/Oct/2018:20:53:03 -0400] [Client 71] Waiting for request.
I [21/Oct/2018:20:53:03 -0400] Expiring subscriptions...
D [21/Oct/2018:20:53:03 -0400] [Client 71] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:53:03 -0400] [Client 71] Closing connection.
D [21/Oct/2018:20:53:03 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:53:04 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [21/Oct/2018:20:53:04 -0400] [Client 72] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:53:04 -0400] [Client 72] Accepted from localhost (Domain)
D [21/Oct/2018:20:53:04 -0400] [Client 72] Waiting for request.
I [21/Oct/2018:20:53:04 -0400] Expiring subscriptions...
D [21/Oct/2018:20:53:04 -0400] [Client 72] POST / HTTP/1.1
D [21/Oct/2018:20:53:04 -0400] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Oct/2018:20:53:04 -0400] [Client 72] Read: status=200, state=6
D [21/Oct/2018:20:53:04 -0400] [Client 72] No authentication data provided.
D [21/Oct/2018:20:53:04 -0400] [Client 72] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:53:04 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:04 -0400] [Client 72] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:04 -0400] [Client 72] Content-Length: 485
D [21/Oct/2018:20:53:04 -0400] [Client 72] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:04 -0400] [Client 72] con->http=0x559ac885e920
D [21/Oct/2018:20:53:04 -0400] [Client 72] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=485, response=0x559ac8848ef0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:04 -0400] [Client 72] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:04 -0400] [Client 72] bytes=0, http_state=0, data_remaining=485
D [21/Oct/2018:20:53:04 -0400] [Client 72] Flushing write buffer.
D [21/Oct/2018:20:53:04 -0400] [Client 72] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:04 -0400] [Client 72] Waiting for request.
D [21/Oct/2018:20:53:04 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [21/Oct/2018:20:53:05 -0400] Expiring subscriptions...
D [21/Oct/2018:20:53:14 -0400] [Client 72] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:53:14 -0400] [Client 72] Closing connection.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [21/Oct/2018:20:53:14 -0400] Saving job.cache...
I [21/Oct/2018:20:53:14 -0400] Saving subscriptions.conf...
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
I [21/Oct/2018:20:53:14 -0400] Expiring subscriptions...
D [21/Oct/2018:20:53:14 -0400] [Job 471] Unloading...
D [21/Oct/2018:20:53:14 -0400] [Job 472] Unloading...
D [21/Oct/2018:20:53:14 -0400] [Job 473] Unloading...
D [21/Oct/2018:20:53:14 -0400] Report: clients=4
D [21/Oct/2018:20:53:14 -0400] Report: jobs=4
D [21/Oct/2018:20:53:14 -0400] Report: jobs-active=4
D [21/Oct/2018:20:53:14 -0400] Report: printers=5
D [21/Oct/2018:20:53:14 -0400] Report: stringpool-string-count=3634
D [21/Oct/2018:20:53:14 -0400] Report: stringpool-alloc-bytes=13360
D [21/Oct/2018:20:53:14 -0400] Report: stringpool-total-bytes=77408
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 73] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:53:14 -0400] [Client 73] Accepted from localhost (Domain)
D [21/Oct/2018:20:53:14 -0400] [Client 73] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] [Client 73] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 73] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 73] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 73] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 73] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 73] Content-Length: 6497
D [21/Oct/2018:20:53:14 -0400] [Client 73] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 73] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 73] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=6497, response=0x559ac880a340(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 73] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 73] bytes=0, http_state=0, data_remaining=6497
D [21/Oct/2018:20:53:14 -0400] [Client 73] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 73] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 73] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 73] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 73] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 73] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 73] 2.0 CUPS-Get-Default 2
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Default
D [21/Oct/2018:20:53:14 -0400] [Client 73] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 73] Content-Length: 10139
D [21/Oct/2018:20:53:14 -0400] [Client 73] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 73] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 73] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=10139, response=0x559ac880a1d0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 73] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 73] bytes=0, http_state=0, data_remaining=10139
D [21/Oct/2018:20:53:14 -0400] [Client 73] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 73] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 73] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 73] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 73] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 73] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 73] 2.0 CUPS-Get-Default 3
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Default
D [21/Oct/2018:20:53:14 -0400] [Client 73] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 73] Content-Length: 10139
D [21/Oct/2018:20:53:14 -0400] [Client 73] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 73] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 73] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=10139, response=0x559ac88448c0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 73] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 73] bytes=0, http_state=0, data_remaining=10139
D [21/Oct/2018:20:53:14 -0400] [Client 73] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 73] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 73] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 73] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 73] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 73] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 73] 2.0 CUPS-Get-Printers 4
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 73] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 73] Content-Length: 1250
D [21/Oct/2018:20:53:14 -0400] [Client 73] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 73] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 73] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1250, response=0x559ac880a340(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 73] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 73] bytes=0, http_state=0, data_remaining=1250
D [21/Oct/2018:20:53:14 -0400] [Client 73] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 73] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 73] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 73] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:53:14 -0400] [Client 73] Closing connection.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 74] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:53:14 -0400] [Client 74] Accepted from localhost (Domain)
D [21/Oct/2018:20:53:14 -0400] [Client 74] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] [Client 74] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 74] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 74] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 74] 2.0 Get-Printer-Attributes 1
D [21/Oct/2018:20:53:14 -0400] Get-Printer-Attributes ipp://localhost:631/printers/HP-LaserJet-Professional-M1217nfw-MFP
D [21/Oct/2018:20:53:14 -0400] [Client 74] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/HP-LaserJet-Professional-M1217nfw-MFP) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 74] Content-Length: 1435
D [21/Oct/2018:20:53:14 -0400] [Client 74] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 74] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 74] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1435, response=0x559ac87b83b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 74] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 74] bytes=0, http_state=0, data_remaining=1435
D [21/Oct/2018:20:53:14 -0400] [Client 74] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 74] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 74] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 74] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 74] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 74] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 74] 2.0 CUPS-Get-Printers 2
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 74] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 74] Content-Length: 2260
D [21/Oct/2018:20:53:14 -0400] [Client 74] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 74] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 74] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2260, response=0x559ac8809b50(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 74] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 74] bytes=0, http_state=0, data_remaining=2260
D [21/Oct/2018:20:53:14 -0400] [Client 74] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 74] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 74] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 74] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:53:14 -0400] [Client 74] Closing connection.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:53:14 -0400] [Client 75] Accepted from localhost (Domain)
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 75] 2.0 CUPS-Get-Printers 1
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac88425c0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 75] 2.0 CUPS-Get-Printers 2
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac87b7e00(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 76] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:53:14 -0400] [Client 76] Accepted from localhost (Domain)
D [21/Oct/2018:20:53:14 -0400] [Client 76] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] [Client 76] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 76] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 76] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 76] 2.0 Get-Printer-Attributes 1
D [21/Oct/2018:20:53:14 -0400] Get-Printer-Attributes ipp://localhost:631/printers/HP-LaserJet-Professional-M1217nfw-MFP-Fax-3
D [21/Oct/2018:20:53:14 -0400] [Client 76] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/HP-LaserJet-Professional-M1217nfw-MFP-Fax-3) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 76] Content-Length: 1282
D [21/Oct/2018:20:53:14 -0400] [Client 76] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 76] con->http=0x559ac8862cf0
D [21/Oct/2018:20:53:14 -0400] [Client 76] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1282, response=0x559ac87cc530(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 76] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 76] bytes=0, http_state=0, data_remaining=1282
D [21/Oct/2018:20:53:14 -0400] [Client 76] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 76] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 76] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 76] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 76] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 76] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 76] 2.0 CUPS-Get-Printers 2
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 76] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 76] Content-Length: 2260
D [21/Oct/2018:20:53:14 -0400] [Client 76] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 76] con->http=0x559ac8862cf0
D [21/Oct/2018:20:53:14 -0400] [Client 76] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2260, response=0x559ac8809b50(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 76] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 76] bytes=0, http_state=0, data_remaining=2260
D [21/Oct/2018:20:53:14 -0400] [Client 76] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 76] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 76] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 76] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:53:14 -0400] [Client 76] Closing connection.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 75] 2.0 CUPS-Get-Printers 3
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac8809aa0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 75] 2.0 CUPS-Get-Printers 4
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac87cc530(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 77] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:53:14 -0400] [Client 77] Accepted from localhost (Domain)
D [21/Oct/2018:20:53:14 -0400] [Client 77] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] [Client 77] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 77] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 77] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 77] 2.0 Get-Printer-Attributes 1
D [21/Oct/2018:20:53:14 -0400] Get-Printer-Attributes ipp://localhost:631/printers/HP_LaserJet_Professional_M1217nfw_MFP
D [21/Oct/2018:20:53:14 -0400] [Client 77] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/HP_LaserJet_Professional_M1217nfw_MFP) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 77] Content-Length: 1414
D [21/Oct/2018:20:53:14 -0400] [Client 77] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 77] con->http=0x559ac8862cf0
D [21/Oct/2018:20:53:14 -0400] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1414, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 77] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 77] bytes=0, http_state=0, data_remaining=1414
D [21/Oct/2018:20:53:14 -0400] [Client 77] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 77] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 77] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 77] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 77] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 77] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 77] 2.0 CUPS-Get-Printers 2
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 77] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 77] Content-Length: 2260
D [21/Oct/2018:20:53:14 -0400] [Client 77] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 77] con->http=0x559ac8862cf0
D [21/Oct/2018:20:53:14 -0400] [Client 77] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2260, response=0x559ac880a420(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 77] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 77] bytes=0, http_state=0, data_remaining=2260
D [21/Oct/2018:20:53:14 -0400] [Client 77] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 77] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 77] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 77] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:53:14 -0400] [Client 77] Closing connection.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 75] 2.0 CUPS-Get-Printers 5
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac8814db0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 75] 2.0 CUPS-Get-Printers 6
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac88273b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 78] Server address is "/var/run/cups/cups.sock".
D [21/Oct/2018:20:53:14 -0400] [Client 78] Accepted from localhost (Domain)
D [21/Oct/2018:20:53:14 -0400] [Client 78] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] [Client 78] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 78] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 78] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 78] 2.0 Get-Printer-Attributes 1
D [21/Oct/2018:20:53:14 -0400] Get-Printer-Attributes ipp://localhost:631/printers/HP_LaserJet_Professional_M1217nfw_MFP_fax
D [21/Oct/2018:20:53:14 -0400] [Client 78] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/HP_LaserJet_Professional_M1217nfw_MFP_fax) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 78] Content-Length: 1305
D [21/Oct/2018:20:53:14 -0400] [Client 78] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 78] con->http=0x559ac8862cf0
D [21/Oct/2018:20:53:14 -0400] [Client 78] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1305, response=0x559ac87cc530(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 78] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 78] bytes=0, http_state=0, data_remaining=1305
D [21/Oct/2018:20:53:14 -0400] [Client 78] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 78] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 78] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 78] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 78] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 78] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 78] 2.0 CUPS-Get-Printers 2
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 78] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 78] Content-Length: 2260
D [21/Oct/2018:20:53:14 -0400] [Client 78] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 78] con->http=0x559ac8862cf0
D [21/Oct/2018:20:53:14 -0400] [Client 78] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2260, response=0x559ac8848ef0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 78] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 78] bytes=0, http_state=0, data_remaining=2260
D [21/Oct/2018:20:53:14 -0400] [Client 78] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 78] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 78] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 78] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:53:14 -0400] [Client 78] Closing connection.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=100, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] 2.0 CUPS-Get-Printers 7
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac8855790(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:14 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:14 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:14 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:14 -0400] [Client 75] 2.0 CUPS-Get-Printers 8
D [21/Oct/2018:20:53:14 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:14 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:14 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:14 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac87cc530(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:14 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:14 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:14 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:14 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:14 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:14 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:15 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:15 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:15 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:15 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:15 -0400] [Client 75] 2.0 CUPS-Get-Printers 9
D [21/Oct/2018:20:53:15 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:15 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:15 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:15 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
I [21/Oct/2018:20:53:15 -0400] Expiring subscriptions...
D [21/Oct/2018:20:53:15 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:15 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac8848ef0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:15 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:15 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:15 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:15 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:15 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:15 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:15 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:15 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:15 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:15 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:15 -0400] [Client 75] 2.0 CUPS-Get-Printers 10
D [21/Oct/2018:20:53:15 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:15 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:15 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:15 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:15 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:15 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac8855790(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:15 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:15 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:15 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:15 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:15 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:15 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Oct/2018:20:53:15 -0400] [Client 75] POST / HTTP/1.1
D [21/Oct/2018:20:53:15 -0400] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Oct/2018:20:53:15 -0400] [Client 75] Read: status=200, state=6
D [21/Oct/2018:20:53:15 -0400] [Client 75] No authentication data provided.
D [21/Oct/2018:20:53:15 -0400] [Client 75] 2.0 CUPS-Get-Printers 11
D [21/Oct/2018:20:53:15 -0400] CUPS-Get-Printers
D [21/Oct/2018:20:53:15 -0400] [Client 75] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [21/Oct/2018:20:53:15 -0400] [Client 75] Content-Length: 2255
D [21/Oct/2018:20:53:15 -0400] [Client 75] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Oct/2018:20:53:15 -0400] [Client 75] con->http=0x559ac885e920
D [21/Oct/2018:20:53:15 -0400] [Client 75] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2255, response=0x559ac87cc530(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Oct/2018:20:53:15 -0400] [Client 75] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Oct/2018:20:53:15 -0400] [Client 75] bytes=0, http_state=0, data_remaining=2255
D [21/Oct/2018:20:53:15 -0400] [Client 75] Flushing write buffer.
D [21/Oct/2018:20:53:15 -0400] [Client 75] New state is HTTP_STATE_WAITING
D [21/Oct/2018:20:53:15 -0400] [Client 75] Waiting for request.
D [21/Oct/2018:20:53:15 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
I [21/Oct/2018:20:53:16 -0400] Expiring subscriptions...
D [21/Oct/2018:20:53:17 -0400] [Client 75] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Oct/2018:20:53:17 -0400] [Client 75] Closing connection.
D [21/Oct/2018:20:53:17 -0400] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
I [21/Oct/2018:20:53:17 -0400] Expiring subscriptions...

Thanks, that worked!