Hallo,
das war es wohl auch nicht. Kurzzeitig reagierte die Cups-Weboberfläche wieder „normal“ schnell. Jetzt ist sie wieder träge wie zuvor 
Mist!
Gruß
Alois
Hallo,
ich habe jetzt noch mal in der error.log eines anderen Servers nachgesehen.
Die Meldung „Duplicate <Location /printers/PDF-Printer> on line 2“ erscheint dort auch und es funktioniert.
Die Meldungen „I [27/Feb/2020:13:56:02 +0100] Resuming new connection processing…
W [27/Feb/2020:13:56:02 +0100] Max clients reached, holding new connections…
I [27/Feb/2020:13:56:02 +0100] Resuming new connection processing…
W [27/Feb/2020:13:56:02 +0100] Max clients reached, holding new connections…“
finden sich dort nicht. Demnach müsste das die Ursache für das Verhalten von Cups bzw. der Weboberfläche sein.
Wie kann ich den Fehler eingrenzen?
Gruß
Alois
Hallo Alois,
Wie kann ich den Fehler eingrenzen?
ich hab mal im Web gesucht:
https://www.ecosia.org/search?tt=mzl&q=Max+clients+reached%2C+holding+new+connections+cups
Der 7te Fund ist deine Nachricht hier im Forum 
Schau mal den 3ten an:
https://bugzilla.redhat.com/show_bug.cgi?id=525637
Da wird das auf die Fieldescriptoren des kernels zurückgeführt.
Wir hatten von ein paar Jahren schon mal eine Diskussion dazu: und
einige hatten dann, wie auf der Seite empfohlen, das ulimit des Kernels
hochgesetzt (auch ich, wenn ich das richtig erinnere).
Ich würde sagen: das ist ein versuch Wert.
Gerade deine Beobachtung, dass es nach einem reboot wieder kurze Zeit
funktioniert, unterstützt diese Vermutung.
LG
Holger
Hallo Holger,
ich hatte zwischenzeitlich meinen persönlichen IT-Spezialisten da. Der hat heraus gefunden dass ein Rechner der in der Schule rum steht das Problem verursacht. Dummerweise lässt sich der Rechner nicht remote herunter fahren. Morgen muss der Kollege vor Ort den Rechner ausschalten und dann hat der Spuk hoffentlich ein Ende.
Viele Grüße und danke an alle die mit gedacht haben. Ich berichte morgen obs das war.
Alois
Hallo,
das war es leider nicht
Hier mal die /var/log/cups/error_log von einem Server bei dem es keine Probleme gibt:
08:30/0 server ~ # service cups restart && tail -f /var/log/cups/error_log
cups stop/waiting
cups start/running, process 13833
W [28/Feb/2020:08:30:59 +0100] failed to CreateDevice: org.freedesktop.ColorManager.AlreadyExists:device id ‚cups-OKIB840‘ already exists
I [28/Feb/2020:08:30:59 +0100] Registering ICC color profiles for „PDF-Printer“
I [28/Feb/2020:08:30:59 +0100] Loading job cache file „/var/cache/cups/job.cache“…
I [28/Feb/2020:08:30:59 +0100] Full reload complete.
I [28/Feb/2020:08:30:59 +0100] Cleaning out old files in „/var/spool/cups/tmp“…
I [28/Feb/2020:08:30:59 +0100] Cleaning out old files in „/var/cache/cups“…
I [28/Feb/2020:08:30:59 +0100] Listening to 0.0.0.0:631 on fd 9…
I [28/Feb/2020:08:30:59 +0100] Listening to [v1.::]:631 on fd 10…
I [28/Feb/2020:08:30:59 +0100] Listening to /var/run/cups/cups.sock:631 on fd 11…
I [28/Feb/2020:08:30:59 +0100] Resuming new connection processing…
Und hier die gleiche Datei vom Server bei dem das Problem besteht:
08:31/0 server ~ # service cups restart && tail -f /var/log/cups/error_log
cups stop/waiting
cups start/running, process 559
I [28/Feb/2020:08:31:56 +0100] Registering ICC color profiles for „PDF-Printer“
W [28/Feb/2020:08:31:56 +0100] failed to CreateDevice: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
I [28/Feb/2020:08:31:56 +0100] Loading job cache file „/var/cache/cups/job.cache“…
I [28/Feb/2020:08:31:56 +0100] Full reload complete.
I [28/Feb/2020:08:31:56 +0100] Cleaning out old files in „/var/spool/cups/tmp“…
I [28/Feb/2020:08:31:56 +0100] Cleaning out old files in „/var/cache/cups“…
I [28/Feb/2020:08:31:56 +0100] Listening to 0.0.0.0:631 on fd 9…
I [28/Feb/2020:08:31:56 +0100] Listening to [v1.::]:631 on fd 10…
I [28/Feb/2020:08:31:56 +0100] Listening to /var/run/cups/cups.sock:631 on fd 11…
I [28/Feb/2020:08:31:56 +0100] Resuming new connection processing…
W [28/Feb/2020:08:31:56 +0100] Max clients reached, holding new connections…
Beim nicht ordentlich funktionierenden erscheint dieses Max clients reached …
Die Zeilen
Resuming new connection processing…
Max clients reached, holding new connections…
wiederholen sich dann ständig.
Gruß
Alois
Hallo Alois,
nach eigener Recherche hätte ich auch auf das Setzen von MaxClients in der cupsd.conf gesetzt. Wo und wie hast Du denn das eingetragen?
Bzw. wie Holger sagt auf ulimit, setz das mal weiter hoch:
ulimit -n 2048
service cups restart
S. hier: https://bugzilla.redhat.com/show_bug.cgi?id=525637
LG,
Jochen
Hallo Jochen,
ich habe in der cupsd.conf eine Zeile
MaxClients 500
eingefügt.
Ausserdem war loglevel von info auf debug gesetzt.
Gestern sah man dann beim Start mit
service cups restart && tail -f /var/log/cups/error_log
wie immer wieder eine Zeile geschrieben wurde in der der einzige in der Schule eingeschaltete Rechner (dessen IP-Adresse) angezeigt wurde. Es wurde in jeder Zeile um eins erhöht bis 500 erreicht war und dann kam wieder Max clients reached …
Ich habe auch mal ulimit 2048 getestet. Das Ergebnis siehst Du unten. Es gab keine Verbesserung.
09:26/130 server ~ # ulimit -n 2048
09:26/0 server ~ # service cups restart && tail -f /var/log/cups/error_log
cups stop/waiting
cups start/running, process 26173
I [28/Feb/2020:09:27:17 +0100] Registering ICC color profiles for „PDF-Printer“
W [28/Feb/2020:09:27:17 +0100] failed to CreateDevice: org.freedesktop.DBus.Error.ServiceUnknown:The name org.freedesktop.ColorManager was not provided by any .service files
I [28/Feb/2020:09:27:17 +0100] Loading job cache file „/var/cache/cups/job.cache“…
I [28/Feb/2020:09:27:17 +0100] Full reload complete.
I [28/Feb/2020:09:27:17 +0100] Cleaning out old files in „/var/spool/cups/tmp“…
I [28/Feb/2020:09:27:17 +0100] Cleaning out old files in „/var/cache/cups“…
I [28/Feb/2020:09:27:17 +0100] Listening to 0.0.0.0:631 on fd 9…
I [28/Feb/2020:09:27:17 +0100] Listening to [v1.::]:631 on fd 10…
I [28/Feb/2020:09:27:17 +0100] Listening to /var/run/cups/cups.sock:631 on fd 11…
I [28/Feb/2020:09:27:17 +0100] Resuming new connection processing…
W [28/Feb/2020:09:27:18 +0100] Max clients reached, holding new connections…
Hallo Alois,
hab woanders noch was gefunden, wo es heißt, das sei ein Problem, dass cups über upstart gestartet wird. Dort wird vorgeschlagen, in /etc/init/cups.conf folgendes zu setzen:
limit nofile 4096 4096
'n Test wär’s wert…
LG,
Jochen
Hallo Jochen,
mit der Änderung „limit nofile 4096 4096“ und einem Neustart gibt es keine Veränderung. Es kommt weiter Max clients reached …
Schade!
Viele Grüße
Alois
Was sagt denn netstat -nplt|grep cupsd? Da sollte ja zumindest zu sehen sein, dass da viele Verbindungen sind. Ein angehängtes |wc sagt die wieviele. Da hast du schon mal einen Anhalt, ob da zu suchen ist.
ein ulimit vor dem service... hilft glaub’ ich nicht, da systemd die limit kontrolliert, du musst du dann da (vermutlich in /lib/systemd/system/cups.service? - bin kein systemd-Experte)umsetzen, denke ich.
Hallo mdt,
14:30/0 server ~ # netstat -nplt|grep cupsd
tcp 0 0 0.0.0.0:631 0.0.0.0:* LISTEN 11878/cupsd
tcp6 0 0 :::631 :::* LISTEN 11878/cupsd
Nichts was Aufschluss über das Problem liefern könnte.
Viele Grüße
Alois
Hallo,
so langsam habe ich das Gefühl, dass die Fehlermeldungen auf eine falsche Spur führen und die Ursache für das Problem eine ganz andere ist.
Gruß
Alois
Hallo,
ich fange noch mal neu an:
Folgende Einstellung in der cupsd.conf
MaxClients 500
loglevel debug
Wenn ich dann
service cups restart && tail -f /var/log/cups/error_log
ausführe, dann finden sich in der Log-Datei u.A. die folgenden Zeilen. Die Zahl 167 in der ersten Zeile erhöht sich um eins bis über 500 und endet irgendwann mit der Meldung Max Clients reached…
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 167 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 169 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 171 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 173 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 175 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 177 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 179 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 181 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 183 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 185 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 187 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 189 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 191 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 193 from 10.18.16.27:631 (IPv4)
D [28/Feb/2020:14:53:51 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.18.16.$
D [28/Feb/2020:14:53:51 +0100] cupsdAcceptClient: 195 from 10.18.16.27:631 (IPv4)
Woher kommen diese Meldungen und wie kann man sie abstellen?
Viele Grüße
Alois
Hallo Alois,
wer oder was steckt denn hinter dieser IP?
Was passiert, wenn Du die offline nimmst?
LG,
Jochen
Hallo Jochen,
das ist ein ganz normaler Windows-Client. Es gibt mindestens noch einen Rechner der die gleiche Meldung produziert. Gestern Abend war es ein anderer.
Allen gemeinsam ist dass ich sie nicht remote herunter fahren kann. Da ich nicht vor Ort bin habe ich keine Chance sie abzuschalten.
Es muss also einen Zusammenhang zwischen den Rechnern und dem Cups-Problem geben.
Viele Grüße Alois
Hallo Alois,
wie starten diese Clients standardmäßig? Synchronisiert oder unsynchronisiert?
Ist bei denen evtl. die Druckerwarteschlange voll (nach dem Motto „wenn der nicht druckt, probier ich’s nochmal und nochmal und nochmal…“), so dass es dadurch zu den vielen Anfragen pro Client kommt, die dann irgendwann über die MaxClients rausgehen? (völlig in’s Blaue hinein geraten)
Viele Grüße,
Jochen
Hallo Jochen,
normalerweise werden die Rechner einmal in der Woche synchronisiert gestartet. Die Idee ist gut. Der Kollege vor Ort liest hier mit und ich denke er wird morgen einmal nachsehen.
Viele Grüße
Alois
Hallo Jochen,
hier noch die komplette Ausgabe. Das ganze wiederholt sich über 500 mal bis zur fett markierten 515.
D [28/Feb/2020:17:46:14 +0100] cupsdSetBusyState: newbusy=„Not busy“, busy=„Active clients“
D [28/Feb/2020:17:46:14 +0100] cupsdAcceptClient: 515 from 10.16.10.12:631 (IPv4)
W [28/Feb/2020:17:46:14 +0100] Max clients reached, holding new connections…
D [28/Feb/2020:17:46:14 +0100] cupsdReadClient: 515 POST /printers/laser-r124 HTTP/1.1
D [28/Feb/2020:17:46:14 +0100] cupsdSetBusyState: newbusy=„Active clients“, busy=„Not busy“
D [28/Feb/2020:17:46:14 +0100] cupsdAuthorize: No authentication data provided.
D [28/Feb/2020:17:46:14 +0100] cupsdReadClient: 515 1.0 Get-Printer-Attributes 11
D [28/Feb/2020:17:46:14 +0100] Get-Printer-Attributes http://10.16.1.1:631/printers/laser-r124
D [28/Feb/2020:17:46:14 +0100] Returning IPP successful-ok for Get-Printer-Attributes (http://10.16.1.1:631/printers/laser-r124) from 10.16.10.12
D [28/Feb/2020:17:46:14 +0100] cupsdSetBusyState: newbusy=„Not busy“, busy=„Active clients“
Viele Grüße
Alois
Anmerkung: Das 10.16.10.12 ist jetzt der einzige Rechner der noch läuft. Auch der lässt sich nicht mehr remote herunter fahren.
Hallo Alois,
Und wenn’s nur hilft, Dinge auszuschließen.
Ich würd mal nur synchronisierte Clients starten und dann schauen, ob die Meldungen noch immer kommen.
Und falls nicht, mal nur von einem einzigen Client einen einzigen Druckjob senden und schauen, wie’s dann aussieht.
Viele Grüße,
Jochen
Hallo Jochen,
ich denke, wir werden morgen weiter testen. Derzeit ist niemand mehr in der Schule.
Vielen Dank für Deine Tips
Alois