printer canon mp495 - seems installed but doesn't print [SOLVED]

Sindarin · 2016-11-09 22:16:01

Hi, everyone I have the problem with printer.

It shows as present in system-config-printer gui and it's troubleshoot check doesn't get anything.

When I ask to print a test-page, my printer display lights move as usual, but no page is taken to print.

I've been gathering information in these links:

But I don't think it's the same that happens to me.
| |
Thank you in advance, if I you recommend to test something i'll post it and update it just down here vv
# ----------------UPDATE-----------------------

- Packages installed: gutenprint-5.2.11-4 (everything 32bits)
cups-bjnp-2.0-1 cups-pdf-2.6.1-2
cups-2.2.1-1 libcups-2.2.1-1
cups-filters-1.11.6-1 cups-pk-helper-0.2.6-1
python-pycups-1.9.73-2 system-config-printer-1.5.7-2
- Driver: It's called Canon MP495 - series Ver.3.40
I did the yaourt command to take cnijfilter-mp495-i386
(it had some heimdall problem that i fixed installing heimdall apart of this an modifying the source to not search for it)
I don't know if i have the yaourt driver or the one downloaded from Canon website, but they have the same name and the printer reaction is the same.
- The error.log by November the 10th. this message.

# ----------------UPDATE----------------------- November the 11th.
[SOLVED] I changed the driver to a more general kind in gutenprint Canon MP490 series - CUPS+Gutenprint v5.2.11
Didn't try the official driver with lib32-libtiff3

Last edited by Sindarin (2016-11-13 09:20:29)

olive · 2016-11-10 08:29:13

Instead of system-config-printer; use the cups interface directly (point your browser to http://localhost:631) enable loging and post/examine /var/log/cups/error.log.

The symptoms you describe seems to be the sigh of a bad driver. Which driver are you using? Gutenprint (package gutenprint; don't forget the optional dependencies) support many Canon printers (but I van't tell for yours).

Sindarin · 2016-11-10 11:29:53

Thank you for your answer:

- I have installed: gutenprint-5.2.11-4 (everything 32bits)
cups-bjnp-2.0-1 cups-pdf-2.6.1-2
cups-2.2.1-1 libcups-2.2.1-1
cups-filters-1.11.6-1 cups-pk-helper-0.2.6-1
python-pycups-1.9.73-2 system-config-printer-1.5.7-2

- Driver: It's called Canon MP495 - series Ver.3.40

I did the yaourt command to take cnijfilter-mp495-i386
(it had some heimdall problem that i fixed installing heimdall apart of this an modifying the source to not search for it)
I don't know if i have the yaourt driver or the one downloaded from Canon website, but they have the same name and the printer reaction is the same.

- Here is the error.log

E [07/Nov/2016:10:37:26 +0100] [cups-deviced] PID 2300 (gutenprint52+usb) stopped with status 1!
C [07/Nov/2016:10:37:26 +0100] [CGI] create_broadcast_socket: bind socket to local address failed - Address already in use
W [07/Nov/2016:10:52:38 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'Canon_MP495_series_2-Gray..\' already exists
W [07/Nov/2016:10:52:38 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'Canon_MP495_series_2-RGB..\' already exists
W [07/Nov/2016:10:53:14 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'Canon_MP495_series_2-Gray..\' already exists
W [07/Nov/2016:10:53:14 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'Canon_MP495_series_2-RGB..\' already exists
E [07/Nov/2016:10:53:45 +0100] [cups-deviced] PID 3846 (gutenprint52+usb) stopped with status 1!
E [07/Nov/2016:11:17:42 +0100] [Client 176] Returning IPP client-error-bad-request for Print-Job (ipp://localhost/printers/Canon%5FMP495%5Fseries) from localhost
W [07/Nov/2016:11:18:27 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'Canon_MP495_series_2-Gray..\' already exists
W [07/Nov/2016:11:18:27 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'Canon_MP495_series_2-RGB..\' already exists
W [07/Nov/2016:11:19:12 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'Canon_MP495_series_2-Gray..\' already exists
W [07/Nov/2016:11:19:12 +0100] CreateProfile failed: org.freedesktop.ColorManager.AlreadyExists:profile id \'Canon_MP495_series_2-RGB..\' already exists
E [07/Nov/2016:11:19:24 +0100] [Client 246] Returning IPP client-error-bad-request for Print-Job (ipp://localhost/printers/Canon%5FMP495%5Fseries%5F2) from localhost
E [07/Nov/2016:11:19:29 +0100] [Client 246] Returning IPP client-error-bad-request for Print-Job (ipp://localhost/printers/Canon%5FMP495%5Fseries%5F2) from localhost
E [07/Nov/2016:11:20:55 +0100] [Client 270] Returning IPP client-error-bad-request for Print-Job (ipp://localhost/printers/Canon%5FMP495%5Fseries%5F2) from localhost
E [07/Nov/2016:11:21:04 +0100] [Client 270] Returning IPP client-error-bad-request for Print-Job (ipp://localhost/printers/Canon%5FMP495%5Fseries%5F2) from localhost
E [07/Nov/2016:11:21:12 +0100] [Client 273] Returning IPP client-error-bad-request for Print-Job (ipp://localhost/printers/Canon%5FMP495%5Fseries) from localhost
E [07/Nov/2016:16:45:04 +0100] [cups-deviced] PID 473 (gutenprint52+usb) stopped with status 1!
E [08/Nov/2016:12:03:23 +0100] [cups-deviced] PID 468 (gutenprint52+usb) stopped with status 1!
E [08/Nov/2016:18:53:53 +0100] [cups-deviced] PID 458 (gutenprint52+usb) stopped with status 1!
C [08/Nov/2016:18:53:54 +0100] [CGI] create_broadcast_socket: bind socket to local address failed - Address already in use
E [09/Nov/2016:17:06:31 +0100] [cups-deviced] PID 25260 (gutenprint52+usb) stopped with status 1!
C [09/Nov/2016:17:06:31 +0100] [CGI] create_broadcast_socket: bind socket to local address failed - Address already in use
E [09/Nov/2016:22:42:27 +0100] [cups-deviced] PID 17867 (gutenprint52+usb) stopped with status 1!
E [09/Nov/2016:22:43:43 +0100] [cups-deviced] PID 18030 (gutenprint52+usb) stopped with status 1!
E [09/Nov/2016:22:44:30 +0100] [cups-deviced] PID 18153 (gutenprint52+usb) stopped with status 1!
E [09/Nov/2016:23:07:05 +0100] Scheduler shutting down due to program error.
I [09/Nov/2016:23:07:05 +0100] Listening to [v1.::1]:631 (IPv6)
I [09/Nov/2016:23:07:05 +0100] Listening to 127.0.0.1:631 (IPv4)
I [09/Nov/2016:23:07:05 +0100] Listening to /run/cups/cups.sock (Domain)
E [09/Nov/2016:23:07:05 +0100] Unknown directive JobPrivateAccess on line 89 of /etc/cups/cupsd.conf.
E [09/Nov/2016:23:07:05 +0100] Unknown directive JobPrivateValues on line 90 of /etc/cups/cupsd.conf.
E [09/Nov/2016:23:07:05 +0100] Unknown directive SubscriptionPrivateAccess on line 91 of /etc/cups/cupsd.conf.
E [09/Nov/2016:23:07:05 +0100] Unknown directive SubscriptionPrivateValues on line 92 of /etc/cups/cupsd.conf.
I [09/Nov/2016:23:07:05 +0100] Remote access is disabled.
D [09/Nov/2016:23:07:05 +0100] Added auto ServerAlias tierramedia
I [09/Nov/2016:23:07:05 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
D [09/Nov/2016:23:07:05 +0100] Using keychain "/etc/cups/ssl" for server name "tierramedia".
I [09/Nov/2016:23:07:05 +0100] Using default TempDir of /var/spool/cups/tmp...
I [09/Nov/2016:23:07:05 +0100] Configured for up to 100 clients.
I [09/Nov/2016:23:07:05 +0100] Allowing up to 100 client connections per host.
I [09/Nov/2016:23:07:05 +0100] Using policy "default" as the default.
I [09/Nov/2016:23:07:05 +0100] Full reload is required.
I [09/Nov/2016:23:07:05 +0100] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 49 types, 80 filters...
D [09/Nov/2016:23:07:05 +0100] Loading printer Canon_MP495_series...
D [09/Nov/2016:23:07:05 +0100] load_ppd: Loading /var/cache/cups/Canon_MP495_series.data...
D [09/Nov/2016:23:07:05 +0100] cupsdRegisterPrinter(p=0x801a1770(Canon_MP495_series))
I [09/Nov/2016:23:07:05 +0100] Loading job cache file "/var/cache/cups/job.cache"...
D [09/Nov/2016:23:07:05 +0100] [Job 31] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 34] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 35] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 36] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 37] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 38] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 39] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 40] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 45] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 48] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 49] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 50] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 51] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 51] Loading attributes...
D [09/Nov/2016:23:07:05 +0100] [Job 51] Unloading...
D [09/Nov/2016:23:07:05 +0100] [Job 52] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 52] Loading attributes...
D [09/Nov/2016:23:07:05 +0100] [Job 52] Unloading...
D [09/Nov/2016:23:07:05 +0100] [Job 53] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 53] Loading attributes...
D [09/Nov/2016:23:07:05 +0100] [Job 53] Unloading...
D [09/Nov/2016:23:07:05 +0100] [Job 54] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 54] Loading attributes...
D [09/Nov/2016:23:07:05 +0100] [Job 54] Unloading...
D [09/Nov/2016:23:07:05 +0100] [Job 55] Loading from cache...
D [09/Nov/2016:23:07:05 +0100] [Job 55] Loading attributes...
D [09/Nov/2016:23:07:05 +0100] [Job 55] Unloading...
D [09/Nov/2016:23:07:05 +0100] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
D [09/Nov/2016:23:07:05 +0100] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
I [09/Nov/2016:23:07:05 +0100] Full reload complete.
D [09/Nov/2016:23:07:05 +0100] cupsdCleanFiles(path="/var/spool/cups/tmp", pattern="(null)")
I [09/Nov/2016:23:07:05 +0100] Cleaning out old files in "/var/spool/cups/tmp".
D [09/Nov/2016:23:07:05 +0100] cupsdCleanFiles(path="/var/cache/cups", pattern="*.ipp")
I [09/Nov/2016:23:07:05 +0100] Cleaning out old files in "/var/cache/cups".
D [09/Nov/2016:23:07:05 +0100] service_checkin: pid=20224
D [09/Nov/2016:23:07:05 +0100] service_checkin: 1 listeners.
D [09/Nov/2016:23:07:05 +0100] service_add_listener: Listener #1 at fd 3, "/run/cups/cups.sock".
D [09/Nov/2016:23:07:05 +0100] service_add_listener: Matched existing listener #1 to /run/cups/cups.sock.
D [09/Nov/2016:23:07:05 +0100] Creating keep-alive file "/var/cache/cups/org.cups.cupsd".
D [09/Nov/2016:23:07:05 +0100] Calling FindDeviceById(cups-Canon_MP495_series)
D [09/Nov/2016:23:07:05 +0100] FindDeviceById failed: org.freedesktop.ColorManager.NotFound:device id \'cups-Canon_MP495_series\' does not exist
D [09/Nov/2016:23:07:05 +0100] Using profile ID "Canon_MP495_series-Gray..".
D [09/Nov/2016:23:07:05 +0100] Calling CreateProfile(Canon_MP495_series-Gray..,temp)
D [09/Nov/2016:23:07:05 +0100] Created profile "/org/freedesktop/ColorManager/profiles/Canon_MP495_series_Gray__".
D [09/Nov/2016:23:07:05 +0100] Using profile ID "Canon_MP495_series-RGB..".
D [09/Nov/2016:23:07:05 +0100] Calling CreateProfile(Canon_MP495_series-RGB..,temp)
D [09/Nov/2016:23:07:05 +0100] Created profile "/org/freedesktop/ColorManager/profiles/Canon_MP495_series_RGB__".
I [09/Nov/2016:23:07:05 +0100] Registering ICC color profiles for "Canon_MP495_series".
D [09/Nov/2016:23:07:05 +0100] Calling CreateDevice(cups-Canon_MP495_series,temp)
D [09/Nov/2016:23:07:05 +0100] Created device "/org/freedesktop/ColorManager/devices/cups_Canon_MP495_series".
D [09/Nov/2016:23:07:05 +0100] Calling /org/freedesktop/ColorManager/devices/cups_Canon_MP495_series:AddProfile(/org/freedesktop/ColorManager/profiles/Canon_MP495_series_Gray__) [soft]
D [09/Nov/2016:23:07:05 +0100] Calling /org/freedesktop/ColorManager/devices/cups_Canon_MP495_series:AddProfile(/org/freedesktop/ColorManager/profiles/Canon_MP495_series_RGB__) [soft]
I [09/Nov/2016:23:07:05 +0100] Listening to [v1.::1]:631 on fd 11...
I [09/Nov/2016:23:07:05 +0100] Listening to 127.0.0.1:631 on fd 12...
I [09/Nov/2016:23:07:05 +0100] Listening to /run/cups/cups.sock on fd 3...
I [09/Nov/2016:23:07:05 +0100] Resuming new connection processing...
D [09/Nov/2016:23:07:05 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [09/Nov/2016:23:07:05 +0100] cupsdAddCert: Adding certificate for PID 0
D [09/Nov/2016:23:07:05 +0100] Discarding unused server-started event...
D [09/Nov/2016:23:07:05 +0100] [Client 1] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:05 +0100] [Client 1] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:05 +0100] [Client 1] Waiting for request.
D [09/Nov/2016:23:07:05 +0100] Report: clients=1
D [09/Nov/2016:23:07:05 +0100] Report: jobs=17
D [09/Nov/2016:23:07:05 +0100] Report: jobs-active=0
D [09/Nov/2016:23:07:05 +0100] Report: printers=1
D [09/Nov/2016:23:07:05 +0100] Report: stringpool-string-count=5058
D [09/Nov/2016:23:07:05 +0100] Report: stringpool-alloc-bytes=8392
D [09/Nov/2016:23:07:05 +0100] Report: stringpool-total-bytes=93184
D [09/Nov/2016:23:07:06 +0100] [Client 2] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:06 +0100] [Client 2] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:06 +0100] [Client 2] Waiting for request.
I [09/Nov/2016:23:07:06 +0100] Expiring subscriptions...
I [09/Nov/2016:23:07:07 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:08 +0100] [Client 2] POST / HTTP/1.1
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=200
D [09/Nov/2016:23:07:08 +0100] [Client 2] No authentication data provided.
I [09/Nov/2016:23:07:08 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] 2.0 Get-Jobs 20
D [09/Nov/2016:23:07:08 +0100] Get-Jobs ipp://localhost/printers/
D [09/Nov/2016:23:07:08 +0100] [Client 2] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [09/Nov/2016:23:07:08 +0100] [Client 2] Content-Length: 75
D [09/Nov/2016:23:07:08 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:08 +0100] [Client 2] con->http=0x802427d8
D [09/Nov/2016:23:07:08 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x8023a1e0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:08 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:08 +0100] [Client 2] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:07:08 +0100] [Client 2] Flushing write buffer.
D [09/Nov/2016:23:07:08 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:08 +0100] [Client 2] Waiting for request.
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [09/Nov/2016:23:07:08 +0100] [Client 2] POST / HTTP/1.1
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=200
D [09/Nov/2016:23:07:08 +0100] [Client 2] No authentication data provided.
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] 2.0 Get-Jobs 21
D [09/Nov/2016:23:07:08 +0100] Get-Jobs ipp://localhost/printers/
I [09/Nov/2016:23:07:08 +0100] [Client 2] Limiting Get-Jobs response to 500 jobs.
D [09/Nov/2016:23:07:08 +0100] [Job 55] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 54] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 53] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 52] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 51] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 50] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 49] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 48] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 45] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 40] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 39] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 38] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 37] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 36] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 35] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 34] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Job 31] Loading attributes...
D [09/Nov/2016:23:07:08 +0100] [Client 2] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [09/Nov/2016:23:07:08 +0100] [Client 2] Content-Length: 1760
D [09/Nov/2016:23:07:08 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:08 +0100] [Job 31] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [09/Nov/2016:23:07:08 +0100] [Job 34] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 35] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 36] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 37] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 38] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 39] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 40] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 45] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 48] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 49] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Job 50] Removing document files.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Client 2] con->http=0x802427d8
D [09/Nov/2016:23:07:08 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1760, response=0x8023a2b8(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:08 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:08 +0100] [Client 2] bytes=0, http_state=0, data_remaining=1760
D [09/Nov/2016:23:07:08 +0100] [Client 2] Flushing write buffer.
D [09/Nov/2016:23:07:08 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:08 +0100] [Client 2] Waiting for request.
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Client 2] POST / HTTP/1.1
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=200
D [09/Nov/2016:23:07:08 +0100] [Client 2] No authentication data provided.
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:08 +0100] [Client 2] 2.0 Create-Printer-Subscriptions 22
D [09/Nov/2016:23:07:08 +0100] Create-Printer-Subscriptions /
D [09/Nov/2016:23:07:08 +0100] create_subscriptions(con=0x8023cfc8(2), uri="/")
D [09/Nov/2016:23:07:08 +0100] pullmethod="ippget"
D [09/Nov/2016:23:07:08 +0100] notify-lease-duration=86400
D [09/Nov/2016:23:07:08 +0100] notify-time-interval=0
D [09/Nov/2016:23:07:08 +0100] cupsdAddSubscription(mask=17800, dest=(nil)(), job=(nil)(0), uri="(null)")
D [09/Nov/2016:23:07:08 +0100] Added subscription #28 for server.
D [09/Nov/2016:23:07:08 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:08 +0100] [Client 2] Returning IPP successful-ok for Create-Printer-Subscriptions (/) from localhost
D [09/Nov/2016:23:07:08 +0100] [Client 2] Content-Length: 107
D [09/Nov/2016:23:07:08 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:08 +0100] [Client 2] con->http=0x802427d8
D [09/Nov/2016:23:07:08 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=107, response=0x8023ae08(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:08 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:08 +0100] [Client 2] bytes=0, http_state=0, data_remaining=107
D [09/Nov/2016:23:07:08 +0100] [Client 2] Flushing write buffer.
D [09/Nov/2016:23:07:08 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:08 +0100] [Client 2] Waiting for request.
D [09/Nov/2016:23:07:08 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [09/Nov/2016:23:07:09 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:10 +0100] [Client 3] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 3] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 3] Waiting for request.
I [09/Nov/2016:23:07:10 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:10 +0100] [Client 3] POST /printers/Canon%5FMP495%5Fseries HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 3] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=100
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=100
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=100
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=100
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=100
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=100
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=100
D [09/Nov/2016:23:07:10 +0100] [Client 3] 2.0 Print-Job 23
D [09/Nov/2016:23:07:10 +0100] [Client 3] Read: status=100
D [09/Nov/2016:23:07:10 +0100] Print-Job ipp://localhost/printers/Canon%5FMP495%5Fseries
D [09/Nov/2016:23:07:10 +0100] [Job ???] Auto-typing file...
I [09/Nov/2016:23:07:10 +0100] [Job ???] Request file type is application/vnd.cups-pdf-banner.
D [09/Nov/2016:23:07:10 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:10 +0100] add_job: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:10 +0100] Adding default job-sheets values "none,none"...
I [09/Nov/2016:23:07:10 +0100] [Job 56] Adding start banner page "none".
D [09/Nov/2016:23:07:10 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:10 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [09/Nov/2016:23:07:10 +0100] [Job 56] Adding end banner page "none".
I [09/Nov/2016:23:07:10 +0100] [Job 56] File of type application/vnd.cups-pdf-banner queued by "mithrandir".
D [09/Nov/2016:23:07:10 +0100] [Job 56] hold_until=0
I [09/Nov/2016:23:07:10 +0100] [Job 56] Queued on "Canon_MP495_series" by "mithrandir".
D [09/Nov/2016:23:07:10 +0100] [Job 56] time-at-processing=1478729230
D [09/Nov/2016:23:07:10 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:10 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Job 56] 4 filters for job:
D [09/Nov/2016:23:07:10 +0100] [Job 56] bannertopdf (application/vnd.cups-pdf-banner to application/pdf, cost 32)
D [09/Nov/2016:23:07:10 +0100] [Job 56] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [09/Nov/2016:23:07:10 +0100] [Job 56] pdftops (application/vnd.cups-pdf to application/vnd.cups-postscript, cost 100)
D [09/Nov/2016:23:07:10 +0100] [Job 56] pstocanonij (application/vnd.cups-postscript to printer/Canon_MP495_series, cost 0)
D [09/Nov/2016:23:07:10 +0100] [Job 56] job-sheets=none,none
D [09/Nov/2016:23:07:10 +0100] [Job 56] argv[0]="Canon_MP495_series"
D [09/Nov/2016:23:07:10 +0100] [Job 56] argv[1]="56"
D [09/Nov/2016:23:07:10 +0100] [Job 56] argv[2]="mithrandir"
D [09/Nov/2016:23:07:10 +0100] [Job 56] argv[3]="Test Page"
D [09/Nov/2016:23:07:10 +0100] [Job 56] argv[4]="1"
D [09/Nov/2016:23:07:10 +0100] [Job 56] argv[5]="job-uuid=urn:uuid:8394503c-a620-3f12-4b93-7b86c69b3450 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1478729230 time-at-processing=1478729230"
D [09/Nov/2016:23:07:10 +0100] [Job 56] argv[6]="/var/spool/cups/d00056-001"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[7]="CUPS_STATEDIR=/run/cups"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[8]="HOME=/var/spool/cups/tmp"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[10]="SERVER_ADMIN=root@tierramedia"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[11]="SOFTWARE=CUPS/2.2.1"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[13]="USER=root"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[14]="CUPS_MAX_MESSAGE=2047"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[17]="IPP_PORT=631"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[18]="CHARSET=utf-8"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[19]="LANG=es_ES.UTF-8"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[20]="PPD=/etc/cups/ppd/Canon_MP495_series.ppd"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[21]="RIP_MAX_CACHE=128m"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[22]="CONTENT_TYPE=application/vnd.cups-pdf-banner"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[23]="DEVICE_URI=cnijusb:/dev/usb/lp0"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[24]="PRINTER_INFO=Canon MP495 series"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[25]="PRINTER_LOCATION=bibl"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[26]="PRINTER=Canon_MP495_series"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[27]="PRINTER_STATE_REASONS=none"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[28]="CUPS_FILETYPE=document"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-postscript"
D [09/Nov/2016:23:07:10 +0100] [Job 56] envp[30]="AUTH_I****"
I [09/Nov/2016:23:07:10 +0100] [Job 56] Started filter /usr/lib/cups/filter/bannertopdf (PID 20238)
I [09/Nov/2016:23:07:10 +0100] [Job 56] Started filter /usr/lib/cups/filter/pdftopdf (PID 20239)
I [09/Nov/2016:23:07:10 +0100] [Job 56] Started filter /usr/lib/cups/filter/pdftops (PID 20240)
I [09/Nov/2016:23:07:10 +0100] [Job 56] Started filter /usr/lib/cups/filter/pstocanonij (PID 20241)
I [09/Nov/2016:23:07:10 +0100] [Job 56] Started backend /usr/lib/cups/backend/cnijusb (PID 20242)
D [09/Nov/2016:23:07:10 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 3] Returning IPP successful-ok for Print-Job (ipp://localhost/printers/Canon%5FMP495%5Fseries) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 3] Content-Length: 192
D [09/Nov/2016:23:07:10 +0100] [Client 3] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 3] con->http=0x8024be80
D [09/Nov/2016:23:07:10 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=192, response=0x801b4090(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 3] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 3] bytes=0, http_state=0, data_remaining=192
D [09/Nov/2016:23:07:10 +0100] [Client 3] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 3] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 3] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Job 56] (cnijusb)p_ppd->model_number=(369)
D [09/Nov/2016:23:07:10 +0100] [Job 56] (Canon) langage moniter[/usr/local/bin/lgmonmp495 --gui --cups] start!
D [09/Nov/2016:23:07:10 +0100] [Job 56] pstocanonij start.
D [09/Nov/2016:23:07:10 +0100] [Job 56] pdftops - copying to temp print file \"/var/spool/cups/tmp/04f10582a913e\"
D [09/Nov/2016:23:07:10 +0100] [Job 56] pdftopdf: Last filter determined by the PPD: pstocanonij; FINAL_CONTENT_TYPE: application/vnd.cups-postscript => pdftopdf will not log pages in page_log.
D [09/Nov/2016:23:07:10 +0100] [Job 56] PDF template file doesn\'t have form. It\'s okay.
D [09/Nov/2016:23:07:10 +0100] [Job 56] PID 20238 (/usr/lib/cups/filter/bannertopdf) exited with no errors.
D [09/Nov/2016:23:07:10 +0100] [Job 56] Printer make and model: Canon mp495
D [09/Nov/2016:23:07:10 +0100] [Job 56] Running command line for pstops: pstops 56 mithrandir \'Test Page\' 1 \'job-uuid=urn:uuid:8394503c-a620-3f12-4b93-7b86c69b3450 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1478729230 time-at-processing=1478729230\'
D [09/Nov/2016:23:07:10 +0100] [Job 56] Using image rendering resolution 600 dpi
D [09/Nov/2016:23:07:10 +0100] [Job 56] Running command line for gs: gs -q -dNOPAUSE -dBATCH -dSAFER -dNOMEDIAATTRS -sDEVICE=ps2write -sOUTPUTFILE=%stdout -dLanguageLevel=3 -r600 -dCompressFonts=false -dNoT3CCITT -dNOINTERPOLATE -c \'save pop\' -f /var/spool/cups/tmp/04f10582a913e
D [09/Nov/2016:23:07:10 +0100] [Job 56] Started filter gs (PID 20246)
D [09/Nov/2016:23:07:10 +0100] [Job 56] Started filter pstops (PID 20247)
D [09/Nov/2016:23:07:10 +0100] [Job 56] PID 20239 (/usr/lib/cups/filter/pdftopdf) exited with no errors.
D [09/Nov/2016:23:07:10 +0100] [Client 4] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 4] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 4] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] [Client 5] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 5] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 5] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] [Client 4] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 4] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 4] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 4] 2.0 Get-Jobs 22
D [09/Nov/2016:23:07:10 +0100] Get-Jobs ipp://localhost/printers/
D [09/Nov/2016:23:07:10 +0100] [Client 4] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 4] Content-Length: 75
D [09/Nov/2016:23:07:10 +0100] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 6] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 6] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 6] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] [Client 4] con->http=0x80251588
D [09/Nov/2016:23:07:10 +0100] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x80258b70(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 4] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:07:10 +0100] [Client 4] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 4] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 4] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 5] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 5] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 5] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 5] 2.0 Get-Notifications 58
D [09/Nov/2016:23:07:10 +0100] Get-Notifications /
D [09/Nov/2016:23:07:10 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:10 +0100] [Client 5] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 5] Content-Length: 1635
D [09/Nov/2016:23:07:10 +0100] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 4] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:10 +0100] [Client 4] Closing connection.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 5] con->http=0x80255968
D [09/Nov/2016:23:07:10 +0100] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1635, response=0x8024b3e0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 5] bytes=0, http_state=0, data_remaining=1635
D [09/Nov/2016:23:07:10 +0100] [Client 5] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 5] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 5] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 6] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 6] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 6] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 6] 2.0 Get-Notifications 24
D [09/Nov/2016:23:07:10 +0100] Get-Notifications /
D [09/Nov/2016:23:07:10 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:10 +0100] [Client 6] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 6] Content-Length: 579
D [09/Nov/2016:23:07:10 +0100] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 5] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 5] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 5] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 5] 2.0 Get-Job-Attributes 59
D [09/Nov/2016:23:07:10 +0100] Get-Job-Attributes ipp://localhost/jobs/56
D [09/Nov/2016:23:07:10 +0100] [Client 5] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/56) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 5] Content-Length: 989
D [09/Nov/2016:23:07:10 +0100] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 6] con->http=0x80259e78
D [09/Nov/2016:23:07:10 +0100] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=579, response=0x80258b70(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 6] bytes=0, http_state=0, data_remaining=579
D [09/Nov/2016:23:07:10 +0100] [Client 6] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 6] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 6] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 5] con->http=0x80255968
D [09/Nov/2016:23:07:10 +0100] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=989, response=0x8025d078(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 5] bytes=0, http_state=0, data_remaining=989
D [09/Nov/2016:23:07:10 +0100] [Client 5] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 5] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 5] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:10 +0100] [Client 6] Closing connection.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 2] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 2] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 2] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 2] 2.0 Get-Notifications 25
D [09/Nov/2016:23:07:10 +0100] Get-Notifications /
D [09/Nov/2016:23:07:10 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:10 +0100] [Client 2] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 2] Content-Length: 1183
D [09/Nov/2016:23:07:10 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 2] con->http=0x802427d8
D [09/Nov/2016:23:07:10 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1183, response=0x8025d270(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 2] bytes=0, http_state=0, data_remaining=1183
D [09/Nov/2016:23:07:10 +0100] [Client 2] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 2] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 7] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 7] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 7] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] [Client 7] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 7] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 7] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 7] 2.0 Get-Printer-Attributes 60
D [09/Nov/2016:23:07:10 +0100] Get-Printer-Attributes 
D [09/Nov/2016:23:07:10 +0100] Get-Printer-Attributes client-error-not-found: La impresora o clase no existe.
D [09/Nov/2016:23:07:10 +0100] [Client 7] Returning IPP client-error-not-found for Get-Printer-Attributes () from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 7] Content-Length: 125
D [09/Nov/2016:23:07:10 +0100] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 7] con->http=0x80251588
D [09/Nov/2016:23:07:10 +0100] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=125, response=0x80258b88(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 7] bytes=0, http_state=0, data_remaining=125
D [09/Nov/2016:23:07:10 +0100] [Client 7] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 7] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 7] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:10 +0100] [Client 7] Closing connection.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 8] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 8] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 8] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] [Client 8] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 8] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 8] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 8] 2.0 Get-Job-Attributes 61
D [09/Nov/2016:23:07:10 +0100] Get-Job-Attributes ipp://localhost/jobs/56
D [09/Nov/2016:23:07:10 +0100] [Client 8] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/56) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 8] Content-Length: 182
D [09/Nov/2016:23:07:10 +0100] [Client 8] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 8] con->http=0x80251588
D [09/Nov/2016:23:07:10 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=182, response=0x80258ba0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 8] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 8] bytes=0, http_state=0, data_remaining=182
D [09/Nov/2016:23:07:10 +0100] [Client 8] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 8] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 8] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 8] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:10 +0100] [Client 8] Closing connection.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 9] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 9] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 9] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] [Client 9] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 9] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 9] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 9] 2.0 Get-Job-Attributes 62
D [09/Nov/2016:23:07:10 +0100] Get-Job-Attributes ipp://localhost/jobs/56
D [09/Nov/2016:23:07:10 +0100] [Client 9] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/56) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 9] Content-Length: 101
D [09/Nov/2016:23:07:10 +0100] [Client 9] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 9] con->http=0x80251588
D [09/Nov/2016:23:07:10 +0100] [Client 9] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x80258ba0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 9] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 9] bytes=0, http_state=0, data_remaining=101
D [09/Nov/2016:23:07:10 +0100] [Client 9] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 9] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 9] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 9] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:10 +0100] [Client 9] Closing connection.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 10] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 10] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 10] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] [Client 10] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 10] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 10] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 10] 2.0 Get-Job-Attributes 63
D [09/Nov/2016:23:07:10 +0100] Get-Job-Attributes ipp://localhost/jobs/56
D [09/Nov/2016:23:07:10 +0100] [Client 10] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/56) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 10] Content-Length: 101
D [09/Nov/2016:23:07:10 +0100] [Client 10] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 10] con->http=0x80251588
D [09/Nov/2016:23:07:10 +0100] [Client 10] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x80258ba0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 10] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 10] bytes=0, http_state=0, data_remaining=101
D [09/Nov/2016:23:07:10 +0100] [Client 10] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 10] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 10] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 10] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:10 +0100] [Client 10] Closing connection.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 5] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:10 +0100] [Client 5] Closing connection.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 11] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:10 +0100] [Client 11] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:10 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 11] 2.0 CUPS-Get-Printers 26
D [09/Nov/2016:23:07:10 +0100] CUPS-Get-Printers
D [09/Nov/2016:23:07:10 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 11] Content-Length: 451
D [09/Nov/2016:23:07:10 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:10 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=451, response=0x801b40b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 11] bytes=0, http_state=0, data_remaining=451
D [09/Nov/2016:23:07:10 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 11] 2.0 CUPS-Get-Classes 27
D [09/Nov/2016:23:07:10 +0100] CUPS-Get-Classes
D [09/Nov/2016:23:07:10 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Classes (no URI) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 11] Content-Length: 75
D [09/Nov/2016:23:07:10 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:10 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x80254a20(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 11] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:07:10 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:10 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:10 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:10 +0100] [Client 11] 2.0 CUPS-Get-Default 28
D [09/Nov/2016:23:07:10 +0100] CUPS-Get-Default
D [09/Nov/2016:23:07:10 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [09/Nov/2016:23:07:10 +0100] [Client 11] Content-Length: 11055
D [09/Nov/2016:23:07:10 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:10 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:10 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11055, response=0x801b40b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:10 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:10 +0100] [Client 11] bytes=0, http_state=0, data_remaining=11055
D [09/Nov/2016:23:07:10 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:10 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:10 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:10 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
I [09/Nov/2016:23:07:11 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:12 +0100] [Job 56] STS:USB MP495           00 IVFLFE 040 B 100                                      E                             4           
D [09/Nov/2016:23:07:12 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Job 56] Set job-printer-state-message to "STS:USB MP495           00 IVFLFE 040 B 100                                      E                             4           ", current level=INFO
D [09/Nov/2016:23:07:12 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [09/Nov/2016:23:07:12 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:12 +0100] [Job 56] STS:USB MP495           00 IVFLFE 040 B 100                                      E                             4           
D [09/Nov/2016:23:07:12 +0100] [Client 12] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:12 +0100] [Client 12] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:12 +0100] [Client 12] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] [Client 13] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:12 +0100] [Client 13] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:12 +0100] [Client 13] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] [Client 12] POST / HTTP/1.1
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 12] Read: status=200
D [09/Nov/2016:23:07:12 +0100] [Client 12] No authentication data provided.
D [09/Nov/2016:23:07:12 +0100] [Client 12] 2.0 Get-Notifications 64
D [09/Nov/2016:23:07:12 +0100] Get-Notifications /
D [09/Nov/2016:23:07:12 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:12 +0100] [Client 12] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:12 +0100] [Client 12] Content-Length: 1204
D [09/Nov/2016:23:07:12 +0100] [Client 12] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:12 +0100] [Client 14] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:12 +0100] [Client 14] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:12 +0100] [Client 14] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] [Client 12] con->http=0x80258128
D [09/Nov/2016:23:07:12 +0100] [Client 12] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1204, response=0x80255c68(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:12 +0100] [Client 12] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:12 +0100] [Client 12] bytes=0, http_state=0, data_remaining=1204
D [09/Nov/2016:23:07:12 +0100] [Client 12] Flushing write buffer.
D [09/Nov/2016:23:07:12 +0100] [Client 12] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:12 +0100] [Client 12] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 13] POST / HTTP/1.1
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 13] Read: status=200
D [09/Nov/2016:23:07:12 +0100] [Client 13] No authentication data provided.
D [09/Nov/2016:23:07:12 +0100] [Client 13] 2.0 Get-Jobs 23
D [09/Nov/2016:23:07:12 +0100] Get-Jobs ipp://localhost/printers/
D [09/Nov/2016:23:07:12 +0100] [Client 13] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [09/Nov/2016:23:07:12 +0100] [Client 13] Content-Length: 75
D [09/Nov/2016:23:07:12 +0100] [Client 13] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:12 +0100] [Client 15] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:12 +0100] [Client 15] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:12 +0100] [Client 15] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] [Client 13] con->http=0x8025d818
D [09/Nov/2016:23:07:12 +0100] [Client 13] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x802564e8(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:12 +0100] [Client 13] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:12 +0100] [Client 13] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:07:12 +0100] [Client 13] Flushing write buffer.
D [09/Nov/2016:23:07:12 +0100] [Client 13] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:12 +0100] [Client 13] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 14] POST / HTTP/1.1
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 14] Read: status=200
D [09/Nov/2016:23:07:12 +0100] [Client 14] No authentication data provided.
D [09/Nov/2016:23:07:12 +0100] [Client 14] 2.0 Get-Notifications 29
D [09/Nov/2016:23:07:12 +0100] Get-Notifications /
D [09/Nov/2016:23:07:12 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:12 +0100] [Client 14] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:12 +0100] [Client 14] Content-Length: 565
D [09/Nov/2016:23:07:12 +0100] [Client 14] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:12 +0100] [Client 13] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:12 +0100] [Client 13] Closing connection.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 14] con->http=0x80260978
D [09/Nov/2016:23:07:12 +0100] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=565, response=0x80255c68(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:12 +0100] [Client 14] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:12 +0100] [Client 14] bytes=0, http_state=0, data_remaining=565
D [09/Nov/2016:23:07:12 +0100] [Client 14] Flushing write buffer.
D [09/Nov/2016:23:07:12 +0100] [Client 14] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:12 +0100] [Client 14] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 15] POST / HTTP/1.1
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 15] Read: status=200
D [09/Nov/2016:23:07:12 +0100] [Client 15] No authentication data provided.
D [09/Nov/2016:23:07:12 +0100] [Client 15] 2.0 Get-Job-Attributes 65
D [09/Nov/2016:23:07:12 +0100] Get-Job-Attributes ipp://localhost/jobs/56
D [09/Nov/2016:23:07:12 +0100] [Client 15] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/56) from localhost
D [09/Nov/2016:23:07:12 +0100] [Client 15] Content-Length: 101
D [09/Nov/2016:23:07:12 +0100] [Client 15] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:12 +0100] [Client 14] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:12 +0100] [Client 14] Closing connection.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 15] con->http=0x80264c50
D [09/Nov/2016:23:07:12 +0100] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=101, response=0x802564e8(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:12 +0100] [Client 15] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:12 +0100] [Client 15] bytes=0, http_state=0, data_remaining=101
D [09/Nov/2016:23:07:12 +0100] [Client 15] Flushing write buffer.
D [09/Nov/2016:23:07:12 +0100] [Client 15] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:12 +0100] [Client 15] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 2] POST / HTTP/1.1
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 2] Read: status=200
D [09/Nov/2016:23:07:12 +0100] [Client 2] No authentication data provided.
D [09/Nov/2016:23:07:12 +0100] [Client 2] 2.0 Get-Notifications 30
D [09/Nov/2016:23:07:12 +0100] Get-Notifications /
D [09/Nov/2016:23:07:12 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:12 +0100] [Client 2] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:12 +0100] [Client 2] Content-Length: 766
D [09/Nov/2016:23:07:12 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:12 +0100] [Client 15] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:12 +0100] [Client 15] Closing connection.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 2] con->http=0x802427d8
D [09/Nov/2016:23:07:12 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=766, response=0x80255c68(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:12 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:12 +0100] [Client 2] bytes=0, http_state=0, data_remaining=766
D [09/Nov/2016:23:07:12 +0100] [Client 2] Flushing write buffer.
D [09/Nov/2016:23:07:12 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:12 +0100] [Client 2] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 12] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:12 +0100] [Client 12] Closing connection.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:12 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:12 +0100] [Client 11] 2.0 CUPS-Get-Printers 31
D [09/Nov/2016:23:07:12 +0100] CUPS-Get-Printers
D [09/Nov/2016:23:07:12 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [09/Nov/2016:23:07:12 +0100] [Client 11] Content-Length: 574
D [09/Nov/2016:23:07:12 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:12 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:12 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=574, response=0x802564e8(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:12 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:12 +0100] [Client 11] bytes=0, http_state=0, data_remaining=574
D [09/Nov/2016:23:07:12 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:12 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:12 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:12 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:12 +0100] [Client 11] 2.0 CUPS-Get-Classes 32
D [09/Nov/2016:23:07:12 +0100] CUPS-Get-Classes
D [09/Nov/2016:23:07:12 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Classes (no URI) from localhost
D [09/Nov/2016:23:07:12 +0100] [Client 11] Content-Length: 75
D [09/Nov/2016:23:07:12 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:12 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:12 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x802565a8(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:12 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:12 +0100] [Client 11] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:07:12 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:12 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:12 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:12 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:12 +0100] [Client 11] 2.0 CUPS-Get-Default 33
D [09/Nov/2016:23:07:12 +0100] CUPS-Get-Default
D [09/Nov/2016:23:07:12 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [09/Nov/2016:23:07:12 +0100] [Client 11] Content-Length: 11178
D [09/Nov/2016:23:07:12 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:12 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:12 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11178, response=0x802564e8(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:12 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:12 +0100] [Client 11] bytes=0, http_state=0, data_remaining=11178
D [09/Nov/2016:23:07:12 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:12 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:12 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:12 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [09/Nov/2016:23:07:12 +0100] [Job 56] STS:USB MP495           00 IVFLFE 040 B 100                                      E                             4           
I [09/Nov/2016:23:07:13 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:14 +0100] [Job 56] STS:USB MP495           00 IVFLFE 040 B 100                                      E                             4           
I [09/Nov/2016:23:07:14 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:15 +0100] [Job 56] Page = 595x842; 10,14 to 586,833
I [09/Nov/2016:23:07:15 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:15 +0100] [Job 56] slow_collate=0, slow_duplex=0, slow_order=0
D [09/Nov/2016:23:07:15 +0100] [Job 56] Before copy_comments - %!PS-Adobe-3.0
D [09/Nov/2016:23:07:15 +0100] [Job 56] %!PS-Adobe-3.0
D [09/Nov/2016:23:07:15 +0100] [Job 56] %%BoundingBox: 0 0 595 842
D [09/Nov/2016:23:07:15 +0100] [Job 56] %%HiResBoundingBox: 0 0 595.00 842.00
D [09/Nov/2016:23:07:15 +0100] [Job 56] %%Creator: GPL Ghostscript 920 (ps2write)
D [09/Nov/2016:23:07:15 +0100] [Job 56] %%LanguageLevel: 2
D [09/Nov/2016:23:07:15 +0100] [Job 56] %%CreationDate: D:20161109230710+01\'00\'
D [09/Nov/2016:23:07:15 +0100] [Job 56] %%Pages: 1
D [09/Nov/2016:23:07:15 +0100] [Job 56] %%EndComments
D [09/Nov/2016:23:07:15 +0100] [Job 56] Before copy_prolog - %%BeginProlog
D [09/Nov/2016:23:07:15 +0100] [Job 56] Before copy_setup - %%Page: 1 1
D [09/Nov/2016:23:07:15 +0100] [Job 56] Before page loop - %%Page: 1 1
D [09/Nov/2016:23:07:15 +0100] [Job 56] Copying page 1...
D [09/Nov/2016:23:07:15 +0100] [Job 56] pagew = 576.0, pagel = 819.2
D [09/Nov/2016:23:07:15 +0100] [Job 56] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [09/Nov/2016:23:07:15 +0100] [Job 56] PageLeft = 9.6, PageRight = 585.6
D [09/Nov/2016:23:07:15 +0100] [Job 56] PageTop = 833.4, PageBottom = 14.2
D [09/Nov/2016:23:07:15 +0100] [Job 56] PageWidth = 595.0, PageLength = 842.0
D [09/Nov/2016:23:07:15 +0100] [Job 56] device_uri=(cnijusb:/dev/usb/lp0)
D [09/Nov/2016:23:07:15 +0100] [Job 56] p_ppd->model_number=(369)
D [09/Nov/2016:23:07:15 +0100] [Job 56] #  p_size->name=A4 , p_size_default->name = A4 #
D [09/Nov/2016:23:07:15 +0100] [Job 56] ### num_opt(lpr optins) = 6 ###
D [09/Nov/2016:23:07:15 +0100] [Job 56] # ppdPageSize width=595.000000 height=842.000000 ###
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:A4 210.0x297.0mm /  A4)
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : choice=A4(p_table->ppd_key=PageSize)
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:Plain Paper /  plain)
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : choice=plain(p_table->ppd_key=MediaType)
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:Rear Tray /  asf)
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : choice=asf(p_table->ppd_key=InputSlot)
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNCartridge is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNQuality is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNHalftoning is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNRenderIntent is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNGamma is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNBalanceC is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNBalanceM is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNBalanceY is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNDensity is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNGrayscale is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNCopies is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNContrast is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : CNInkCartridgeSettings is not found in p_ppd
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : p_choice found in p_ppd (p_choice:2 /  2)
D [09/Nov/2016:23:07:15 +0100] [Job 56] (3)Make cif options : choice=2(p_table->ppd_key=CNExtension)
D [09/Nov/2016:23:07:15 +0100] [Job 56] ### lpr optins(5) : date-time-at-creation= ###
D [09/Nov/2016:23:07:15 +0100] [Job 56] ### lpr optins(4) : date-time-at-processing= ###
D [09/Nov/2016:23:07:15 +0100] [Job 56] ### lpr optins(3) : job-originating-host-name=localhost ###
D [09/Nov/2016:23:07:15 +0100] [Job 56] ### lpr optins(2) : job-uuid=urn:uuid:8394503c-a620-3f12-4b93-7b86c69b3450 ###
D [09/Nov/2016:23:07:15 +0100] [Job 56] ### lpr optins(1) : time-at-creation=1478729230 ###
D [09/Nov/2016:23:07:15 +0100] [Job 56] ### lpr optins(0) : time-at-processing=1478729230 ###
D [09/Nov/2016:23:07:15 +0100] [Job 56] make_filter_param_list: --bidi
D [09/Nov/2016:23:07:15 +0100] [Job 56] make_filter_param_list: --fit
D [09/Nov/2016:23:07:15 +0100] [Job 56] make_filter_param_list: --bbox
D [09/Nov/2016:23:07:15 +0100] [Job 56] make_filter_param_list: --extension
D [09/Nov/2016:23:07:15 +0100] [Job 56] make_filter_param_list: --paperload
D [09/Nov/2016:23:07:15 +0100] [Job 56] make_filter_param_list: --media
D [09/Nov/2016:23:07:15 +0100] [Job 56] make_filter_param_list: --papersize
D [09/Nov/2016:23:07:15 +0100] [Job 56] pstocanonij: /usr/bin/gs -r600 -g4958x7016 -q -dNOPROMPT -dSAFER -sDEVICE=ppmraw -sOutputFile=- -| /usr/local/bin/cifmp495 --imageres 600 --papersize a4 --media plain --paperload asf --bbox 9,14,586,834 --fit  --bidi  
D [09/Nov/2016:23:07:15 +0100] [Job 56] /usr/local/bin/cifmp495: error while loading shared libraries: libtiff.so.3: cannot open shared object file: No such file or directory
I [09/Nov/2016:23:07:16 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:16 +0100] [Job 56] STS:USB MP495           00 IVFLFE 040 B 100                                      E                             4           
D [09/Nov/2016:23:07:17 +0100] [Job 56] PID 20246 (gs) exited with no errors.
I [09/Nov/2016:23:07:17 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:17 +0100] [Job 56] Wrote 1 pages...
D [09/Nov/2016:23:07:17 +0100] [Job 56] PID 20240 (/usr/lib/cups/filter/pdftops) exited with no errors.
D [09/Nov/2016:23:07:17 +0100] [Job 56] PID 20247 (pstops) exited with no errors.
D [09/Nov/2016:23:07:17 +0100] [Job 56] PID 20241 (/usr/lib/cups/filter/pstocanonij) exited with no errors.
D [09/Nov/2016:23:07:17 +0100] [Job 56] STS:USB MP495           00 IVFLFE 040 B 100                                      E                             4           
D [09/Nov/2016:23:07:17 +0100] [Job 56] Set job-printer-state-message to "STS:USB MP495           00 IVFLFE 040 B 100                                      E                             4           ", current level=INFO
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 56] PID 20242 (/usr/lib/cups/backend/cnijusb) exited with no errors.
D [09/Nov/2016:23:07:17 +0100] [Job 56] time-at-completed=1478729237
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [09/Nov/2016:23:07:17 +0100] [Job 56] Job completed.
I [09/Nov/2016:23:07:17 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 31] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 34] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 35] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 36] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 37] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 38] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 39] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 40] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 45] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 48] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 49] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 50] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:17 +0100] [Job 56] Removing document files.
D [09/Nov/2016:23:07:17 +0100] cupsdMarkDirty(---J-)
D [09/Nov/2016:23:07:17 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 16] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:18 +0100] [Client 16] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:18 +0100] [Client 16] Waiting for request.
I [09/Nov/2016:23:07:18 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:18 +0100] [Job 56] Unloading...
D [09/Nov/2016:23:07:18 +0100] [Client 17] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:18 +0100] [Client 17] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:18 +0100] [Client 17] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] [Client 16] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 16] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 16] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 16] 2.0 Get-Notifications 66
D [09/Nov/2016:23:07:18 +0100] Get-Notifications /
D [09/Nov/2016:23:07:18 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:18 +0100] [Client 16] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 16] Content-Length: 2072
D [09/Nov/2016:23:07:18 +0100] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 16] con->http=0x80258de8
D [09/Nov/2016:23:07:18 +0100] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2072, response=0x8023f628(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 16] bytes=0, http_state=0, data_remaining=2072
D [09/Nov/2016:23:07:18 +0100] [Client 16] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 16] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 16] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 17] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 17] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 17] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 17] 2.0 Get-Jobs 24
D [09/Nov/2016:23:07:18 +0100] Get-Jobs ipp://localhost/printers/
D [09/Nov/2016:23:07:18 +0100] [Client 17] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 17] Content-Length: 75
D [09/Nov/2016:23:07:18 +0100] [Client 17] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 17] con->http=0x8025d818
D [09/Nov/2016:23:07:18 +0100] [Client 17] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x80256280(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 17] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 17] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:07:18 +0100] [Client 17] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 17] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 17] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 18] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:18 +0100] [Client 18] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:18 +0100] [Client 18] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] [Client 17] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:18 +0100] [Client 17] Closing connection.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 18] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 18] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 18] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 18] 2.0 Get-Job-Attributes 67
D [09/Nov/2016:23:07:18 +0100] Get-Job-Attributes ipp://localhost/jobs/56
D [09/Nov/2016:23:07:18 +0100] [Job 56] Loading attributes...
D [09/Nov/2016:23:07:18 +0100] [Client 18] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/56) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 18] Content-Length: 120
D [09/Nov/2016:23:07:18 +0100] [Client 18] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 18] con->http=0x80261af0
D [09/Nov/2016:23:07:18 +0100] [Client 18] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=120, response=0x8023f628(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 18] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 18] bytes=0, http_state=0, data_remaining=120
D [09/Nov/2016:23:07:18 +0100] [Client 18] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 18] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 18] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 19] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:18 +0100] [Client 19] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:18 +0100] [Client 19] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] [Client 18] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:18 +0100] [Client 18] Closing connection.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 20] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:18 +0100] [Client 20] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:18 +0100] [Client 20] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] [Client 19] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 19] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 19] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 19] 2.0 Get-Notifications 34
D [09/Nov/2016:23:07:18 +0100] Get-Notifications /
D [09/Nov/2016:23:07:18 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:18 +0100] [Client 19] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 19] Content-Length: 1011
D [09/Nov/2016:23:07:18 +0100] [Client 19] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 19] con->http=0x8025d818
D [09/Nov/2016:23:07:18 +0100] [Client 19] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1011, response=0x80256280(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 19] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 19] bytes=0, http_state=0, data_remaining=1011
D [09/Nov/2016:23:07:18 +0100] [Client 19] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 19] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 19] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 20] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 20] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 20] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 20] 2.0 Get-Printer-Attributes 68
D [09/Nov/2016:23:07:18 +0100] Get-Printer-Attributes ipp://tierramedia/printers/Canon_MP495_series
D [09/Nov/2016:23:07:18 +0100] [Client 20] Returning IPP successful-ok for Get-Printer-Attributes (ipp://tierramedia/printers/Canon_MP495_series) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 20] Content-Length: 111
D [09/Nov/2016:23:07:18 +0100] [Client 20] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 19] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:18 +0100] [Client 19] Closing connection.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 20] con->http=0x80261af0
D [09/Nov/2016:23:07:18 +0100] [Client 20] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=111, response=0x8023f628(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 20] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 20] bytes=0, http_state=0, data_remaining=111
D [09/Nov/2016:23:07:18 +0100] [Client 20] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 20] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 20] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 2] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 2] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 2] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 2] 2.0 Get-Notifications 35
D [09/Nov/2016:23:07:18 +0100] Get-Notifications /
D [09/Nov/2016:23:07:18 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:18 +0100] [Client 2] Returning IPP successful-ok for Get-Notifications (/) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 2] Content-Length: 1188
D [09/Nov/2016:23:07:18 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 2] con->http=0x802427d8
D [09/Nov/2016:23:07:18 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1188, response=0x80256280(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 2] bytes=0, http_state=0, data_remaining=1188
D [09/Nov/2016:23:07:18 +0100] [Client 2] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 2] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 16] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:18 +0100] [Client 16] Closing connection.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] 2.0 CUPS-Get-Printers 36
D [09/Nov/2016:23:07:18 +0100] CUPS-Get-Printers
D [09/Nov/2016:23:07:18 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 11] Content-Length: 451
D [09/Nov/2016:23:07:18 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:18 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=451, response=0x8023f628(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 11] bytes=0, http_state=0, data_remaining=451
D [09/Nov/2016:23:07:18 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] 2.0 CUPS-Get-Classes 37
D [09/Nov/2016:23:07:18 +0100] CUPS-Get-Classes
D [09/Nov/2016:23:07:18 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Classes (no URI) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 11] Content-Length: 75
D [09/Nov/2016:23:07:18 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:18 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x802551b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 11] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:07:18 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 11] POST / HTTP/1.1
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=200
D [09/Nov/2016:23:07:18 +0100] [Client 11] No authentication data provided.
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] Read: status=100
D [09/Nov/2016:23:07:18 +0100] [Client 11] 2.0 CUPS-Get-Default 38
D [09/Nov/2016:23:07:18 +0100] CUPS-Get-Default
D [09/Nov/2016:23:07:18 +0100] [Client 11] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost
D [09/Nov/2016:23:07:18 +0100] [Client 11] Content-Length: 11055
D [09/Nov/2016:23:07:18 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:18 +0100] [Client 11] con->http=0x80251588
D [09/Nov/2016:23:07:18 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11055, response=0x8023f628(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:18 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:18 +0100] [Client 11] bytes=0, http_state=0, data_remaining=11055
D [09/Nov/2016:23:07:18 +0100] [Client 11] Flushing write buffer.
D [09/Nov/2016:23:07:18 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:18 +0100] [Client 11] Waiting for request.
D [09/Nov/2016:23:07:18 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [09/Nov/2016:23:07:19 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:20 +0100] [Client 2] POST / HTTP/1.1
D [09/Nov/2016:23:07:20 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:20 +0100] [Client 2] Read: status=200
D [09/Nov/2016:23:07:20 +0100] [Client 2] No authentication data provided.
I [09/Nov/2016:23:07:20 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:20 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 2] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 2] 2.0 Get-Job-Attributes 39
D [09/Nov/2016:23:07:20 +0100] Get-Job-Attributes ipp://localhost/jobs/56
D [09/Nov/2016:23:07:20 +0100] [Client 2] Returning IPP successful-ok for Get-Job-Attributes (ipp://localhost/jobs/56) from localhost
D [09/Nov/2016:23:07:20 +0100] [Client 2] Content-Length: 1099
D [09/Nov/2016:23:07:20 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:20 +0100] [Client 2] con->http=0x802427d8
D [09/Nov/2016:23:07:20 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1099, response=0x80255108(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:20 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:20 +0100] [Client 2] bytes=0, http_state=0, data_remaining=1099
D [09/Nov/2016:23:07:20 +0100] [Client 2] Flushing write buffer.
D [09/Nov/2016:23:07:20 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:20 +0100] [Client 2] Waiting for request.
D [09/Nov/2016:23:07:20 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:20 +0100] [Client 2] POST / HTTP/1.1
D [09/Nov/2016:23:07:20 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:20 +0100] [Client 2] Read: status=200
D [09/Nov/2016:23:07:20 +0100] [Client 2] No authentication data provided.
D [09/Nov/2016:23:07:20 +0100] [Client 2] 2.0 Cancel-Subscription 40
D [09/Nov/2016:23:07:20 +0100] Cancel-Subscription /
D [09/Nov/2016:23:07:20 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:07:20 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:07:20 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:20 +0100] [Client 2] Returning IPP successful-ok for Cancel-Subscription (/) from localhost
D [09/Nov/2016:23:07:20 +0100] [Client 2] Content-Length: 75
D [09/Nov/2016:23:07:20 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:20 +0100] [Client 2] con->http=0x802427d8
D [09/Nov/2016:23:07:20 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x80256280(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:20 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:20 +0100] [Client 2] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:07:20 +0100] [Client 2] Flushing write buffer.
D [09/Nov/2016:23:07:20 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:20 +0100] [Client 2] Waiting for request.
D [09/Nov/2016:23:07:20 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:07:20 +0100] [Client 21] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:07:20 +0100] [Client 21] Accepted from localhost (Domain)
D [09/Nov/2016:23:07:20 +0100] [Client 21] Waiting for request.
D [09/Nov/2016:23:07:20 +0100] [Client 21] POST / HTTP/1.1
D [09/Nov/2016:23:07:20 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:07:20 +0100] [Client 21] Read: status=200
D [09/Nov/2016:23:07:20 +0100] [Client 21] No authentication data provided.
D [09/Nov/2016:23:07:20 +0100] [Client 21] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 21] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 21] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 21] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 21] Read: status=100
D [09/Nov/2016:23:07:20 +0100] [Client 21] 2.0 Get-Printer-Attributes 41
D [09/Nov/2016:23:07:20 +0100] Get-Printer-Attributes ipp://localhost/printers/Canon%5FMP495%5Fseries
D [09/Nov/2016:23:07:20 +0100] [Client 21] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon%5FMP495%5Fseries) from localhost
D [09/Nov/2016:23:07:20 +0100] [Client 21] Content-Length: 11055
D [09/Nov/2016:23:07:20 +0100] [Client 21] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:07:20 +0100] [Client 21] con->http=0x80257c70
D [09/Nov/2016:23:07:20 +0100] [Client 21] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=11055, response=0x80255f78(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:07:20 +0100] [Client 21] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:07:20 +0100] [Client 21] bytes=0, http_state=0, data_remaining=11055
D [09/Nov/2016:23:07:20 +0100] [Client 21] Flushing write buffer.
D [09/Nov/2016:23:07:20 +0100] [Client 21] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:07:20 +0100] [Client 21] Waiting for request.
D [09/Nov/2016:23:07:20 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [09/Nov/2016:23:07:21 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:31 +0100] [Client 1] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:31 +0100] [Client 1] Closing connection.
D [09/Nov/2016:23:07:31 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [09/Nov/2016:23:07:31 +0100] Expiring subscriptions...
I [09/Nov/2016:23:07:32 +0100] Expiring subscriptions...
I [09/Nov/2016:23:07:39 +0100] Saving job.cache...
I [09/Nov/2016:23:07:39 +0100] Saving subscriptions.conf...
D [09/Nov/2016:23:07:39 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
I [09/Nov/2016:23:07:39 +0100] Expiring subscriptions...
D [09/Nov/2016:23:07:49 +0100] [Client 21] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:07:49 +0100] [Client 21] Closing connection.
D [09/Nov/2016:23:07:49 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
I [09/Nov/2016:23:07:49 +0100] Expiring subscriptions...
I [09/Nov/2016:23:07:50 +0100] Expiring subscriptions...
I [09/Nov/2016:23:12:11 +0100] Expiring subscriptions...
D [09/Nov/2016:23:12:11 +0100] [Job 31] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 34] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 35] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 36] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 37] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 38] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 39] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 40] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 45] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 48] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 49] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 50] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 51] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 52] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 53] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 54] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 55] Unloading...
D [09/Nov/2016:23:12:11 +0100] [Job 56] Unloading...
D [09/Nov/2016:23:12:11 +0100] cupsdAddCert: Adding certificate for PID 0
D [09/Nov/2016:23:12:11 +0100] Closing client 3 after 300 seconds of inactivity.
D [09/Nov/2016:23:12:11 +0100] [Client 3] Closing connection.
D [09/Nov/2016:23:12:11 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [09/Nov/2016:23:12:11 +0100] Report: clients=3
D [09/Nov/2016:23:12:11 +0100] Report: jobs=18
D [09/Nov/2016:23:12:11 +0100] Report: jobs-active=0
D [09/Nov/2016:23:12:11 +0100] Report: printers=1
D [09/Nov/2016:23:12:11 +0100] Report: stringpool-string-count=5347
D [09/Nov/2016:23:12:11 +0100] Report: stringpool-alloc-bytes=9664
D [09/Nov/2016:23:12:11 +0100] Report: stringpool-total-bytes=99528
I [09/Nov/2016:23:12:19 +0100] Expiring subscriptions...
D [09/Nov/2016:23:12:19 +0100] Closing client 11 after 300 seconds of inactivity.
D [09/Nov/2016:23:12:19 +0100] [Client 11] Closing connection.
D [09/Nov/2016:23:12:19 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [09/Nov/2016:23:12:19 +0100] Closing client 20 after 300 seconds of inactivity.
D [09/Nov/2016:23:12:19 +0100] [Client 20] Closing connection.
D [09/Nov/2016:23:12:19 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
I [09/Nov/2016:23:12:21 +0100] Expiring subscriptions...
D [09/Nov/2016:23:12:21 +0100] Closing client 2 after 300 seconds of inactivity.
D [09/Nov/2016:23:12:21 +0100] [Client 2] Closing connection.
D [09/Nov/2016:23:12:21 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [09/Nov/2016:23:23:14 +0100] [Client 22] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:23:14 +0100] [Client 22] Accepted from localhost (Domain)
D [09/Nov/2016:23:23:14 +0100] [Client 22] Waiting for request.
I [09/Nov/2016:23:23:14 +0100] Expiring subscriptions...
D [09/Nov/2016:23:23:14 +0100] cupsdAddCert: Adding certificate for PID 0
D [09/Nov/2016:23:23:14 +0100] Report: clients=1
D [09/Nov/2016:23:23:14 +0100] Report: jobs=18
D [09/Nov/2016:23:23:14 +0100] Report: jobs-active=0
D [09/Nov/2016:23:23:14 +0100] Report: printers=1
D [09/Nov/2016:23:23:14 +0100] Report: stringpool-string-count=5341
D [09/Nov/2016:23:23:14 +0100] Report: stringpool-alloc-bytes=9600
D [09/Nov/2016:23:23:14 +0100] Report: stringpool-total-bytes=99384
D [09/Nov/2016:23:23:14 +0100] [Client 22] POST / HTTP/1.1
D [09/Nov/2016:23:23:14 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [09/Nov/2016:23:23:14 +0100] [Client 22] Read: status=200
D [09/Nov/2016:23:23:14 +0100] [Client 22] No authentication data provided.
D [09/Nov/2016:23:23:14 +0100] [Client 22] 2.0 Cancel-Subscription 42
D [09/Nov/2016:23:23:14 +0100] Cancel-Subscription /
D [09/Nov/2016:23:23:14 +0100] cupsdIsAuthorized: requesting-user-name="mithrandir"
D [09/Nov/2016:23:23:14 +0100] cupsdMarkDirty(----S)
D [09/Nov/2016:23:23:14 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [09/Nov/2016:23:23:14 +0100] [Client 22] Returning IPP successful-ok for Cancel-Subscription (/) from localhost
D [09/Nov/2016:23:23:14 +0100] [Client 22] Content-Length: 75
D [09/Nov/2016:23:23:14 +0100] [Client 22] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [09/Nov/2016:23:23:14 +0100] [Client 22] con->http=0x8024bc90
D [09/Nov/2016:23:23:14 +0100] [Client 22] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x80255f78(IPP_STATE_DATA), pipe_pid=0, file=-1
D [09/Nov/2016:23:23:14 +0100] [Client 22] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [09/Nov/2016:23:23:14 +0100] [Client 22] bytes=0, http_state=0, data_remaining=75
D [09/Nov/2016:23:23:14 +0100] [Client 22] Flushing write buffer.
D [09/Nov/2016:23:23:14 +0100] [Client 22] New state is HTTP_STATE_WAITING
D [09/Nov/2016:23:23:14 +0100] [Client 22] Waiting for request.
D [09/Nov/2016:23:23:14 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:23:14 +0100] [Client 22] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:23:14 +0100] [Client 22] Closing connection.
D [09/Nov/2016:23:23:14 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:23:14 +0100] [Client 23] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:23:14 +0100] [Client 23] Accepted from localhost (Domain)
D [09/Nov/2016:23:23:14 +0100] [Client 23] Waiting for request.
D [09/Nov/2016:23:23:14 +0100] [Client 24] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:23:14 +0100] [Client 24] Accepted from localhost (Domain)
D [09/Nov/2016:23:23:14 +0100] [Client 24] Waiting for request.
I [09/Nov/2016:23:23:15 +0100] Expiring subscriptions...
D [09/Nov/2016:23:23:21 +0100] [Client 24] PUT /admin/conf/cupsd.conf HTTP/1.1
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:23:21 +0100] [Client 24] Read: status=200
D [09/Nov/2016:23:23:21 +0100] [Client 24] No authentication data provided.
D [09/Nov/2016:23:23:21 +0100] cupsdIsAuthorized: username=""
D [09/Nov/2016:23:23:21 +0100] [Client 24] cupsdSendHeader: code=401, type="text/html", auth_type=0
D [09/Nov/2016:23:23:21 +0100] [Client 24] WWW-Authenticate: Basic realm=\"CUPS\", trc=\"y\"
D [09/Nov/2016:23:23:21 +0100] [Client 24] Closing connection.
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [09/Nov/2016:23:23:21 +0100] Expiring subscriptions...
D [09/Nov/2016:23:23:21 +0100] [Client 25] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:23:21 +0100] [Client 25] Accepted from localhost (Domain)
D [09/Nov/2016:23:23:21 +0100] [Client 25] Waiting for request.
D [09/Nov/2016:23:23:21 +0100] [Client 25] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:23:21 +0100] [Client 25] Closing connection.
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:23:21 +0100] [Client 26] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:23:21 +0100] [Client 26] Accepted from localhost (Domain)
D [09/Nov/2016:23:23:21 +0100] [Client 26] Waiting for request.
D [09/Nov/2016:23:23:21 +0100] [Client 26] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [09/Nov/2016:23:23:21 +0100] [Client 26] Closing connection.
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:23:21 +0100] [Client 27] Server address is "/run/cups/cups.sock".
D [09/Nov/2016:23:23:21 +0100] [Client 27] Accepted from localhost (Domain)
D [09/Nov/2016:23:23:21 +0100] [Client 27] Waiting for request.
D [09/Nov/2016:23:23:21 +0100] [Client 27] PUT /admin/conf/cupsd.conf HTTP/1.1
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [09/Nov/2016:23:23:21 +0100] [Client 27] Read: status=200
D [09/Nov/2016:23:23:21 +0100] [Client 27] Authorized as root using PeerCred.
D [09/Nov/2016:23:23:21 +0100] cupsdIsAuthorized: username="root"
D [09/Nov/2016:23:23:21 +0100] [Client 27] Read: status=100
I [09/Nov/2016:23:23:21 +0100] [Client 27] Installing config file "/etc/cups/cupsd.conf"...
D [09/Nov/2016:23:23:21 +0100] [Client 27] cupsdSendHeader: code=201, type="(null)", auth_type=0
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [09/Nov/2016:23:23:21 +0100] [Client 23] Closing connection.
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [09/Nov/2016:23:23:21 +0100] [Client 27] Closing connection.
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
E [09/Nov/2016:23:23:21 +0100] Scheduler shutting down due to program error.
D [09/Nov/2016:23:23:21 +0100] Discarding unused server-stopped event...
I [09/Nov/2016:23:23:21 +0100] Saving subscriptions.conf...
D [09/Nov/2016:23:23:21 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
D [09/Nov/2016:23:23:21 +0100] Creating keep-alive file "/var/cache/cups/org.cups.cupsd".
I [09/Nov/2016:23:23:21 +0100] Saving job.cache...
D [09/Nov/2016:23:23:21 +0100] cupsdStopSelect()
E [09/Nov/2016:23:23:21 +0100] Unknown directive JobPrivateAccess on line 89 of /etc/cups/cupsd.conf.
E [09/Nov/2016:23:23:21 +0100] Unknown directive JobPrivateValues on line 90 of /etc/cups/cupsd.conf.
E [09/Nov/2016:23:23:21 +0100] Unknown directive SubscriptionPrivateAccess on line 91 of /etc/cups/cupsd.conf.
E [09/Nov/2016:23:23:21 +0100] Unknown directive SubscriptionPrivateValues on line 92 of /etc/cups/cupsd.conf.
E [10/Nov/2016:12:07:44 +0100] Unknown directive JobPrivateAccess on line 89 of /etc/cups/cupsd.conf.
E [10/Nov/2016:12:07:44 +0100] Unknown directive JobPrivateValues on line 90 of /etc/cups/cupsd.conf.
E [10/Nov/2016:12:07:44 +0100] Unknown directive SubscriptionPrivateAccess on line 91 of /etc/cups/cupsd.conf.
E [10/Nov/2016:12:07:44 +0100] Unknown directive SubscriptionPrivateValues on line 92 of /etc/cups/cupsd.conf.

V1del · 2016-11-10 11:32:14

Canon drivers tend to not work, use the gutenprint provided drivers instead.

Sindarin · 2016-11-10 11:48:35

V1del wrote:

Canon drivers tend to not work, use the gutenprint provided drivers instead.

Did

yaourt -Rsn cnijfilter-mp495-i386

and selected in cups web interface the driver: Canon PIXMA MP495 - CUPS+Gutenprint v5.2.11 (color)
---> It doesn't do anything, shows the test-page print jobs as completed
Canon_MP495_series-58 Unknown Withheld 1k 1 completed at Thu Nov 10 12:46:59 2016
Canon_MP495_series-57 Unknown Withheld 1k 1 completed at Thu Nov 10 12:45:25 2016

pypi · 2016-11-10 22:54:38

From the log:

/usr/local/bin/cifmp495: error while loading shared libraries: libtiff.so.3: cannot open shared object file: No such file or directory

You should install https://aur.archlinux.org/packages/lib32-libtiff3/ as well.

What is the output of lpstat -t? The contents of /etc/cups/printers.conf? If it still doesn't work, you should try printing again and then post the contents of your CUPS error log.

Sindarin · 2016-11-11 11:03:45

Hi, SOLVED -->
I changed the driver to a more general kind in gutenprint Canon MP490 series - CUPS+Gutenprint v5.2.11

I'll give a chance to install lib32-libtiff3 and try the exact driver, I made some printing and I wasn't confident in how the printer was doing the things (sound was different than when I print from windows).

Next step trying to get a smart draft printing configuration.

Thank you everyone!! @pypi @V1del @olive

Sindarin · 2016-11-11 11:14:03

lib32-libtiff3 cannot be built, yaourt doesn't find dependency packages:

error: destino no encontrado: gcc-multilib
error: destino no encontrado: lib32-zlib
error: destino no encontrado: lib32-libxi
error: destino no encontrado: libtiff3
error: destino no encontrado: lib32-libxmu
error: destino no encontrado: lib32-libgl
error: destino no encontrado: lib32-libjpeg

Slithery · 2016-11-11 11:22:49

You need to enable the multilib repo.

https://wiki.archlinux.org/index.php/Multilib#Enabling

Sindarin · 2016-11-11 11:49:15

Thanks @slithery

Enable that, but there's no mirror usable everyone is 404
I think there's a problem if I'm using an i686 system

Last edited by Sindarin (2016-11-11 11:55:35)

pypi · 2016-11-11 20:25:53

Whoops - try libtiff3 archived from the old AUR instead.

Sindarin · 2016-11-13 09:23:26

Thanks for the clue pypi but i don't know what to do with git things (although i have little code skill I'm not a programmer). Idon't want you to waste a lot of time, can you post any link to some guide?

pypi · 2016-11-13 19:40:54

You can just download the "raw" file (the raw button is in the top right corner of the file viewing area), and build that like a normal PKGBUILD - using makepkg.

On that note, it might also be a good idea to point you to http://jasonwryan.com/blog/2013/04/09/helpers/; there is a lot of documentation on the wiki and elsewhere describing makepkg, PKGBUILDs, and so on, which you should be able to use to get the package installed without needing any extra help.

Sindarin · 2016-11-18 09:29:34

Hi pypi,
I've been reading few days.

I do agree with the post about the aur helpers and trying to DIY as much as I learn,
Well, I tell you:
I've tried the mkpkg from the old aur that you linked above,

The pkgbuild file is easy to read,
It warned to get a mkdepends package wich I supose are necesary to be installed outside of the pkgbuild, I did it.

But de download source doesn't work, the package is not there anymore.
Is there anything that I've missed?

pypi · 2016-11-18 20:14:24

Hmm, the website appears to be down.

You could use the source files in the debian source package instead? (there are download links at the bottom of that page)
You will probably have to change the PKGBUILD a bit to make it work - at least point the "source" at your downloaded file, correct the *sums (you can use updpkgsums for that), and correct the pkgver.

Sindarin · 2016-11-18 22:41:46

How exciting! I'm going to try it!!

Sindarin · 2016-11-21 12:38:15

I modified a PKGBUILD with this code (don't used the dependencies and I hadn't the sha1sums so I commented it. Also changed the directory reference.

# Maintainer: --
# Contributor: --

pkgname=libtiff3
pkgver=3.9.6
pkgrel=1
pkgdesc="Version obtained from the forum tip and the debian download."
arch=('i686' 'x86_64')
url="https://packages.debian.org/source/wheezy/tiff3"
license=('custom')
depends=()
# depends=('libjpeg' 'zlib' 'libtiff')
makedepends=('libgl' 'freeglut' 'libxmu' 'libxi' )
optdepends=()
# optdepends=('freeglut: for using tiffgt')
options=('!libtool')
source=(http://security.debian.org/debian-security/pool/updates/main/t/tiff3/tiff3_${pkgver}.orig.tar.gz)
md5sums=('6920f3bf628d791d49f268b83612ed23')
# sha1sums=('f40aab20fb2f609b5cbc1171c40b66a1445e3773')

build() {
  cd "${srcdir}/tiff-${pkgver}"
  ./configure --prefix=/usr
  make
}

package() {
  cd "${srcdir}/tiff-${pkgver}"
  make DESTDIR="${pkgdir}" install
  install -D -m644 COPYRIGHT "${pkgdir}"/usr/share/licenses/${pkgname}/LICENSE
  # We want only version3. Avoid conflict with 'libtiff' package
  rm -rf "${pkgdir}/usr/lib/libtiff".{a,so}
  rm -rf "${pkgdir}/usr/lib/libtiffxx".{a,so}
  # We want only libraries
  rm -rf "${pkgdir}/usr"/{bin,include,share/doc,share/man}
}

executed makepkg and now I have:
libtiff3-3.9.6-1-i686.pkg.tar.xz
tiff3_3.9.6.orig.tar.gz

Shoud this be ok to install now the package and try the driver install?
md5sum is equal to the one provided in the tiff3 file but it doesn't with the libtiff3 file

Last edited by Sindarin (2016-11-21 12:43:34)

pypi · 2016-11-22 19:12:45

Sindarin wrote:

executed makepkg and now I have:
libtiff3-3.9.6-1-i686.pkg.tar.xz
tiff3_3.9.6.orig.tar.gz
Shoud this be ok to install now the package and try the driver install?
md5sum is equal to the one provided in the tiff3 file but it doesn't with the libtiff3 file

I don't see why not?
You can at least sanity check the contents of the package by running

pacman -Qlp <path to package>

.

Arch Linux

#1 2016-11-09 22:16:01

printer canon mp495 - seems installed but doesn't print [SOLVED]

#2 2016-11-10 08:29:13

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#3 2016-11-10 11:29:53

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#4 2016-11-10 11:32:14

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#5 2016-11-10 11:48:35

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#6 2016-11-10 22:54:38

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#7 2016-11-11 11:03:45

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#8 2016-11-11 11:14:03

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#9 2016-11-11 11:22:49

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#10 2016-11-11 11:49:15

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#11 2016-11-11 20:25:53

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#12 2016-11-13 09:23:26

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#13 2016-11-13 19:40:54

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#14 2016-11-18 09:29:34

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#15 2016-11-18 20:14:24

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#16 2016-11-18 22:41:46

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#17 2016-11-21 12:38:15

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

#18 2016-11-22 19:12:45

Re: printer canon mp495 - seems installed but doesn't print [SOLVED]

Board footer