Du bist nicht angemeldet.

#1 21.09.2020 10:48:29

ransome
Mitglied

CUPS: Angeblich erfolgreicher Druck, jedoch ohne Output

Hallo zusammen,

nach zwei wirklich anstrengenden und frustrierenden Abenden im Arch Wiki und dem Rest des Interwebs wende ich mich mit Hundeaugen an Euch.
uname -a

Linux thinkpad 5.4.66-1-lts #1 SMP Thu, 17 Sep 2020 18:00:06 +0000 x86_64 GNU/Linux

Ich habe CUPS nach der Anleitung im Wiki installiert und anschließend meinen Drucker (Canon MF4140 Multifunktionsgerät) über die Weboberfläche hinzugefügt, alle Drucker-Einstellungen auf Default gelassen und ihn als Standarddrucker deklariert.

Die passende PPD habe ich aus dem offiziellen und passenden Canon Treiber (MF 4100 Series) per rpmextract gezogen. Der Drucker ist leider nicht Teil von gutenprint, weshalb ich dieses Paket zwar installiert habe, aber nicht nutze.

Ich habe dem Troubleshooting zufolge auch ghostscript, lib32-libstdc++5 und lib32-glibc installiert.

Auch das usblp Modul habe ich in ""/etc/modprobe.d/blacklistusblp.conf" auf die Blacklist gesetzt, wobei dies vermutlich nicht nötig ist.

Auf den ersten Blick sieht alles gut aus. Der Drucker ist direkt per USB-Kabel am Rechner angeschlossen.

Nun drucke ich, egal ob aus einem Text-Dokument, einem PDF, einem Bild oder einer Website und das CUPS Backend attestiert mir der Druck sei " beendet am", was auf einen erfolgreichen Druck hinweist, wenn ich das richtig deute.

In der CUPS Config habe ich den debugLevel auf "debug" gestellt und hier beispielhaft einmal der Mitschnitt für einen dieser "erfolgreichen" Ausdrucke, der aber eigentlich gar nichts zu Papier bringt:
access_log

localhost - - [21/Sep/2020:10:30:26 +0200] "POST /printers/Canon_MF4100_Series HTTP/1.1" 200 5305 Print-Job successful-ok

error_log

D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:17 +0200] [Client 245] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:17 +0200] [Client 245] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:17 +0200] [Client 245] Waiting for request.
I [21/Sep/2020:10:32:17 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:17 +0200] Report: clients=1
D [21/Sep/2020:10:32:17 +0200] Report: jobs=11
D [21/Sep/2020:10:32:17 +0200] Report: jobs-active=0
D [21/Sep/2020:10:32:17 +0200] Report: printers=1
D [21/Sep/2020:10:32:17 +0200] Report: stringpool-string-count=1673
D [21/Sep/2020:10:32:17 +0200] Report: stringpool-alloc-bytes=8032
D [21/Sep/2020:10:32:17 +0200] Report: stringpool-total-bytes=35072
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 246] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:17 +0200] [Client 246] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:17 +0200] [Client 246] Waiting for request.
D [21/Sep/2020:10:32:17 +0200] [Client 245] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:17 +0200] [Client 245] Closing connection.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 246] POST / HTTP/1.1
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=200, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] No authentication data provided.
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 246] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:17 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:17 +0200] [Client 246] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:17 +0200] [Client 246] Content-Length: 928
D [21/Sep/2020:10:32:17 +0200] [Client 246] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:17 +0200] [Client 246] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:17 +0200] [Client 246] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd0730(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:17 +0200] [Client 246] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:17 +0200] [Client 246] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:17 +0200] [Client 246] Flushing write buffer.
D [21/Sep/2020:10:32:17 +0200] [Client 246] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:17 +0200] [Client 246] Waiting for request.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 246] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:17 +0200] [Client 246] Closing connection.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:17 +0200] [Client 247] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:17 +0200] [Client 247] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:17 +0200] [Client 247] Waiting for request.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 248] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:17 +0200] [Client 248] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:17 +0200] [Client 248] Waiting for request.
D [21/Sep/2020:10:32:17 +0200] [Client 247] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:17 +0200] [Client 247] Closing connection.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 248] POST / HTTP/1.1
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=200, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] No authentication data provided.
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] Read: status=100, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 248] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:17 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:17 +0200] [Client 248] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:17 +0200] [Client 248] Content-Length: 928
D [21/Sep/2020:10:32:17 +0200] [Client 248] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:17 +0200] [Client 248] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:17 +0200] [Client 248] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:17 +0200] [Client 248] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:17 +0200] [Client 248] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:17 +0200] [Client 248] Flushing write buffer.
D [21/Sep/2020:10:32:17 +0200] [Client 248] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:17 +0200] [Client 248] Waiting for request.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 248] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:17 +0200] [Client 248] Closing connection.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:17 +0200] [Client 249] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:17 +0200] [Client 249] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:17 +0200] [Client 249] Waiting for request.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 250] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:17 +0200] [Client 250] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:17 +0200] [Client 250] Waiting for request.
D [21/Sep/2020:10:32:17 +0200] [Client 249] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:17 +0200] [Client 249] Closing connection.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 250] POST / HTTP/1.1
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:17 +0200] [Client 250] Read: status=200, state=6
D [21/Sep/2020:10:32:17 +0200] [Client 250] No authentication data provided.
D [21/Sep/2020:10:32:17 +0200] [Client 250] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:17 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:17 +0200] [Client 250] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:17 +0200] [Client 250] Content-Length: 928
D [21/Sep/2020:10:32:17 +0200] [Client 250] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:17 +0200] [Client 250] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:17 +0200] [Client 250] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:17 +0200] [Client 250] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:17 +0200] [Client 250] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:17 +0200] [Client 250] Flushing write buffer.
D [21/Sep/2020:10:32:17 +0200] [Client 250] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:17 +0200] [Client 250] Waiting for request.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:17 +0200] [Client 250] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:17 +0200] [Client 250] Closing connection.
D [21/Sep/2020:10:32:17 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 251] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 251] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 251] Waiting for request.
I [21/Sep/2020:10:32:18 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 252] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 252] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 252] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] [Client 251] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 251] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 252] POST / HTTP/1.1
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=200, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] No authentication data provided.
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] Read: status=100, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 252] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:18 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:18 +0200] [Client 252] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:18 +0200] [Client 252] Content-Length: 928
D [21/Sep/2020:10:32:18 +0200] [Client 252] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:18 +0200] [Client 252] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:18 +0200] [Client 252] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:18 +0200] [Client 252] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:18 +0200] [Client 252] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:18 +0200] [Client 252] Flushing write buffer.
D [21/Sep/2020:10:32:18 +0200] [Client 252] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:18 +0200] [Client 252] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 252] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 252] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 253] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 253] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 253] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 254] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 254] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 254] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] [Client 253] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 253] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 254] POST / HTTP/1.1
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 254] Read: status=200, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 254] No authentication data provided.
D [21/Sep/2020:10:32:18 +0200] [Client 254] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:18 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:18 +0200] [Client 254] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:18 +0200] [Client 254] Content-Length: 928
D [21/Sep/2020:10:32:18 +0200] [Client 254] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:18 +0200] [Client 254] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:18 +0200] [Client 254] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd0730(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:18 +0200] [Client 254] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:18 +0200] [Client 254] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:18 +0200] [Client 254] Flushing write buffer.
D [21/Sep/2020:10:32:18 +0200] [Client 254] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:18 +0200] [Client 254] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 254] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 254] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 255] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 255] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 255] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 256] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 256] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 256] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] [Client 255] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 255] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 256] POST / HTTP/1.1
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 256] Read: status=200, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 256] No authentication data provided.
D [21/Sep/2020:10:32:18 +0200] [Client 256] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:18 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:18 +0200] [Client 256] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:18 +0200] [Client 256] Content-Length: 928
D [21/Sep/2020:10:32:18 +0200] [Client 256] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:18 +0200] [Client 256] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:18 +0200] [Client 256] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:18 +0200] [Client 256] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:18 +0200] [Client 256] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:18 +0200] [Client 256] Flushing write buffer.
D [21/Sep/2020:10:32:18 +0200] [Client 256] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:18 +0200] [Client 256] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 256] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 256] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 257] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 257] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 257] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 258] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 258] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 258] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] [Client 257] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 257] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 258] POST / HTTP/1.1
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 258] Read: status=200, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 258] No authentication data provided.
D [21/Sep/2020:10:32:18 +0200] [Client 258] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:18 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:18 +0200] [Client 258] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:18 +0200] [Client 258] Content-Length: 928
D [21/Sep/2020:10:32:18 +0200] [Client 258] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:18 +0200] [Client 258] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:18 +0200] [Client 258] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:18 +0200] [Client 258] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:18 +0200] [Client 258] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:18 +0200] [Client 258] Flushing write buffer.
D [21/Sep/2020:10:32:18 +0200] [Client 258] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:18 +0200] [Client 258] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 258] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 258] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 259] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 259] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 259] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 260] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:18 +0200] [Client 260] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:18 +0200] [Client 260] Waiting for request.
D [21/Sep/2020:10:32:18 +0200] [Client 259] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:18 +0200] [Client 259] Closing connection.
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:18 +0200] [Client 260] POST / HTTP/1.1
D [21/Sep/2020:10:32:18 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:18 +0200] [Client 260] Read: status=200, state=6
D [21/Sep/2020:10:32:18 +0200] [Client 260] No authentication data provided.
D [21/Sep/2020:10:32:18 +0200] [Client 260] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:19 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:19 +0200] [Client 260] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:19 +0200] [Client 260] Content-Length: 928
D [21/Sep/2020:10:32:19 +0200] [Client 260] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:19 +0200] [Client 260] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:19 +0200] [Client 260] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:19 +0200] [Client 260] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:19 +0200] [Client 260] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:19 +0200] [Client 260] Flushing write buffer.
D [21/Sep/2020:10:32:19 +0200] [Client 260] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:19 +0200] [Client 260] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 260] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 260] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] [Client 261] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:19 +0200] [Client 261] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:19 +0200] [Client 261] Waiting for request.
I [21/Sep/2020:10:32:19 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 262] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:19 +0200] [Client 262] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:19 +0200] [Client 262] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] [Client 261] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 261] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 262] POST / HTTP/1.1
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] [Client 262] Read: status=200, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 262] No authentication data provided.
D [21/Sep/2020:10:32:19 +0200] [Client 262] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:19 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:19 +0200] [Client 262] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:19 +0200] [Client 262] Content-Length: 928
D [21/Sep/2020:10:32:19 +0200] [Client 262] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:19 +0200] [Client 262] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:19 +0200] [Client 262] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd0730(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:19 +0200] [Client 262] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:19 +0200] [Client 262] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:19 +0200] [Client 262] Flushing write buffer.
D [21/Sep/2020:10:32:19 +0200] [Client 262] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:19 +0200] [Client 262] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 262] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 262] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] [Client 263] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:19 +0200] [Client 263] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:19 +0200] [Client 263] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 264] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:19 +0200] [Client 264] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:19 +0200] [Client 264] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] [Client 263] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 263] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 264] POST / HTTP/1.1
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] [Client 264] Read: status=200, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 264] No authentication data provided.
D [21/Sep/2020:10:32:19 +0200] [Client 264] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:19 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:19 +0200] [Client 264] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:19 +0200] [Client 264] Content-Length: 928
D [21/Sep/2020:10:32:19 +0200] [Client 264] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:19 +0200] [Client 264] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:19 +0200] [Client 264] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:19 +0200] [Client 264] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:19 +0200] [Client 264] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:19 +0200] [Client 264] Flushing write buffer.
D [21/Sep/2020:10:32:19 +0200] [Client 264] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:19 +0200] [Client 264] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 264] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 264] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] [Client 265] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:19 +0200] [Client 265] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:19 +0200] [Client 265] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 266] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:19 +0200] [Client 266] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:19 +0200] [Client 266] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] [Client 265] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 265] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 266] POST / HTTP/1.1
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=200, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] No authentication data provided.
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] Read: status=100, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 266] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:19 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:19 +0200] [Client 266] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:19 +0200] [Client 266] Content-Length: 928
D [21/Sep/2020:10:32:19 +0200] [Client 266] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:19 +0200] [Client 266] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:19 +0200] [Client 266] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd0730(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:19 +0200] [Client 266] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:19 +0200] [Client 266] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:19 +0200] [Client 266] Flushing write buffer.
D [21/Sep/2020:10:32:19 +0200] [Client 266] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:19 +0200] [Client 266] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 266] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 266] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] [Client 267] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:19 +0200] [Client 267] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:19 +0200] [Client 267] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 268] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:19 +0200] [Client 268] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:19 +0200] [Client 268] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] [Client 267] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 267] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 268] POST / HTTP/1.1
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:19 +0200] [Client 268] Read: status=200, state=6
D [21/Sep/2020:10:32:19 +0200] [Client 268] No authentication data provided.
D [21/Sep/2020:10:32:19 +0200] [Client 268] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:19 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:19 +0200] [Client 268] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:19 +0200] [Client 268] Content-Length: 928
D [21/Sep/2020:10:32:19 +0200] [Client 268] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:19 +0200] [Client 268] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:19 +0200] [Client 268] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:19 +0200] [Client 268] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:19 +0200] [Client 268] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:19 +0200] [Client 268] Flushing write buffer.
D [21/Sep/2020:10:32:19 +0200] [Client 268] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:19 +0200] [Client 268] Waiting for request.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:19 +0200] [Client 268] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:19 +0200] [Client 268] Closing connection.
D [21/Sep/2020:10:32:19 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 269] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 269] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 269] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 270] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 270] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 270] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] [Client 269] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 269] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 270] POST / HTTP/1.1
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 270] Read: status=200, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 270] No authentication data provided.
D [21/Sep/2020:10:32:20 +0200] [Client 270] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:20 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:20 +0200] [Client 270] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:20 +0200] [Client 270] Content-Length: 928
D [21/Sep/2020:10:32:20 +0200] [Client 270] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:20 +0200] [Client 270] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:20 +0200] [Client 270] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:20 +0200] [Client 270] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:20 +0200] [Client 270] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:20 +0200] [Client 270] Flushing write buffer.
D [21/Sep/2020:10:32:20 +0200] [Client 270] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:20 +0200] [Client 270] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
I [21/Sep/2020:10:32:20 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:20 +0200] [Client 270] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 270] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 271] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 271] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 271] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] [Client 271] GET /printers/Canon_MF4100_Series.ppd HTTP/1.1
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 271] Read: status=200, state=3
D [21/Sep/2020:10:32:20 +0200] [Client 271] No authentication data provided.
D [21/Sep/2020:10:32:20 +0200] [Client 271] Processing GET /printers/Canon_MF4100_Series.ppd
D [21/Sep/2020:10:32:20 +0200] [Client 271] cupsdSendHeader: code=404, type="text/html", auth_type=0
D [21/Sep/2020:10:32:20 +0200] [Client 271] Closing because Keep-Alive is disabled.
D [21/Sep/2020:10:32:20 +0200] [Client 271] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 272] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 272] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 272] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] [Client 272] POST / HTTP/1.1
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=200, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] No authentication data provided.
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] Read: status=100, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 272] 1.1 Get-Printer-Attributes 1
D [21/Sep/2020:10:32:20 +0200] Get-Printer-Attributes ipp://localhost/printers/Canon_MF4100_Series
D [21/Sep/2020:10:32:20 +0200] [Client 272] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Canon_MF4100_Series) from localhost.
D [21/Sep/2020:10:32:20 +0200] [Client 272] Content-Length: 1009
D [21/Sep/2020:10:32:20 +0200] [Client 272] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:20 +0200] [Client 272] con->http=0x560f9df50900
D [21/Sep/2020:10:32:20 +0200] [Client 272] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=1009, response=0x560f9df43f70(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:20 +0200] [Client 272] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:20 +0200] [Client 272] bytes=0, http_state=0, data_remaining=1009
D [21/Sep/2020:10:32:20 +0200] [Client 272] Flushing write buffer.
D [21/Sep/2020:10:32:20 +0200] [Client 272] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:20 +0200] [Client 272] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 272] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 272] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 273] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 273] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 273] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 274] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 274] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 274] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] [Client 273] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 273] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 274] POST / HTTP/1.1
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 274] Read: status=200, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 274] No authentication data provided.
D [21/Sep/2020:10:32:20 +0200] [Client 274] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:20 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:20 +0200] [Client 274] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:20 +0200] [Client 274] Content-Length: 928
D [21/Sep/2020:10:32:20 +0200] [Client 274] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:20 +0200] [Client 274] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:20 +0200] [Client 274] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd0730(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:20 +0200] [Client 274] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:20 +0200] [Client 274] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:20 +0200] [Client 274] Flushing write buffer.
D [21/Sep/2020:10:32:20 +0200] [Client 274] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:20 +0200] [Client 274] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 274] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 274] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 275] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 275] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 275] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 276] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 276] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 276] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] [Client 275] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 275] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 276] POST / HTTP/1.1
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 276] Read: status=200, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 276] No authentication data provided.
D [21/Sep/2020:10:32:20 +0200] [Client 276] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:20 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:20 +0200] [Client 276] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:20 +0200] [Client 276] Content-Length: 928
D [21/Sep/2020:10:32:20 +0200] [Client 276] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:20 +0200] [Client 276] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:20 +0200] [Client 276] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd0730(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:20 +0200] [Client 276] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:20 +0200] [Client 276] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:20 +0200] [Client 276] Flushing write buffer.
D [21/Sep/2020:10:32:20 +0200] [Client 276] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:20 +0200] [Client 276] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 276] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 276] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 277] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 277] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 277] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 278] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 278] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 278] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] [Client 277] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 277] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 278] POST / HTTP/1.1
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 278] Read: status=200, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 278] No authentication data provided.
D [21/Sep/2020:10:32:20 +0200] [Client 278] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:20 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:20 +0200] [Client 278] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:20 +0200] [Client 278] Content-Length: 928
D [21/Sep/2020:10:32:20 +0200] [Client 278] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:20 +0200] [Client 278] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:20 +0200] [Client 278] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:20 +0200] [Client 278] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:20 +0200] [Client 278] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:20 +0200] [Client 278] Flushing write buffer.
D [21/Sep/2020:10:32:20 +0200] [Client 278] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:20 +0200] [Client 278] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 278] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 278] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 279] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 279] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 279] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 280] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:20 +0200] [Client 280] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:20 +0200] [Client 280] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] [Client 279] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 279] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 280] POST / HTTP/1.1
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:20 +0200] [Client 280] Read: status=200, state=6
D [21/Sep/2020:10:32:20 +0200] [Client 280] No authentication data provided.
D [21/Sep/2020:10:32:20 +0200] [Client 280] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:20 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:20 +0200] [Client 280] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:20 +0200] [Client 280] Content-Length: 928
D [21/Sep/2020:10:32:20 +0200] [Client 280] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:20 +0200] [Client 280] con->http=0x560f9df53fa0
D [21/Sep/2020:10:32:20 +0200] [Client 280] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd0730(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:20 +0200] [Client 280] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:20 +0200] [Client 280] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:20 +0200] [Client 280] Flushing write buffer.
D [21/Sep/2020:10:32:20 +0200] [Client 280] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:20 +0200] [Client 280] Waiting for request.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:20 +0200] [Client 280] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:20 +0200] [Client 280] Closing connection.
D [21/Sep/2020:10:32:20 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:21 +0200] [Client 281] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:21 +0200] [Client 281] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:21 +0200] [Client 281] Waiting for request.
I [21/Sep/2020:10:32:21 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:21 +0200] [Client 281] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:21 +0200] [Client 281] Closing connection.
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:21 +0200] [Client 282] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:21 +0200] [Client 282] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:21 +0200] [Client 282] Waiting for request.
D [21/Sep/2020:10:32:21 +0200] [Client 282] POST / HTTP/1.1
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=200, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] No authentication data provided.
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 282] 2.0 CUPS-Get-Printers 1
D [21/Sep/2020:10:32:21 +0200] CUPS-Get-Printers
D [21/Sep/2020:10:32:21 +0200] [Client 282] Returning IPP successful-ok for CUPS-Get-Printers (no URI) from localhost.
D [21/Sep/2020:10:32:21 +0200] [Client 282] Content-Length: 928
D [21/Sep/2020:10:32:21 +0200] [Client 282] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:21 +0200] [Client 282] con->http=0x560f9df50900
D [21/Sep/2020:10:32:21 +0200] [Client 282] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=928, response=0x560f9dfd4f30(IPP_STATE_DATA), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:21 +0200] [Client 282] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:21 +0200] [Client 282] bytes=0, http_state=0, data_remaining=928
D [21/Sep/2020:10:32:21 +0200] [Client 282] Flushing write buffer.
D [21/Sep/2020:10:32:21 +0200] [Client 282] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:21 +0200] [Client 282] Waiting for request.
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Active clients"
D [21/Sep/2020:10:32:21 +0200] [Client 282] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:21 +0200] [Client 282] Closing connection.
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Not busy"
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [21/Sep/2020:10:32:21 +0200] [Client 283] Server address is "/run/cups/cups.sock".
D [21/Sep/2020:10:32:21 +0200] [Client 283] Accepted from localhost (Domain)
D [21/Sep/2020:10:32:21 +0200] [Client 283] Waiting for request.
D [21/Sep/2020:10:32:21 +0200] [Client 283] POST /printers/Canon_MF4100_Series HTTP/1.1
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=200, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] No authentication data provided.
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] Read: status=100, state=6
D [21/Sep/2020:10:32:21 +0200] [Client 283] 2.1 Print-Job 1
D [21/Sep/2020:10:32:21 +0200] Print-Job ipp://localhost:631/printers/Canon_MF4100_Series
D [21/Sep/2020:10:32:21 +0200] [Job ???] Auto-typing file...
I [21/Sep/2020:10:32:21 +0200] [Job ???] Request file type is application/pdf.
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients"
D [21/Sep/2020:10:32:21 +0200] [Job 69] Applying default options...
D [21/Sep/2020:10:32:21 +0200] add_job: requesting-user-name="ransome"
D [21/Sep/2020:10:32:21 +0200] Adding default job-sheets values "none,none"...
I [21/Sep/2020:10:32:21 +0200] [Job 69] Adding start banner page "none".
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
I [21/Sep/2020:10:32:21 +0200] [Job 69] Adding end banner page "none".
I [21/Sep/2020:10:32:21 +0200] [Job 69] File of type application/pdf queued by "ransome".
D [21/Sep/2020:10:32:21 +0200] [Job 69] hold_until=0
I [21/Sep/2020:10:32:21 +0200] [Job 69] Queued on "Canon_MF4100_Series" by "ransome".
D [21/Sep/2020:10:32:21 +0200] [Job 69] time-at-processing=1600677141
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients and dirty files", busy="Active clients and dirty files"
D [21/Sep/2020:10:32:21 +0200] [Job 69] Sending job to queue tagged as raw...
D [21/Sep/2020:10:32:21 +0200] [Job 69] job-sheets=none,none
D [21/Sep/2020:10:32:21 +0200] [Job 69] argv[0]="Canon_MF4100_Series"
D [21/Sep/2020:10:32:21 +0200] [Job 69] argv[1]="69"
D [21/Sep/2020:10:32:21 +0200] [Job 69] argv[2]="ransome"
D [21/Sep/2020:10:32:21 +0200] [Job 69] argv[3]="Mousepad-Auftrag #4"
D [21/Sep/2020:10:32:21 +0200] [Job 69] argv[4]="1"
D [21/Sep/2020:10:32:21 +0200] [Job 69] argv[5]="number-up=1 noCollate PageSize=A4 job-uuid=urn:uuid:42d3bc1e-df93-3f7f-647f-545190f5a06b job-originating-host-name=localhost date-time-at-creation= date-time-at-processing= time-at-creation=1600677141 time-at-processing=1600677141"
D [21/Sep/2020:10:32:21 +0200] [Job 69] argv[6]="/var/spool/cups/d00069-001"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[1]="CUPS_DATADIR=/usr/share/cups"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[2]="CUPS_DOCROOT=/usr/share/cups/doc"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[6]="CUPS_SERVERROOT=/etc/cups"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[7]="CUPS_STATEDIR=/run/cups"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[8]="HOME=/var/spool/cups/tmp"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[10]="SERVER_ADMIN=root@thinkpad"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[11]="SOFTWARE=CUPS/2.3.3"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[12]="TMPDIR=/var/spool/cups/tmp"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[13]="USER=root"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[14]="CUPS_MAX_MESSAGE=2047"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[15]="CUPS_SERVER=/run/cups/cups.sock"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[16]="CUPS_ENCRYPTION=IfRequested"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[17]="IPP_PORT=631"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[18]="CHARSET=utf-8"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[19]="LANG=de_DE.UTF-8"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[20]="PPD=/etc/cups/ppd/Canon_MF4100_Series.ppd"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[21]="RIP_MAX_CACHE=128m"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[22]="CONTENT_TYPE=application/pdf"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[23]="DEVICE_URI=usb://Canon/MF4100%20Series?serial=SDF690360698P&interface=1"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[24]="PRINTER_INFO=Canon MF4100 Series"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[25]="PRINTER_LOCATION="
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[26]="PRINTER=Canon_MF4100_Series"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[27]="PRINTER_STATE_REASONS=none"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[28]="CUPS_FILETYPE=document"
D [21/Sep/2020:10:32:21 +0200] [Job 69] envp[29]="AUTH_I****"
I [21/Sep/2020:10:32:21 +0200] [Job 69] Started backend /usr/lib/cups/backend/usb (PID 4373)
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Active clients, printing jobs, and dirty files", busy="Active clients and dirty files"
D [21/Sep/2020:10:32:21 +0200] [Client 283] Returning IPP successful-ok for Print-Job (ipp://localhost:631/printers/Canon_MF4100_Series) from localhost.
D [21/Sep/2020:10:32:21 +0200] [Client 283] Content-Length: 192
D [21/Sep/2020:10:32:21 +0200] [Client 283] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [21/Sep/2020:10:32:21 +0200] [Client 283] con->http=0x560f9df50900
D [21/Sep/2020:10:32:21 +0200] [Client 283] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=192, response=0x560f9df38a60(IPP_STATE_IDLE), pipe_pid=0, file=-1
D [21/Sep/2020:10:32:21 +0200] [Client 283] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [21/Sep/2020:10:32:21 +0200] [Client 283] bytes=0, http_state=0, data_remaining=192
D [21/Sep/2020:10:32:21 +0200] [Client 283] Flushing write buffer.
D [21/Sep/2020:10:32:21 +0200] [Client 283] New state is HTTP_STATE_WAITING
D [21/Sep/2020:10:32:21 +0200] [Client 283] Waiting for request.
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Active clients, printing jobs, and dirty files"
D [21/Sep/2020:10:32:21 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:21 +0200] [Notifier] JobCreated
D [21/Sep/2020:10:32:21 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:21 +0200] [Notifier] PrinterStateChanged
D [21/Sep/2020:10:32:21 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:21 +0200] [Notifier] JobState
D [21/Sep/2020:10:32:21 +0200] [Client 283] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:21 +0200] [Client 283] Closing connection.
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:21 +0200] [Job 69] Loading USB quirks from \"/usr/share/cups/usb\".
D [21/Sep/2020:10:32:21 +0200] [Job 69] Loaded 181 quirks.
D [21/Sep/2020:10:32:21 +0200] [Job 69] Printing on printer with URI: usb://Canon/MF4100%20Series?serial=SDF690360698P&interface=1
D [21/Sep/2020:10:32:21 +0200] [Job 69] libusb_get_device_list=14
D [21/Sep/2020:10:32:21 +0200] [Job 69] STATE: +connecting-to-device
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Dirty files", busy="Dirty files"
D [21/Sep/2020:10:32:21 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:21 +0200] [Notifier] PrinterStateChanged
D [21/Sep/2020:10:32:21 +0200] [Job 69] STATE: -connecting-to-device
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Dirty files"
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:21 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:21 +0200] [Notifier] PrinterStateChanged
D [21/Sep/2020:10:32:21 +0200] [Job 69] Device protocol: 2
D [21/Sep/2020:10:32:21 +0200] [Job 69] Printer does not like usblp kernel module to be re-attached after job
D [21/Sep/2020:10:32:21 +0200] [Job 69] Sende Daten zum Drucker.
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:21 +0200] [Job 69] Set job-printer-state-message to "Sende Daten zum Drucker.", current level=INFO
D [21/Sep/2020:10:32:21 +0200] [Job 69] PAGE: 1 1
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:21 +0200] [Job 69] Read 5034 bytes of print data...
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:21 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:21 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:21 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:21 +0200] [Notifier] JobProgress
D [21/Sep/2020:10:32:21 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:21 +0200] [Notifier] JobProgress
D [21/Sep/2020:10:32:21 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:21 +0200] [Notifier] PrinterStateChanged
I [21/Sep/2020:10:32:22 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:32 +0200] [Job 69] Wrote 5034 bytes of print data...
D [21/Sep/2020:10:32:32 +0200] [Job 69] Sending print file, 5034 bytes...
I [21/Sep/2020:10:32:32 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:32 +0200] [Job 69] Sent 5034 bytes...
D [21/Sep/2020:10:32:32 +0200] [Job 69] Waiting for read thread to exit...
D [21/Sep/2020:10:32:32 +0200] [Job 69] PID 4373 (/usr/lib/cups/backend/usb) exited with no errors.
D [21/Sep/2020:10:32:32 +0200] [Job 69] time-at-completed=1600677152
D [21/Sep/2020:10:32:32 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:32 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
I [21/Sep/2020:10:32:32 +0200] [Job 69] Job completed.
I [21/Sep/2020:10:32:32 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:32 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:32 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:32 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:32 +0200] cupsdMarkDirty(----S)
D [21/Sep/2020:10:32:32 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:32 +0200] cupsdMarkDirty(---J-)
D [21/Sep/2020:10:32:32 +0200] cupsdSetBusyState: newbusy="Printing jobs and dirty files", busy="Printing jobs and dirty files"
D [21/Sep/2020:10:32:32 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:32 +0200] [Notifier] JobCompleted
D [21/Sep/2020:10:32:32 +0200] [Notifier] state=3
D [21/Sep/2020:10:32:32 +0200] [Notifier] PrinterStateChanged
I [21/Sep/2020:10:32:33 +0200] Expiring subscriptions...
D [21/Sep/2020:10:32:33 +0200] [Job 69] Unloading...
I [21/Sep/2020:10:32:52 +0200] Saving job.cache...
I [21/Sep/2020:10:32:52 +0200] Saving subscriptions.conf...
D [21/Sep/2020:10:32:52 +0200] cupsdSetBusyState: newbusy="Not busy", busy="Printing jobs and dirty files"
I [21/Sep/2020:10:32:52 +0200] Expiring subscriptions...

Inwieweit dies hier kritisch ist, kann ich nicht beurteilen. Da ich aber direkt über USB drucke und sich das eher nach einem Netzwerkaufbau anhört, sehe ich hier weniger das Problem

D [21/Sep/2020:10:32:21 +0200] [Client 283] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [21/Sep/2020:10:32:21 +0200] [Client 283] Closing connection."

Das Ergebnis ist nun ein Eintrag in der Auftragsliste mit dem Status

beendet am 
Mon Sep 21 10:32:32 2020

Und nun stehe ich auf dem Schlauch sad Wie mache ich am besten weiter? Aufgeben geht nicht!

Gruß
ransome

Fun fact: Als ich vor einiger Zeit Manjaro installiert hatte, ging das Drucken mit dem Gerät ohne Probleme.

Offline

#2 21.09.2020 12:07:31

Greg
Mitglied

Re: CUPS: Angeblich erfolgreicher Druck, jedoch ohne Output

Scheinbar reicht die ppd Datei alleine nicht aus.
Nach dieser Seite:
https://www.canon.de/support/consumer_p … 20(64-bit)
benötigt dein Drucker folgenden Treiber:
UFR II/UFRII LT Printer Driver for Linux V5.20

Wenn man den runterlädt und dort in das Archiv reinsieht, so heißt dann der Treiber cnrdrvcups-ufr2-uk_5.20-1_amd64.deb. Gemein.
Nein, kein Debianpaket passt hier in Arch-Linux. Daher sucht man jetzt im AUR nach cnrdrvcups.
https://aur.archlinux.org/packages/?O=0 … _Search=Go
Die Version 5.20 ist im Aur mit cnrdrvcups-lb gelistet.
Dann kommt man auf die Seite https://aur.archlinux.org/packages/cnrdrvcups-lb
Oben rechts download-snapshot betätigen.
Das Ding entpacken und in das Verzeichnis wechseln.
Mit makepkg wird das Paket gebaut.
Installieren mit pacman -U *.zst
Den Drucker per cups neu installieren.
Testdruck, fertig.

Gruß aus DN
Greg

Offline

#3 21.09.2020 14:05:27

ransome
Mitglied

Re: CUPS: Angeblich erfolgreicher Druck, jedoch ohne Output

Greg schrieb:

Scheinbar reicht die ppd Datei alleine nicht aus.
Nach dieser Seite:
https://www.canon.de/support/consumer_p … 20(64-bit)
benötigt dein Drucker folgenden Treiber:
UFR II/UFRII LT Printer Driver for Linux V5.20

Wenn man den runterlädt und dort in das Archiv reinsieht, so heißt dann der Treiber cnrdrvcups-ufr2-uk_5.20-1_amd64.deb. Gemein.
Nein, kein Debianpaket passt hier in Arch-Linux. Daher sucht man jetzt im AUR nach cnrdrvcups.
https://aur.archlinux.org/packages/?O=0 … _Search=Go
Die Version 5.20 ist im Aur mit cnrdrvcups-lb gelistet.
Dann kommt man auf die Seite https://aur.archlinux.org/packages/cnrdrvcups-lb
Oben rechts download-snapshot betätigen.
Das Ding entpacken und in das Verzeichnis wechseln.
Mit makepkg wird das Paket gebaut.
Installieren mit pacman -U *.zst
Den Drucker per cups neu installieren.
Testdruck, fertig.

Gruß aus DN
Greg

Greg Du bist der Beste! Es klappt! Ich hatte ganz naiv gedacht, alles was es benötigt ist diese eine PPD Datei, die ich aus dem Treiber extrahiert hatte und das reicht. Da habe ich etwas gelernt. Vielen Dank!

Offline

#4 21.09.2020 15:12:20

Greg
Mitglied

Re: CUPS: Angeblich erfolgreicher Druck, jedoch ohne Output

ransome schrieb:

...Ich hatte ganz naiv gedacht, alles was es benötigt ist diese eine PPD Datei..

So naiv ist das nicht. Es gibt recht viele Drucker wo diese Vorgehensweise reicht. Aber bei den neueren Druckern machen die Hersteller immer mehr propritären Kram rein, was ohne dem Zeug einfach nicht mehr geht.
Falls du den Scanner auch unter Linux betreiben willst, so kannst du das mit sane und xsane probieren.
In den sane-project :
http://www.sane-project.org/sane-mfgs.html#Z-CANON
steht etwas von einem imageCLASS MF4140 das der komplett unterstützt wird. Allerdings heißt dein Drucker nicht imageclass sondern i-SENSYS MF4140. Mußt du einfach mal ausprobieren.
https://wiki.archlinux.org/index.php/SANE

Offline

#5 23.09.2020 17:24:33

ransome
Mitglied

Re: CUPS: Angeblich erfolgreicher Druck, jedoch ohne Output

Greg schrieb:
ransome schrieb:

...Ich hatte ganz naiv gedacht, alles was es benötigt ist diese eine PPD Datei..

So naiv ist das nicht. Es gibt recht viele Drucker wo diese Vorgehensweise reicht. Aber bei den neueren Druckern machen die Hersteller immer mehr propritären Kram rein, was ohne dem Zeug einfach nicht mehr geht.
Falls du den Scanner auch unter Linux betreiben willst, so kannst du das mit sane und xsane probieren.
In den sane-project :
http://www.sane-project.org/sane-mfgs.html#Z-CANON
steht etwas von einem imageCLASS MF4140 das der komplett unterstützt wird. Allerdings heißt dein Drucker nicht imageclass sondern i-SENSYS MF4140. Mußt du einfach mal ausprobieren.
https://wiki.archlinux.org/index.php/SANE

Ich habe xsane installiert und alles funktioniert out of the box, traumhaft! Danke für den Hinweis.

Offline

Schnellantwort auf dieses Thema

Schreibe deinen Beitrag und versende ihn
Deine Antwort

Fußzeile des Forums