[solved] Drucker geht am USB Fernanschluss nicht mehr

thio · 16 Okt. 2019

Hallo,

irgendwie will mein Brother Drucker am "USB-Fernanschluss" an meiner Fritz-Box nicht mehr.
Hat alles schon problemlos funktioniert..

Sieht ganz gut eingerichtet aus, allerdings druckt er einfach nicht..

Code:

http://localhost:631/printers/MFC7420
Description:	Brother MFC7420 for CUPS
Location:	yy
Driver:	Brother MFC7420 for CUPS (grayscale)
Connection:	socket://fritz.box:9100
Defaults:	job-sheets=none, none media=iso_a4_210x297mm sides=one-sided

Code:

 	processing since
Wed 16 Oct 2019 05:50:05 PM CEST 
"Der Drucker antwortet nicht."

Hat jemand eine Idee/ Tip??

Vielen Dank im Voraus

manzek · 16 Okt. 2019

Ich selbst besitze noch einen alten MFC-8880DN, der allerdings über Ethernet angebunden ist, aber seit Leap 15.0 nicht mehr ohne Extrawurst richtig funktioneren will. Der proprietäre Treiber von Brother lässt sich zwar ganz normal installieren, aber der Scanner ging plötzlich nicht mehr.
Interessanterweise gab es eine Fehlermeldung, die ein Problem mit libusb (!) anmerkte. So habe ich libusb sowie das dazugehörige Kompatibilitätspaket sowohl in 32 bit als auch in 64 bit nachinstalliert.
Seit dem geht wieder alles wie gewohnt

Vielleicht hilft das ja weiter...

Sauerland · 16 Okt. 2019

System up-to-date?

Da gab es Probleme mit cups-filters.

thio · 19 Okt. 2019

ja, System ist up-to-date

libstdc++6-32bit
glibc-32bit
libusb-0_1_4
libusb-0_1_4-32bit
libusb-1_0_0
libusb-1_0_0-32bit

installiert

Durcker funktionert unter Windows wie er soll (verbindung zur Fritzbox ist also okay..)

manzek · 19 Okt. 2019

Seit wann geht denn der Fernanschluss zur Fritzbox nicht mehr? Kernelupdate oder gar eine neue openSUSE-Version?
Ich hatte in der Vergangenheit so einiges an Hardware, die ab einer bestimmten Distri einfach nicht mehr laufen wollte.

Hattest du die libusb-Sachen nachinstalliert, oder waren die schon auf deinem System? Falls du die gerade nachinstalliert hast, würde ich den Brother-Treiber nochmal drüber bügeln.

thio · 22 Okt. 2019

Libusb habe ich erneut installiert und auch anschließend den Brother Treiber nochmal.
Habe den Drucker jetzt auch an meinen anderen Laptop installiert (jungfräuliche Leap 15.1 Installation) da funktioniert der MFC7420 auch nicht :-(

Auch kurios, meine Eltern haben deinen MFC7360, der funzt unter Leap 15.1 problemlos...

Weitere Tips/ Ideen?

manzek · 22 Okt. 2019

Ich kann mich dunkel an derartige Probleme unter Windows erinnern, als die Fritzboxen noch nicht so potent waren wie heute.
Grundsätzlich würde ich den Drucker zunächst lokal per USB an den Rechner hängen und die Treiber installieren. Wenn er denn mal läuft, sollte auch die Geschichte mit dem Fernanschluss funktionieren, was ja eigentlich wirklich simpel ist... :irre:

[Edit]

Mir fällt gerade noch auf, dass bei der Druckerinstallation als Adresse lediglich "socket://fritz.box:9100" steht; ersetze mal 'fritz.box' durch die exakte IP-Adresse, beispielsweise "socket://192.192.178.1:9100". Vielleicht klappt das ja besser...

[/Edit]

thio · 23 Okt. 2019

Werde die Tage den Drucker auch mal lokal anschließen, aber mit älteren Suse-Versionen hat der Drucker am Fernanschluss problemlos funktioniert..

Und auch aktuell funktioniert der Drucker am Fernanschluss noch unter Windows..

Habe jetzt mal ein paar "Cups-Filter"-Versionen, die ich unter "software.opensuse.org" finden kann auf einem Testrechner installiert. Dabei bringt "smart" die folgende Meldung

Code:

Ausgabe von cups-filters-1.20.3-lp151.3.3.1@x86_64
warning: /etc/cups/cups-browsed.conf created as /etc/cups/cups-browsed.conf.rpmnew

Ausgabe von cups-filters-1.25.0-lp151.1.1@x86_64
warning: /etc/cups/cups-browsed.conf created as /etc/cups/cups-browsed.conf.rpmnew

Ausgabe von cups-filters-999.git.20190904.1c80dbe6-lp151.14.18@x86_64
warning: /etc/cups/cups-browsed.conf created as /etc/cups/cups-browsed.conf.rpmnew

Könnt Ihr damit was Anfangen?
Evtl. ein Ansatz dem Fehler auf die Schliche zu kommen?

manzek · 23 Okt. 2019

thio schrieb:
Code:

warning: /etc/cups/cups-browsed.conf created as /etc/cups/cups-browsed.conf.rpmnew

Habe gerade mal selbst in besagtes Verzeichnis geschaut, und dort findet sich ebenfalls o.a. Datei, nur ohne die Endung 'rpmnew'.
Die lässt darauf schließen, dass die Datei ganz einfach in 'cups-browsed.conf' umbenannt werden sollte. Allerdings würde ich ein Backup von der ursprünglichen Version erstellen.

josef-wien · 23 Okt. 2019

Wenn die Installationsroutine eines Pakets feststellt, daß eine Konfigurationsdatei geändert wurde, kann sie Ihre Version mit der Ergänzung ".rpmnew" erzeugen und die vorhandene Datei in Ruhe lassen. In diesem Fall muß Du selbst entscheiden, wie die Konfigurationsdatei in Zukunft aussehen soll. Das gilt auch, wenn die Installationsroutine ihre Version schreibt und die bisherige mit dem Zusatz ".rpmsave" versieht.

thio · 10 Nov. 2019

Habe einen Rechner auf Leap 15.0 zurückgesetzt, funktioniert leider immer noch nicht...
(Unter 15.0 sollte der Drucker früher aber funktioniert haben)
Bin irgendwie ratlos...

Sauerland · 10 Nov. 2019

Usb-Kabel?

Code:

ping -c2 fritz.box

funktioniert?
Ich mach es über IP:

Code:

socket://192.168.0.254:9100

Sauerland · 10 Nov. 2019

log-level in der /etc/cups/cupsd.conf auf debug erhöhen und Datei speichern.
cups neu starten:

Code:

systemctl restart cups.service

Dann versuchen zu drucken und das /var/log/cups/error.log hier posten, bzw. nur die Teile mit heutigem Datum.

thio · 10 Nov. 2019

Funktioniert unter USB auch nicht..

Unter Windows 10 funktioniert der Drucker am USB-Anschluss der Fritz-Box

Code:

linux-5ndf:~ # ping -c2 fritz.box
PING fritz.box(fritz.box (fd00::3681:c4ff:fed6:84db)) 56 data bytes
64 bytes from fritz.box (fd00::3681:c4ff:fed6:84db): icmp_seq=1 ttl=255 time=1.44 ms
64 bytes from fritz.box (fd00::3681:c4ff:fed6:84db): icmp_seq=2 ttl=255 time=137 ms

--- fritz.box ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1001ms
rtt min/avg/max/mdev = 1.444/69.457/137.470/68.013 ms

thio · 10 Nov. 2019

Wie gehe ich hier vor?

log-level in der /etc/cups/cupsd.conf auf debug erhöhen und Datei speichern.

??

/var/log/cups/error.log

Code:

W [10/Nov/2019:17:57:31 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:17:57:31 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:17:57:32 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:17:57:32 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:17:57:32 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:17:57:32 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:17:57:32 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:18:04:52 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:18:04:52 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:18:04:52 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:18:04:52 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:18:04:52 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:18:04:52 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
W [10/Nov/2019:18:04:52 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
E [10/Nov/2019:18:05:29 +0100] [Job 82] The printer is not responding.

manzek · 10 Nov. 2019

thio schrieb:
Wie gehe ich hier vor?

log-level in der /etc/cups/cupsd.conf auf debug erhöhen und Datei speichern.

Zum Vergrößern anklicken....

In Zeile 6-9 der Datei findest du Folgendes:

Code:

# Log general information in error_log - change "warn" to "debug" # for troubleshooting... LogLevel warn PageLogFormat

Also einfach in Zeile 8 das Wort 'warn durch 'debug' ersetzen.

Geier0815 · 11 Nov. 2019

Mal doof am Rande gefragt: Arbeitest Du ernsthaft mit IPv6? Oder warum wird

ping -c2 fritz.box
PING fritz.box(fritz.box (fd00::3681:c4ff:fed6:84db)) 56 data bytes
64 bytes from fritz.box (fd00::3681:c4ff:fed6:84db): icmp_seq=1 ttl=255 time=1.44 ms

die Anfrage per neighbour discovery protocol aufgelöst?

thio · 11 Nov. 2019

Sorry ich verstehe nur Bahnhof..
ipv6 ??

thio · 11 Nov. 2019

Lolgendes gemacht:

- log-level in der /etc/cups/cupsd.conf auf debug erhöhen und Datei speichern.
- systemctl restart cups.service
- mit yast versuc ht eine Testseite auszudrucken - leider Erfolglos..

meine /var/log/cups/error.log:

Teil1

Code:

D [11/Nov/2019:21:16:21 +0100] [Client 1] POST / HTTP/1.1
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [11/Nov/2019:21:16:21 +0100] [Client 1] Read: status=200, state=6
D [11/Nov/2019:21:16:21 +0100] [Client 1] No authentication data provided.
D [11/Nov/2019:21:16:21 +0100] [Client 1] 2.0 Cancel-Subscription 6
D [11/Nov/2019:21:16:21 +0100] Cancel-Subscription /
D [11/Nov/2019:21:16:21 +0100] [Client 1] Returning HTTP Unauthorized for Cancel-Subscription (/) from localhost
D [11/Nov/2019:21:16:21 +0100] [Client 1] cupsdSendHeader: code=401, type="text/html", auth_type=0
D [11/Nov/2019:21:16:21 +0100] [Client 1] WWW-Authenticate: Basic realm=\"CUPS\", PeerCred, Local trc=\"y\"
I [11/Nov/2019:21:16:21 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:21 +0100] Report: clients=2
D [11/Nov/2019:21:16:21 +0100] Report: jobs=87
D [11/Nov/2019:21:16:21 +0100] Report: jobs-active=0
D [11/Nov/2019:21:16:21 +0100] Report: printers=3
D [11/Nov/2019:21:16:21 +0100] Report: stringpool-string-count=3407
D [11/Nov/2019:21:16:21 +0100] Report: stringpool-alloc-bytes=14520
D [11/Nov/2019:21:16:21 +0100] Report: stringpool-total-bytes=66840
D [11/Nov/2019:21:16:21 +0100] [Client 1] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:21 +0100] [Client 1] Closing connection.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [11/Nov/2019:21:16:21 +0100] [Client 22] Server address is "/run/cups/cups.sock".
D [11/Nov/2019:21:16:21 +0100] [Client 22] Accepted from localhost (Domain)
D [11/Nov/2019:21:16:21 +0100] [Client 22] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [11/Nov/2019:21:16:21 +0100] [Client 23] Server address is "/run/cups/cups.sock".
D [11/Nov/2019:21:16:21 +0100] [Client 23] Accepted from localhost (Domain)
D [11/Nov/2019:21:16:21 +0100] [Client 23] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] [Client 22] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:21 +0100] [Client 22] Closing connection.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [11/Nov/2019:21:16:21 +0100] [Client 24] Server address is "/run/cups/cups.sock".
D [11/Nov/2019:21:16:21 +0100] [Client 24] Accepted from localhost (Domain)
D [11/Nov/2019:21:16:21 +0100] [Client 24] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] [Client 23] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:21 +0100] [Client 23] Closing connection.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [11/Nov/2019:21:16:21 +0100] [Client 24] POST / HTTP/1.1
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [11/Nov/2019:21:16:21 +0100] [Client 24] Read: status=200, state=6
D [11/Nov/2019:21:16:21 +0100] [Client 24] Authorized as root using PeerCred.
D [11/Nov/2019:21:16:21 +0100] [Client 24] 2.0 Cancel-Subscription 6
D [11/Nov/2019:21:16:21 +0100] Cancel-Subscription /
D [11/Nov/2019:21:16:21 +0100] cupsdIsAuthorized: username="root"
D [11/Nov/2019:21:16:21 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [11/Nov/2019:21:16:21 +0100] [Client 24] Returning IPP successful-ok for Cancel-Subscription (/) from localhost.
D [11/Nov/2019:21:16:21 +0100] [Client 24] Content-Length: 75
D [11/Nov/2019:21:16:21 +0100] [Client 24] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:21 +0100] [Client 24] con->http=0x55fdd27df440
D [11/Nov/2019:21:16:21 +0100] [Client 24] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x55fdd2719b60(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:21 +0100] [Client 24] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:21 +0100] [Client 24] bytes=0, http_state=0, data_remaining=75
D [11/Nov/2019:21:16:21 +0100] [Client 24] Flushing write buffer.
D [11/Nov/2019:21:16:21 +0100] [Client 24] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:21 +0100] [Client 24] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Notifier] state=-1
D [11/Nov/2019:21:16:21 +0100] [Notifier] ippReadFile() returned IPP_ERROR!
D [11/Nov/2019:21:16:21 +0100] PID 4799 (/usr/lib/cups/notifier/dbus) exited with no errors.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 25] Server address is "/run/cups/cups.sock".
D [11/Nov/2019:21:16:21 +0100] [Client 25] Accepted from localhost (Domain)
D [11/Nov/2019:21:16:21 +0100] [Client 25] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] [Client 25] POST / HTTP/1.1
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 25] Read: status=200, state=6
D [11/Nov/2019:21:16:21 +0100] [Client 25] No authentication data provided.
D [11/Nov/2019:21:16:21 +0100] [Client 25] 2.0 Cancel-Subscription 7
D [11/Nov/2019:21:16:21 +0100] Cancel-Subscription /
D [11/Nov/2019:21:16:21 +0100] cupsdIsAuthorized: requesting-user-name="root"
D [11/Nov/2019:21:16:21 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 25] Returning IPP successful-ok for Cancel-Subscription (/) from localhost.
D [11/Nov/2019:21:16:21 +0100] [Client 25] Content-Length: 75
D [11/Nov/2019:21:16:21 +0100] [Client 25] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:21 +0100] [Client 25] con->http=0x55fdd2838930
D [11/Nov/2019:21:16:21 +0100] [Client 25] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=75, response=0x55fdd27c9c90(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:21 +0100] [Client 25] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:21 +0100] [Client 25] bytes=0, http_state=0, data_remaining=75
D [11/Nov/2019:21:16:21 +0100] [Client 25] Flushing write buffer.
D [11/Nov/2019:21:16:21 +0100] [Client 25] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:21 +0100] [Client 25] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 25] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:21 +0100] [Client 25] Closing connection.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 24] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:21 +0100] [Client 24] Closing connection.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 2] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:21 +0100] [Client 2] Closing connection.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [11/Nov/2019:21:16:21 +0100] Scheduler shutting down normally.
D [11/Nov/2019:21:16:21 +0100] Discarding unused server-stopped event...
I [11/Nov/2019:21:16:21 +0100] Saving subscriptions.conf...
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Dirty files"
D [11/Nov/2019:21:16:21 +0100] Creating KeepAlive/PID file "/var/cache/cups/org.cups.cupsd".
I [11/Nov/2019:21:16:21 +0100] Saving job.cache...
D [11/Nov/2019:21:16:21 +0100] cupsdStopSelect()
I [11/Nov/2019:21:16:21 +0100] Listening to [v1.::1]:631 (IPv6)
I [11/Nov/2019:21:16:21 +0100] Listening to 127.0.0.1:631 (IPv4)
I [11/Nov/2019:21:16:21 +0100] Listening to /run/cups/cups.sock (Domain)
I [11/Nov/2019:21:16:21 +0100] Remote access is disabled.
D [11/Nov/2019:21:16:21 +0100] Added auto ServerAlias linux-5ndf
I [11/Nov/2019:21:16:21 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
D [11/Nov/2019:21:16:21 +0100] Using keychain "/etc/cups/ssl" for server name "linux-5ndf".
I [11/Nov/2019:21:16:21 +0100] Using default TempDir of /var/spool/cups/tmp...
I [11/Nov/2019:21:16:21 +0100] Configured for up to 100 clients.
I [11/Nov/2019:21:16:21 +0100] Allowing up to 100 client connections per host.
I [11/Nov/2019:21:16:21 +0100] Full reload is required.
I [11/Nov/2019:21:16:21 +0100] Loaded MIME database from "/usr/share/cups/mime" and "/etc/cups": 78 types, 118 filters...
D [11/Nov/2019:21:16:21 +0100] Loading printer brother...
D [11/Nov/2019:21:16:21 +0100] load_ppd: Loading /var/cache/cups/brother.data...
D [11/Nov/2019:21:16:21 +0100] cupsdRegisterPrinter(p=0x55efe978c760(brother))
D [11/Nov/2019:21:16:21 +0100] load_ppd: Loading /var/cache/cups/brother.data...
D [11/Nov/2019:21:16:21 +0100] cupsdRegisterPrinter(p=0x55efe978c760(brother))
D [11/Nov/2019:21:16:21 +0100] Loading printer CUPS-PDF...
D [11/Nov/2019:21:16:21 +0100] load_ppd: Loading /var/cache/cups/CUPS-PDF.data...
D [11/Nov/2019:21:16:21 +0100] cupsdRegisterPrinter(p=0x55efe97c2af0(CUPS-PDF))
D [11/Nov/2019:21:16:21 +0100] Loading printer MFC7420...
D [11/Nov/2019:21:16:21 +0100] load_ppd: Loading /var/cache/cups/MFC7420.data...
D [11/Nov/2019:21:16:21 +0100] cupsdRegisterPrinter(p=0x55efe9808ae0(MFC7420))
I [11/Nov/2019:21:16:21 +0100] Loading job cache file "/var/cache/cups/job.cache"...
D [11/Nov/2019:21:16:21 +0100] [Job 1] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 1] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 2] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 2] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 3] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 3] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 4] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 4] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 5] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 5] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 8] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 10] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 11] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 12] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 13] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 14] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 15] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 16] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 17] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 18] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 19] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 20] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 21] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 22] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 23] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 24] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 25] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 26] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 27] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 28] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 29] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 30] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 31] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 32] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 33] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 34] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 35] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 36] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 37] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 38] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 39] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 40] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 41] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 42] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 43] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 44] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 45] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 46] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 47] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 48] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 49] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 50] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 51] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 52] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 53] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 54] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 55] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 56] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 57] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 58] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 59] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 60] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 61] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 62] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 63] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 64] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 65] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 66] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 67] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 68] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 69] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 70] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 71] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 72] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 73] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 74] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 75] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 76] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 77] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 78] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 79] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 80] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 81] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 82] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 83] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 84] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 85] Loading from cache...
D [11/Nov/2019:21:16:21 +0100] [Job 85] Loading attributes...
D [11/Nov/2019:21:16:21 +0100] [Job 85] Unloading...
D [11/Nov/2019:21:16:21 +0100] cupsdAddSubscription(mask=0, dest=(nil)(), job=(nil)(0), uri="(null)")
I [11/Nov/2019:21:16:21 +0100] Full reload complete.
D [11/Nov/2019:21:16:21 +0100] cupsdCleanFiles(path="/var/spool/cups/tmp", pattern="(null)")
I [11/Nov/2019:21:16:21 +0100] Cleaning out old files in "/var/spool/cups/tmp".
D [11/Nov/2019:21:16:21 +0100] cupsdCleanFiles(path="/var/cache/cups", pattern="*.ipp")
I [11/Nov/2019:21:16:21 +0100] Cleaning out old files in "/var/cache/cups".
D [11/Nov/2019:21:16:21 +0100] service_checkin: pid=5079
D [11/Nov/2019:21:16:21 +0100] service_checkin: 1 listeners.
D [11/Nov/2019:21:16:21 +0100] service_add_listener: Listener #1 at fd 3, "/run/cups/cups.sock".
D [11/Nov/2019:21:16:21 +0100] service_add_listener: Matched existing listener #1 to /run/cups/cups.sock.
D [11/Nov/2019:21:16:21 +0100] Creating KeepAlive/PID file "/var/cache/cups/org.cups.cupsd".
D [11/Nov/2019:21:16:21 +0100] Calling FindDeviceById(cups-brother)
D [11/Nov/2019:21:16:21 +0100] FindDeviceById failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
D [11/Nov/2019:21:16:21 +0100] Using profile ID "brother-Gray..".
D [11/Nov/2019:21:16:21 +0100] Calling CreateProfile(brother-Gray..,temp)
W [11/Nov/2019:21:16:21 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
I [11/Nov/2019:21:16:21 +0100] Registering ICC color profiles for "brother".
D [11/Nov/2019:21:16:21 +0100] Calling CreateDevice(cups-brother,temp)
W [11/Nov/2019:21:16:21 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
D [11/Nov/2019:21:16:21 +0100] Calling FindDeviceById(cups-CUPS-PDF)
D [11/Nov/2019:21:16:21 +0100] FindDeviceById failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
D [11/Nov/2019:21:16:21 +0100] Using profile ID "CUPS-PDF-Gray..".
D [11/Nov/2019:21:16:21 +0100] Calling CreateProfile(CUPS-PDF-Gray..,temp)
W [11/Nov/2019:21:16:21 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
D [11/Nov/2019:21:16:21 +0100] Using profile ID "CUPS-PDF-RGB..".
D [11/Nov/2019:21:16:21 +0100] Calling CreateProfile(CUPS-PDF-RGB..,temp)
W [11/Nov/2019:21:16:21 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
I [11/Nov/2019:21:16:21 +0100] Registering ICC color profiles for "CUPS-PDF".
D [11/Nov/2019:21:16:21 +0100] Calling CreateDevice(cups-CUPS-PDF,temp)
W [11/Nov/2019:21:16:21 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
D [11/Nov/2019:21:16:21 +0100] Calling FindDeviceById(cups-MFC7420)
D [11/Nov/2019:21:16:21 +0100] FindDeviceById failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
D [11/Nov/2019:21:16:21 +0100] Using profile ID "MFC7420-Gray..".
D [11/Nov/2019:21:16:21 +0100] Calling CreateProfile(MFC7420-Gray..,temp)
W [11/Nov/2019:21:16:21 +0100] CreateProfile failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
I [11/Nov/2019:21:16:21 +0100] Registering ICC color profiles for "MFC7420".
D [11/Nov/2019:21:16:21 +0100] Calling CreateDevice(cups-MFC7420,temp)
W [11/Nov/2019:21:16:21 +0100] CreateDevice failed: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
I [11/Nov/2019:21:16:21 +0100] Listening to [v1.::1]:631 on fd 7...
I [11/Nov/2019:21:16:21 +0100] Listening to 127.0.0.1:631 on fd 8...
I [11/Nov/2019:21:16:21 +0100] Listening to /run/cups/cups.sock on fd 3...
I [11/Nov/2019:21:16:21 +0100] Resuming new connection processing...
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [11/Nov/2019:21:16:21 +0100] cupsdAddCert: Adding certificate for PID 0
D [11/Nov/2019:21:16:21 +0100] Discarding unused server-started event...
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [11/Nov/2019:21:16:21 +0100] [Client 1] Server address is "/run/cups/cups.sock".
D [11/Nov/2019:21:16:21 +0100] [Client 1] Accepted from localhost (Domain)
D [11/Nov/2019:21:16:21 +0100] [Client 1] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] Report: clients=1
D [11/Nov/2019:21:16:21 +0100] Report: jobs=87
D [11/Nov/2019:21:16:21 +0100] Report: jobs-active=0
D [11/Nov/2019:21:16:21 +0100] Report: printers=3
D [11/Nov/2019:21:16:21 +0100] Report: stringpool-string-count=2927
D [11/Nov/2019:21:16:21 +0100] Report: stringpool-alloc-bytes=13256
D [11/Nov/2019:21:16:21 +0100] Report: stringpool-total-bytes=56944
D [11/Nov/2019:21:16:21 +0100] [Client 1] POST / HTTP/1.1
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [11/Nov/2019:21:16:21 +0100] [Client 1] Read: status=200, state=6
D [11/Nov/2019:21:16:21 +0100] [Client 1] No authentication data provided.
D [11/Nov/2019:21:16:21 +0100] [Client 1] 2.0 Create-Printer-Subscriptions 1
D [11/Nov/2019:21:16:21 +0100] Create-Printer-Subscriptions /
D [11/Nov/2019:21:16:21 +0100] create_subscriptions(con=0x55efe9850fe0(1), uri="/")
D [11/Nov/2019:21:16:21 +0100] pullmethod="ippget"
D [11/Nov/2019:21:16:21 +0100] notify-lease-duration=86400
D [11/Nov/2019:21:16:21 +0100] notify-time-interval=60
D [11/Nov/2019:21:16:21 +0100] cupsdAddSubscription(mask=7ff, dest=(nil)(), job=(nil)(0), uri="(null)")
D [11/Nov/2019:21:16:21 +0100] Added subscription #1479 for server.
D [11/Nov/2019:21:16:21 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [11/Nov/2019:21:16:21 +0100] [Client 1] Returning IPP successful-ok for Create-Printer-Subscriptions (/) from localhost.
D [11/Nov/2019:21:16:21 +0100] [Client 1] Content-Length: 107
D [11/Nov/2019:21:16:21 +0100] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:21 +0100] [Client 1] con->http=0x55efe985c6b0
D [11/Nov/2019:21:16:21 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=107, response=0x55efe985b9c0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:21 +0100] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:21 +0100] [Client 1] bytes=0, http_state=0, data_remaining=107
D [11/Nov/2019:21:16:21 +0100] [Client 1] Flushing write buffer.
D [11/Nov/2019:21:16:21 +0100] [Client 1] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:21 +0100] [Client 1] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 2] Server address is "/run/cups/cups.sock".
D [11/Nov/2019:21:16:21 +0100] [Client 2] Accepted from localhost (Domain)
D [11/Nov/2019:21:16:21 +0100] [Client 2] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] [Client 2] POST / HTTP/1.1
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 2] Read: status=200, state=6
D [11/Nov/2019:21:16:21 +0100] [Client 2] No authentication data provided.
D [11/Nov/2019:21:16:21 +0100] [Client 2] 2.0 CUPS-Get-Default 2
D [11/Nov/2019:21:16:21 +0100] CUPS-Get-Default
D [11/Nov/2019:21:16:21 +0100] [Client 2] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [11/Nov/2019:21:16:21 +0100] [Client 2] Content-Length: 9211
D [11/Nov/2019:21:16:21 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:21 +0100] [Client 2] con->http=0x55efe9862fd0
D [11/Nov/2019:21:16:21 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9211, response=0x55efe9836510(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:21 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:21 +0100] [Client 2] bytes=0, http_state=0, data_remaining=9211
D [11/Nov/2019:21:16:21 +0100] [Client 2] Flushing write buffer.
D [11/Nov/2019:21:16:21 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:21 +0100] [Client 2] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 2] POST / HTTP/1.1
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 2] Read: status=200, state=6
D [11/Nov/2019:21:16:21 +0100] [Client 2] No authentication data provided.
D [11/Nov/2019:21:16:21 +0100] [Client 2] 2.0 CUPS-Get-Printers 3
D [11/Nov/2019:21:16:21 +0100] CUPS-Get-Printers
D [11/Nov/2019:21:16:21 +0100] [Client 2] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [11/Nov/2019:21:16:21 +0100] [Client 2] Content-Length: 3746
D [11/Nov/2019:21:16:21 +0100] [Client 2] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:21 +0100] [Client 2] con->http=0x55efe9862fd0
D [11/Nov/2019:21:16:21 +0100] [Client 2] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=3746, response=0x55efe984bcc0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:21 +0100] [Client 2] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:21 +0100] [Client 2] bytes=0, http_state=0, data_remaining=3746
D [11/Nov/2019:21:16:21 +0100] [Client 2] Flushing write buffer.
D [11/Nov/2019:21:16:21 +0100] [Client 2] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:21 +0100] [Client 2] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 1] POST / HTTP/1.1
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 1] Read: status=200, state=6
D [11/Nov/2019:21:16:21 +0100] [Client 1] No authentication data provided.
D [11/Nov/2019:21:16:21 +0100] [Client 1] 2.0 CUPS-Get-Default 4
D [11/Nov/2019:21:16:21 +0100] CUPS-Get-Default
D [11/Nov/2019:21:16:21 +0100] [Client 1] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [11/Nov/2019:21:16:21 +0100] [Client 1] Content-Length: 9211
D [11/Nov/2019:21:16:21 +0100] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:21 +0100] [Client 1] con->http=0x55efe985c6b0
D [11/Nov/2019:21:16:21 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9211, response=0x55efe98493b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:21 +0100] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:21 +0100] [Client 1] bytes=0, http_state=0, data_remaining=9211
D [11/Nov/2019:21:16:21 +0100] [Client 1] Flushing write buffer.
D [11/Nov/2019:21:16:21 +0100] [Client 1] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:21 +0100] [Client 1] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 1] POST / HTTP/1.1
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 1] Read: status=200, state=6
D [11/Nov/2019:21:16:21 +0100] [Client 1] No authentication data provided.
D [11/Nov/2019:21:16:21 +0100] [Client 1] 2.0 Create-Printer-Subscriptions 5
D [11/Nov/2019:21:16:21 +0100] Create-Printer-Subscriptions /
D [11/Nov/2019:21:16:21 +0100] create_subscriptions(con=0x55efe9850fe0(1), uri="/")
D [11/Nov/2019:21:16:21 +0100] recipient="dbus://"
D [11/Nov/2019:21:16:21 +0100] notify-lease-duration=86400
D [11/Nov/2019:21:16:21 +0100] notify-time-interval=0
D [11/Nov/2019:21:16:21 +0100] cupsdAddSubscription(mask=1fffff, dest=(nil)(), job=(nil)(0), uri="dbus://")
D [11/Nov/2019:21:16:21 +0100] Added subscription #1480 for server.
D [11/Nov/2019:21:16:21 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:21 +0100] [Client 1] Returning IPP successful-ok for Create-Printer-Subscriptions (/) from localhost.
D [11/Nov/2019:21:16:21 +0100] [Client 1] Content-Length: 107
D [11/Nov/2019:21:16:21 +0100] [Client 1] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:21 +0100] [Client 1] con->http=0x55efe985c6b0
D [11/Nov/2019:21:16:21 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=107, response=0x55efe984bcc0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:21 +0100] [Client 1] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:21 +0100] [Client 1] bytes=0, http_state=0, data_remaining=107
D [11/Nov/2019:21:16:21 +0100] [Client 1] Flushing write buffer.
D [11/Nov/2019:21:16:21 +0100] [Client 1] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:21 +0100] [Client 1] Waiting for request.
D [11/Nov/2019:21:16:21 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
I [11/Nov/2019:21:16:22 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:25 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:25 +0100] [Client 3] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:25 +0100] [Client 3] Accepted from localhost:56326 (IPv6)
D [11/Nov/2019:21:16:25 +0100] [Client 3] Waiting for request.
I [11/Nov/2019:21:16:25 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:25 +0100] [Client 3] POST / HTTP/1.1
D [11/Nov/2019:21:16:25 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=200, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] No authentication data provided.
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] 2.0 Get-Printer-Attributes 1
D [11/Nov/2019:21:16:25 +0100] Get-Printer-Attributes ipp://localhost:631/printers/MFC7420
D [11/Nov/2019:21:16:25 +0100] [Client 3] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:25 +0100] [Client 3] Content-Length: 1283
D [11/Nov/2019:21:16:25 +0100] [Client 3] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:25 +0100] [Client 3] con->http=0x55efe9867830
D [11/Nov/2019:21:16:25 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1283, response=0x55efe9796840(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:25 +0100] [Client 3] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:25 +0100] [Client 3] bytes=0, http_state=0, data_remaining=1283
D [11/Nov/2019:21:16:25 +0100] [Client 3] Flushing write buffer.
D [11/Nov/2019:21:16:25 +0100] [Client 3] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:25 +0100] [Client 3] Waiting for request.
D [11/Nov/2019:21:16:25 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:25 +0100] [Client 3] POST / HTTP/1.1
D [11/Nov/2019:21:16:25 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=200, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] No authentication data provided.
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] Read: status=100, state=6
D [11/Nov/2019:21:16:25 +0100] [Client 3] 2.0 Get-Jobs 2
D [11/Nov/2019:21:16:25 +0100] Get-Jobs ipp://localhost/
D [11/Nov/2019:21:16:25 +0100] [Client 3] Returning IPP successful-ok for Get-Jobs (ipp://localhost/) from localhost.
D [11/Nov/2019:21:16:25 +0100] [Client 3] Content-Length: 72
D [11/Nov/2019:21:16:25 +0100] [Client 3] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:25 +0100] [Client 3] con->http=0x55efe9867830
D [11/Nov/2019:21:16:25 +0100] [Client 3] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=72, response=0x55efe9854150(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:25 +0100] [Client 3] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:25 +0100] [Client 3] bytes=0, http_state=0, data_remaining=72
D [11/Nov/2019:21:16:25 +0100] [Client 3] Flushing write buffer.
D [11/Nov/2019:21:16:25 +0100] [Client 3] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:25 +0100] [Client 3] Waiting for request.
D [11/Nov/2019:21:16:25 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:25 +0100] [Client 3] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:25 +0100] [Client 3] Closing connection.
D [11/Nov/2019:21:16:25 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
I [11/Nov/2019:21:16:26 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] Server address is "/run/cups/cups.sock".
D [11/Nov/2019:21:16:27 +0100] [Client 4] Accepted from localhost (Domain)
D [11/Nov/2019:21:16:27 +0100] [Client 4] Waiting for request.
I [11/Nov/2019:21:16:27 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:27 +0100] [Client 4] POST / HTTP/1.1
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=200, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] No authentication data provided.
D [11/Nov/2019:21:16:27 +0100] [Client 4] 2.0 Get-Printer-Attributes 1
D [11/Nov/2019:21:16:27 +0100] Get-Printer-Attributes ipp://localhost:631/printers/MFC7420
D [11/Nov/2019:21:16:27 +0100] [Client 4] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:27 +0100] [Client 4] Content-Length: 1279
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] con->http=0x55efe9867830
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1279, response=0x55efe9796800(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:27 +0100] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] bytes=0, http_state=0, data_remaining=1279
D [11/Nov/2019:21:16:27 +0100] [Client 4] Flushing write buffer.
D [11/Nov/2019:21:16:27 +0100] [Client 4] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:27 +0100] [Client 4] Waiting for request.
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] POST / HTTP/1.1
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=200, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] No authentication data provided.
D [11/Nov/2019:21:16:27 +0100] [Client 4] 2.0 Get-Printer-Attributes 2
D [11/Nov/2019:21:16:27 +0100] Get-Printer-Attributes ipp://localhost:631/printers/MFC7420
D [11/Nov/2019:21:16:27 +0100] [Client 4] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:27 +0100] [Client 4] Content-Length: 1279
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] con->http=0x55efe9867830
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1279, response=0x55efe9796850(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:27 +0100] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] bytes=0, http_state=0, data_remaining=1279
D [11/Nov/2019:21:16:27 +0100] [Client 4] Flushing write buffer.
D [11/Nov/2019:21:16:27 +0100] [Client 4] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:27 +0100] [Client 4] Waiting for request.
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] POST /printers/MFC7420 HTTP/1.1
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=200, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] No authentication data provided.
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] 2.0 Get-Printer-Attributes 3
D [11/Nov/2019:21:16:27 +0100] Get-Printer-Attributes ipp://localhost/printers/MFC7420
D [11/Nov/2019:21:16:27 +0100] [Client 4] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:27 +0100] [Client 4] Content-Length: 16117
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] con->http=0x55efe9867830
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=16117, response=0x55efe9796800(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:27 +0100] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] bytes=0, http_state=0, data_remaining=16117
D [11/Nov/2019:21:16:27 +0100] [Client 4] Flushing write buffer.
D [11/Nov/2019:21:16:27 +0100] [Client 4] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:27 +0100] [Client 4] Waiting for request.
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] POST /printers/MFC7420 HTTP/1.1
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=200, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] No authentication data provided.
D [11/Nov/2019:21:16:27 +0100] [Client 4] 2.0 Create-Job 4
D [11/Nov/2019:21:16:27 +0100] Create-Job ipp://localhost/printers/MFC7420
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Job 86] Applying default options...
D [11/Nov/2019:21:16:27 +0100] add_job: requesting-user-name="root"
I [11/Nov/2019:21:16:27 +0100] [Job 86] Adding start banner page "none".
D [11/Nov/2019:21:16:27 +0100] Notifier dbus started - PID = 5096
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [11/Nov/2019:21:16:27 +0100] [Job 86] Queued on "MFC7420" by "root".
D [11/Nov/2019:21:16:27 +0100] [Client 4] Returning IPP successful-ok for Create-Job (ipp://localhost/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:27 +0100] [Client 4] Content-Length: 197
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] con->http=0x55efe9867830
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=197, response=0x55efe98493b0(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:27 +0100] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] bytes=0, http_state=0, data_remaining=197
D [11/Nov/2019:21:16:27 +0100] [Client 4] Flushing write buffer.
D [11/Nov/2019:21:16:27 +0100] [Client 4] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:27 +0100] [Client 4] Waiting for request.
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] POST /printers/MFC7420 HTTP/1.1
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=200, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] No authentication data provided.
D [11/Nov/2019:21:16:27 +0100] [Client 4] 2.0 Send-Document 5
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] [Client 4] Read: status=100, state=6
D [11/Nov/2019:21:16:27 +0100] Send-Document ipp://localhost:631/printers/MFC7420
D [11/Nov/2019:21:16:27 +0100] cupsdIsAuthorized: requesting-user-name="root"
D [11/Nov/2019:21:16:27 +0100] [Job 86] Auto-typing file...
D [11/Nov/2019:21:16:27 +0100] [Job 86] Request file type is application/postscript.
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [11/Nov/2019:21:16:27 +0100] [Job 86] File of type application/postscript queued by "root".
I [11/Nov/2019:21:16:27 +0100] [Job 86] Adding end banner page "none".
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Job 86] time-at-processing=1573503387
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Job 86] 2 filters for job:
D [11/Nov/2019:21:16:27 +0100] [Job 86] pstops (application/postscript to application/vnd.cups-postscript, cost 66)
D [11/Nov/2019:21:16:27 +0100] [Job 86] brlpdwrapperMFC7420 (application/vnd.cups-postscript to printer/MFC7420, cost 0)
D [11/Nov/2019:21:16:27 +0100] [Job 86] job-sheets=none,none
D [11/Nov/2019:21:16:27 +0100] [Job 86] argv[0]="MFC7420"
D [11/Nov/2019:21:16:27 +0100] [Job 86] argv[1]="86"
D [11/Nov/2019:21:16:27 +0100] [Job 86] argv[2]="root"
D [11/Nov/2019:21:16:27 +0100] [Job 86] argv[3]="YaST2testprint_MFC7420"
D [11/Nov/2019:21:16:27 +0100] [Job 86] argv[4]="1"
D [11/Nov/2019:21:16:27 +0100] [Job 86] argv[5]="finishings=3 number-up=1 page-label=MFC7420:YaST2testprint@linux-5ndf job-uuid=urn:uuid:2910e2b7-1b4f-3de0-51b9-c85560295cb2 job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1573503387 time-at-processing=1573503387 document-name-supplied=testprint.ps"
D [11/Nov/2019:21:16:27 +0100] [Job 86] argv[6]="/var/spool/cups/d00086-001"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[2]="CUPS_DOCROOT=/usr/share/cups/webcontent"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[7]="CUPS_STATEDIR=/run/cups"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[8]="HOME=/var/spool/cups/tmp"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[10]="SERVER_ADMIN=root@linux-5ndf"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[11]="SOFTWARE=CUPS/2.3b6"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[13]="USER=root"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[14]="CUPS_MAX_MESSAGE=2047"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[17]="IPP_PORT=631"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[18]="CHARSET=utf-8"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[19]="LANG=en.UTF-8"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[20]="PPD=/etc/cups/ppd/MFC7420.ppd"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[21]="RIP_MAX_CACHE=128m"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[22]="CONTENT_TYPE=application/postscript"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[23]="DEVICE_URI=socket://fritz.box:9100"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[24]="PRINTER_INFO=Brother MFC7420 with driver Brother MFC7420 for CUPS"

thio · 11 Nov. 2019

Teil2

Code:

D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[25]="PRINTER_LOCATION=Augsburg"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[26]="PRINTER=MFC7420"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[27]="PRINTER_STATE_REASONS=none"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[28]="CUPS_FILETYPE=document"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[29]="FINAL_CONTENT_TYPE=application/vnd.cups-postscript"
D [11/Nov/2019:21:16:27 +0100] [Job 86] envp[30]="AUTH_I****"
I [11/Nov/2019:21:16:27 +0100] [Job 86] Started filter /usr/lib/cups/filter/pstops (PID 5097)
I [11/Nov/2019:21:16:27 +0100] [Job 86] Started filter /usr/lib/cups/filter/brlpdwrapperMFC7420 (PID 5098)
I [11/Nov/2019:21:16:27 +0100] [Job 86] Started backend /usr/lib/cups/backend/socket (PID 5099)
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Client 4] Returning IPP successful-ok for Send-Document (ipp://localhost:631/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:27 +0100] [Client 4] Content-Length: 167
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:27 +0100] [Job 86] PID 5097 (/usr/lib/cups/filter/pstops) exited with no errors.
D [11/Nov/2019:21:16:27 +0100] [Client 4] con->http=0x55efe9867830
D [11/Nov/2019:21:16:27 +0100] [Client 4] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=167, response=0x55efe984d010(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:27 +0100] [Client 4] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:27 +0100] [Client 4] bytes=0, http_state=0, data_remaining=167
D [11/Nov/2019:21:16:27 +0100] [Client 4] Flushing write buffer.
D [11/Nov/2019:21:16:27 +0100] [Client 4] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:27 +0100] [Client 4] Waiting for request.
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:27 +0100] [Notifier] Connected to D-BUS
D [11/Nov/2019:21:16:27 +0100] [Notifier] JobCreated
D [11/Nov/2019:21:16:27 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:27 +0100] [Notifier] PrinterStateChanged
D [11/Nov/2019:21:16:27 +0100] [Job 86] Page = 595x842; 18,12 to 577,830
D [11/Nov/2019:21:16:27 +0100] [Job 86] slow_collate=0, slow_duplex=0, slow_order=0
D [11/Nov/2019:21:16:27 +0100] [Job 86] Before copy_comments - %!PS-Adobe-3.0
D [11/Nov/2019:21:16:27 +0100] [Job 86] %!PS-Adobe-3.0
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%BoundingBox: 0 0 612 792
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%Pages: 1
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%LanguageLevel: 1
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%DocumentData: Clean7Bit
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%DocumentSuppliedResources: procset testprint/1.3
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%DocumentNeededResources: font Helvetica Helvetica-Bold Times-Roman
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%Creator: Michael Sweet, Apple Inc. - adapted by openSUSE/Novell
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%CreationDate: D:20090113092400+0800
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%Title: Test Page
D [11/Nov/2019:21:16:27 +0100] [Job 86] %%EndComments
D [11/Nov/2019:21:16:27 +0100] [Job 86] Before copy_prolog - %%BeginProlog
D [11/Nov/2019:21:16:27 +0100] [Job 86] Before copy_setup - %%Page: 1 1
D [11/Nov/2019:21:16:27 +0100] [Job 86] Before page loop - %%Page: 1 1
D [11/Nov/2019:21:16:27 +0100] [Job 86] Copying page 1...
D [11/Nov/2019:21:16:27 +0100] [Job 86] pagew = 559.0, pagel = 818.0
D [11/Nov/2019:21:16:27 +0100] [Job 86] bboxx = 0, bboxy = 0, bboxw = 595, bboxl = 842
D [11/Nov/2019:21:16:27 +0100] [Job 86] PageLeft = 18.0, PageRight = 577.0
D [11/Nov/2019:21:16:27 +0100] [Job 86] PageTop = 830.0, PageBottom = 12.0
D [11/Nov/2019:21:16:27 +0100] [Job 86] PageWidth = 595.0, PageLength = 842.0
D [11/Nov/2019:21:16:27 +0100] [Job 86] Wrote 1 pages...
D [11/Nov/2019:21:16:27 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:27 +0100] [Notifier] JobState
D [11/Nov/2019:21:16:27 +0100] [Client 4] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:27 +0100] [Client 4] Closing connection.
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Job 86] STATE: +connecting-to-device
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:27 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:27 +0100] [Notifier] PrinterStateChanged
D [11/Nov/2019:21:16:27 +0100] [Job 86] Looking up \"fritz.box\"...
D [11/Nov/2019:21:16:27 +0100] [Job 86] STATE: -connecting-to-device
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:27 +0100] [Job 86] fritz.box=[v1.fd00::3681:c4ff:fed6:84db]
D [11/Nov/2019:21:16:27 +0100] [Job 86] fritz.box=[v1.2001:a62:4cb:b01:3681:c4ff:fed6:84db]
D [11/Nov/2019:21:16:27 +0100] [Job 86] fritz.box=192.168.178.1
D [11/Nov/2019:21:16:27 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:27 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:27 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:27 +0100] [Notifier] PrinterStateChanged
I [11/Nov/2019:21:16:28 +0100] Expiring subscriptions...
I [11/Nov/2019:21:16:29 +0100] Expiring subscriptions...
I [11/Nov/2019:21:16:30 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 5] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:31 +0100] [Client 5] Accepted from localhost:56328 (IPv6)
D [11/Nov/2019:21:16:31 +0100] [Client 5] Waiting for request.
I [11/Nov/2019:21:16:31 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:31 +0100] [Client 5] POST / HTTP/1.1
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=200, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] No authentication data provided.
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] 2.0 Get-Printer-Attributes 1
D [11/Nov/2019:21:16:31 +0100] Get-Printer-Attributes ipp://localhost:631/printers/MFC7420
D [11/Nov/2019:21:16:31 +0100] [Client 5] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:31 +0100] [Client 5] Content-Length: 1283
D [11/Nov/2019:21:16:31 +0100] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:31 +0100] [Client 5] con->http=0x55efe9867830
D [11/Nov/2019:21:16:31 +0100] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1283, response=0x55efe983f220(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:31 +0100] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:31 +0100] [Client 5] bytes=0, http_state=0, data_remaining=1283
D [11/Nov/2019:21:16:31 +0100] [Client 5] Flushing write buffer.
D [11/Nov/2019:21:16:31 +0100] [Client 5] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:31 +0100] [Client 5] Waiting for request.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 5] POST / HTTP/1.1
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=200, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] No authentication data provided.
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 5] 2.0 Get-Jobs 2
D [11/Nov/2019:21:16:31 +0100] Get-Jobs ipp://localhost/
D [11/Nov/2019:21:16:31 +0100] [Client 5] Returning IPP successful-ok for Get-Jobs (ipp://localhost/) from localhost.
D [11/Nov/2019:21:16:31 +0100] [Client 5] Content-Length: 345
D [11/Nov/2019:21:16:31 +0100] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:31 +0100] [Client 5] con->http=0x55efe9867830
D [11/Nov/2019:21:16:31 +0100] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=345, response=0x55efe983bcc0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:31 +0100] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:31 +0100] [Client 5] bytes=0, http_state=0, data_remaining=345
D [11/Nov/2019:21:16:31 +0100] [Client 5] Flushing write buffer.
D [11/Nov/2019:21:16:31 +0100] [Client 5] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:31 +0100] [Client 5] Waiting for request.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 5] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:31 +0100] [Client 5] Closing connection.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:31 +0100] [Client 6] Accepted from localhost:56330 (IPv6)
D [11/Nov/2019:21:16:31 +0100] [Client 6] Waiting for request.
D [11/Nov/2019:21:16:31 +0100] [Client 6] POST / HTTP/1.1
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=200, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] No authentication data provided.
D [11/Nov/2019:21:16:31 +0100] [Client 6] 2.0 Get-Printer-Attributes 1
D [11/Nov/2019:21:16:31 +0100] Get-Printer-Attributes ipp://localhost:631/printers/MFC7420
D [11/Nov/2019:21:16:31 +0100] [Client 6] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:31 +0100] [Client 6] Content-Length: 1283
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] con->http=0x55efe9867830
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1283, response=0x55efe983f1b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:31 +0100] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] bytes=0, http_state=0, data_remaining=1283
D [11/Nov/2019:21:16:31 +0100] [Client 6] Flushing write buffer.
D [11/Nov/2019:21:16:31 +0100] [Client 6] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:31 +0100] [Client 6] Waiting for request.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] POST / HTTP/1.1
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=200, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] No authentication data provided.
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] 2.0 Get-Jobs 2
D [11/Nov/2019:21:16:31 +0100] Get-Jobs ipp://localhost/
D [11/Nov/2019:21:16:31 +0100] [Client 6] Returning IPP successful-ok for Get-Jobs (ipp://localhost/) from localhost.
D [11/Nov/2019:21:16:31 +0100] [Client 6] Content-Length: 345
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] con->http=0x55efe9867830
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=345, response=0x55efe983bcc0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:31 +0100] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] bytes=0, http_state=0, data_remaining=345
D [11/Nov/2019:21:16:31 +0100] [Client 6] Flushing write buffer.
D [11/Nov/2019:21:16:31 +0100] [Client 6] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:31 +0100] [Client 6] Waiting for request.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] POST / HTTP/1.1
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=200, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] No authentication data provided.
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=100, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] 2.0 Get-Printer-Attributes 3
D [11/Nov/2019:21:16:31 +0100] Get-Printer-Attributes ipp://localhost:631/printers/MFC7420
D [11/Nov/2019:21:16:31 +0100] [Client 6] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost:631/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:31 +0100] [Client 6] Content-Length: 1283
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] con->http=0x55efe9867830
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1283, response=0x55efe983f1b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:31 +0100] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] bytes=0, http_state=0, data_remaining=1283
D [11/Nov/2019:21:16:31 +0100] [Client 6] Flushing write buffer.
D [11/Nov/2019:21:16:31 +0100] [Client 6] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:31 +0100] [Client 6] Waiting for request.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] POST / HTTP/1.1
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=200, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] No authentication data provided.
D [11/Nov/2019:21:16:31 +0100] [Client 6] 2.0 CUPS-Get-Printers 4
D [11/Nov/2019:21:16:31 +0100] CUPS-Get-Printers
D [11/Nov/2019:21:16:31 +0100] [Client 6] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [11/Nov/2019:21:16:31 +0100] [Client 6] Content-Length: 1119
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] con->http=0x55efe9867830
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1119, response=0x55efe983bcc0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:31 +0100] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] bytes=0, http_state=0, data_remaining=1119
D [11/Nov/2019:21:16:31 +0100] [Client 6] Flushing write buffer.
D [11/Nov/2019:21:16:31 +0100] [Client 6] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:31 +0100] [Client 6] Waiting for request.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] POST / HTTP/1.1
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] Read: status=200, state=6
D [11/Nov/2019:21:16:31 +0100] [Client 6] No authentication data provided.
D [11/Nov/2019:21:16:31 +0100] [Client 6] 2.0 Get-Jobs 1
D [11/Nov/2019:21:16:31 +0100] Get-Jobs ipp://localhost/printers/MFC7420
D [11/Nov/2019:21:16:31 +0100] [Client 6] Returning IPP successful-ok for Get-Jobs (ipp://localhost/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:31 +0100] [Client 6] Content-Length: 106
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] con->http=0x55efe9867830
D [11/Nov/2019:21:16:31 +0100] [Client 6] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=106, response=0x55efe983f1b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:31 +0100] [Client 6] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:31 +0100] [Client 6] bytes=0, http_state=0, data_remaining=106
D [11/Nov/2019:21:16:31 +0100] [Client 6] Flushing write buffer.
D [11/Nov/2019:21:16:31 +0100] [Client 6] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:31 +0100] [Client 6] Waiting for request.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:31 +0100] [Client 6] Closing connection.
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Job 86] prtGeneralCurrentLocalization type is 0, expected 2!
D [11/Nov/2019:21:16:31 +0100] [Job 86] backendWaitLoop(snmp_fd=5, addr=0x5578c4dd09c8, side_cb=0x5578c33df5b0)
D [11/Nov/2019:21:16:31 +0100] [Job 86] Connecting to fritz.box:9100
D [11/Nov/2019:21:16:31 +0100] [Job 86] Connecting to printer.
D [11/Nov/2019:21:16:31 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Job 86] Set job-printer-state-message to "Connecting to printer.", current level=INFO
D [11/Nov/2019:21:16:31 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:31 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:31 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:31 +0100] [Notifier] JobProgress
D [11/Nov/2019:21:16:31 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:31 +0100] [Notifier] PrinterStateChanged
I [11/Nov/2019:21:16:32 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 7] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:35 +0100] [Client 7] Accepted from localhost:56338 (IPv6)
D [11/Nov/2019:21:16:35 +0100] [Client 7] Waiting for request.
I [11/Nov/2019:21:16:35 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:35 +0100] [Client 7] POST / HTTP/1.1
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 7] Read: status=200, state=6
D [11/Nov/2019:21:16:35 +0100] [Client 7] No authentication data provided.
D [11/Nov/2019:21:16:35 +0100] [Client 7] 2.0 CUPS-Get-Default 1
D [11/Nov/2019:21:16:35 +0100] CUPS-Get-Default
D [11/Nov/2019:21:16:35 +0100] [Client 7] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [11/Nov/2019:21:16:35 +0100] [Client 7] Content-Length: 9246
D [11/Nov/2019:21:16:35 +0100] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:35 +0100] [Client 7] con->http=0x55efe9867830
D [11/Nov/2019:21:16:35 +0100] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9246, response=0x55efe98544a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:35 +0100] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:35 +0100] [Client 7] bytes=0, http_state=0, data_remaining=9246
D [11/Nov/2019:21:16:35 +0100] [Client 7] Flushing write buffer.
D [11/Nov/2019:21:16:35 +0100] [Client 7] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:35 +0100] [Client 7] Waiting for request.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 7] POST / HTTP/1.1
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 7] Read: status=200, state=6
D [11/Nov/2019:21:16:35 +0100] [Client 7] No authentication data provided.
D [11/Nov/2019:21:16:35 +0100] [Client 7] 2.0 CUPS-Get-Printers 2
D [11/Nov/2019:21:16:35 +0100] CUPS-Get-Printers
D [11/Nov/2019:21:16:35 +0100] [Client 7] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [11/Nov/2019:21:16:35 +0100] [Client 7] Content-Length: 3755
D [11/Nov/2019:21:16:35 +0100] [Client 7] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:35 +0100] [Client 7] con->http=0x55efe9867830
D [11/Nov/2019:21:16:35 +0100] [Client 7] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=3755, response=0x55efe98562a0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:35 +0100] [Client 7] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:35 +0100] [Client 7] bytes=0, http_state=0, data_remaining=3755
D [11/Nov/2019:21:16:35 +0100] [Client 7] Flushing write buffer.
D [11/Nov/2019:21:16:35 +0100] [Client 7] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:35 +0100] [Client 7] Waiting for request.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 8] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:35 +0100] [Client 8] Accepted from localhost:56340 (IPv6)
D [11/Nov/2019:21:16:35 +0100] [Client 8] Waiting for request.
D [11/Nov/2019:21:16:35 +0100] [Client 8] POST /admin/ HTTP/1.1
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 8] Read: status=200, state=6
D [11/Nov/2019:21:16:35 +0100] [Client 8] No authentication data provided.
D [11/Nov/2019:21:16:35 +0100] [Client 8] 2.0 Cancel-Jobs 3
D [11/Nov/2019:21:16:35 +0100] Cancel-Jobs ipp://localhost/printers/MFC7420
D [11/Nov/2019:21:16:35 +0100] cupsdIsAuthorized: username=""
D [11/Nov/2019:21:16:35 +0100] [Client 8] Returning HTTP Unauthorized for Cancel-Jobs (ipp://localhost/printers/MFC7420) from localhost
D [11/Nov/2019:21:16:35 +0100] [Client 8] cupsdSendHeader: code=401, type="text/html", auth_type=1
D [11/Nov/2019:21:16:35 +0100] [Client 8] WWW-Authenticate: Basic realm=\"CUPS\", Local trc=\"y\"
D [11/Nov/2019:21:16:35 +0100] [Client 8] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:35 +0100] [Client 8] Closing connection.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 9] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:35 +0100] [Client 9] Accepted from localhost:56342 (IPv6)
D [11/Nov/2019:21:16:35 +0100] [Client 9] Waiting for request.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 10] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:35 +0100] [Client 10] Accepted from localhost:56344 (IPv6)
D [11/Nov/2019:21:16:35 +0100] [Client 10] Waiting for request.
D [11/Nov/2019:21:16:35 +0100] [Client 9] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:35 +0100] [Client 9] Closing connection.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 11] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:35 +0100] [Client 11] Accepted from localhost:56346 (IPv6)
D [11/Nov/2019:21:16:35 +0100] [Client 11] Waiting for request.
D [11/Nov/2019:21:16:35 +0100] [Client 10] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:35 +0100] [Client 10] Closing connection.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 11] POST /admin/ HTTP/1.1
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 11] Read: status=200, state=6
D [11/Nov/2019:21:16:35 +0100] [Client 11] Authorized as root using Local.
D [11/Nov/2019:21:16:35 +0100] [Client 11] 2.0 Cancel-Jobs 3
D [11/Nov/2019:21:16:35 +0100] Cancel-Jobs ipp://localhost/printers/MFC7420
D [11/Nov/2019:21:16:35 +0100] cupsdIsAuthorized: username="root"
D [11/Nov/2019:21:16:35 +0100] [Job 86] time-at-completed=1573503395
D [11/Nov/2019:21:16:35 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
I [11/Nov/2019:21:16:35 +0100] [Job 86] Job canceled by user.
I [11/Nov/2019:21:16:35 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:35 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients, printing jobs, and dirty files"
I [11/Nov/2019:21:16:35 +0100] All jobs on "MFC7420" were canceled by "root".
D [11/Nov/2019:21:16:35 +0100] [Client 11] Returning IPP successful-ok for Cancel-Jobs (ipp://localhost/printers/MFC7420) from localhost.
D [11/Nov/2019:21:16:35 +0100] [Client 11] Content-Length: 72
D [11/Nov/2019:21:16:35 +0100] [Client 11] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:35 +0100] [Job 86] PID 5098 (/usr/lib/cups/filter/brlpdwrapperMFC7420) was terminated normally with signal 15.
D [11/Nov/2019:21:16:35 +0100] [Job 86] PID 5099 (/usr/lib/cups/backend/socket) was terminated normally with signal 15.
D [11/Nov/2019:21:16:35 +0100] [Client 11] con->http=0x55efe986c6a0
D [11/Nov/2019:21:16:35 +0100] [Client 11] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=72, response=0x55efe9892350(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:35 +0100] [Client 11] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:35 +0100] [Client 11] bytes=0, http_state=0, data_remaining=72
D [11/Nov/2019:21:16:35 +0100] [Client 11] Flushing write buffer.
D [11/Nov/2019:21:16:35 +0100] [Client 11] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:35 +0100] [Client 11] Waiting for request.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [11/Nov/2019:21:16:35 +0100] cupsdMarkDirty(----S)
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] cupsdMarkDirty(---J-)
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:35 +0100] [Notifier] JobCompleted
D [11/Nov/2019:21:16:35 +0100] [Client 11] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:35 +0100] [Client 11] Closing connection.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [11/Nov/2019:21:16:35 +0100] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:35 +0100] [Client 7] Closing connection.
D [11/Nov/2019:21:16:35 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:35 +0100] [Notifier] state=3
D [11/Nov/2019:21:16:35 +0100] [Notifier] PrinterStateChanged
I [11/Nov/2019:21:16:36 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:36 +0100] [Job 86] Unloading...
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 12] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:41 +0100] [Client 12] Accepted from localhost:56348 (IPv6)
D [11/Nov/2019:21:16:41 +0100] [Client 12] Waiting for request.
I [11/Nov/2019:21:16:41 +0100] Expiring subscriptions...
D [11/Nov/2019:21:16:41 +0100] [Client 12] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:41 +0100] [Client 12] Closing connection.
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 13] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:41 +0100] [Client 13] Accepted from localhost:56350 (IPv6)
D [11/Nov/2019:21:16:41 +0100] [Client 13] Waiting for request.
D [11/Nov/2019:21:16:41 +0100] [Client 13] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [11/Nov/2019:21:16:41 +0100] [Client 13] Closing connection.
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 14] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:41 +0100] [Client 14] Accepted from localhost:56352 (IPv6)
D [11/Nov/2019:21:16:41 +0100] [Client 14] Waiting for request.
D [11/Nov/2019:21:16:41 +0100] [Client 14] POST / HTTP/1.1
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=200, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] No authentication data provided.
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] 2.0 CUPS-Get-Default 1
D [11/Nov/2019:21:16:41 +0100] CUPS-Get-Default
D [11/Nov/2019:21:16:41 +0100] [Client 14] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [11/Nov/2019:21:16:41 +0100] [Client 14] Content-Length: 9224
D [11/Nov/2019:21:16:41 +0100] [Client 14] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:41 +0100] [Client 14] con->http=0x55efe986c6a0
D [11/Nov/2019:21:16:41 +0100] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9224, response=0x55efe9844a30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:41 +0100] [Client 14] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:41 +0100] [Client 14] bytes=0, http_state=0, data_remaining=9224
D [11/Nov/2019:21:16:41 +0100] [Client 14] Flushing write buffer.
D [11/Nov/2019:21:16:41 +0100] [Client 14] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:41 +0100] [Client 14] Waiting for request.
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 14] POST / HTTP/1.1
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=200, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] No authentication data provided.
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] Read: status=100, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 14] 2.0 CUPS-Get-Printers 2
D [11/Nov/2019:21:16:41 +0100] CUPS-Get-Printers
D [11/Nov/2019:21:16:41 +0100] [Client 14] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [11/Nov/2019:21:16:41 +0100] [Client 14] Content-Length: 3755
D [11/Nov/2019:21:16:41 +0100] [Client 14] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:41 +0100] [Client 14] con->http=0x55efe986c6a0
D [11/Nov/2019:21:16:41 +0100] [Client 14] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=3755, response=0x55efe98543d0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:41 +0100] [Client 14] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:41 +0100] [Client 14] bytes=0, http_state=0, data_remaining=3755
D [11/Nov/2019:21:16:41 +0100] [Client 14] Flushing write buffer.
D [11/Nov/2019:21:16:41 +0100] [Client 14] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:41 +0100] [Client 14] Waiting for request.
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 15] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:41 +0100] [Client 15] Accepted from localhost:56354 (IPv6)
D [11/Nov/2019:21:16:41 +0100] [Client 15] Waiting for request.
D [11/Nov/2019:21:16:41 +0100] [Client 15] POST / HTTP/1.1
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 15] Read: status=200, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 15] No authentication data provided.
D [11/Nov/2019:21:16:41 +0100] [Client 15] 2.0 CUPS-Get-Default 1
D [11/Nov/2019:21:16:41 +0100] CUPS-Get-Default
D [11/Nov/2019:21:16:41 +0100] [Client 15] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [11/Nov/2019:21:16:41 +0100] [Client 15] Content-Length: 9224
D [11/Nov/2019:21:16:41 +0100] [Client 15] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:41 +0100] [Client 15] con->http=0x55efe9866670
D [11/Nov/2019:21:16:41 +0100] [Client 15] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9224, response=0x55efe983a000(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:41 +0100] [Client 15] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [11/Nov/2019:21:16:41 +0100] [Client 15] bytes=0, http_state=0, data_remaining=9224
D [11/Nov/2019:21:16:41 +0100] [Client 15] Flushing write buffer.
D [11/Nov/2019:21:16:41 +0100] [Client 15] New state is HTTP_STATE_WAITING
D [11/Nov/2019:21:16:41 +0100] [Client 15] Waiting for request.
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 16] Server address is "[v1.::1]".
D [11/Nov/2019:21:16:41 +0100] [Client 16] Accepted from localhost:56356 (IPv6)
D [11/Nov/2019:21:16:41 +0100] [Client 16] Waiting for request.
D [11/Nov/2019:21:16:41 +0100] [Client 16] POST / HTTP/1.1
D [11/Nov/2019:21:16:41 +0100] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [11/Nov/2019:21:16:41 +0100] [Client 16] Read: status=200, state=6
D [11/Nov/2019:21:16:41 +0100] [Client 16] No authentication data provided.
D [11/Nov/2019:21:16:41 +0100] [Client 16] 2.0 CUPS-Get-Default 1
D [11/Nov/2019:21:16:41 +0100] CUPS-Get-Default
D [11/Nov/2019:21:16:41 +0100] [Client 16] Returning IPP successful-ok for CUPS-Get-Default (no URI) from localhost.
D [11/Nov/2019:21:16:41 +0100] [Client 16] Content-Length: 9224
D [11/Nov/2019:21:16:41 +0100] [Client 16] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [11/Nov/2019:21:16:41 +0100] [Client 16] con->http=0x55efe98b51a0
D [11/Nov/2019:21:16:41 +0100] [Client 16] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=9224, response=0x55efe9847660(IPP_STATE_DATA), pipe_pid=0, file=-1
D [11/Nov/2019:21:16:41 +0100] [Client 16] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0