Systemd und die Limits : The Revenge of Mariadb

Es hätte so ein schöner Tag werden können, Weihnachten ist grade rum, der deutsche Wetterdienst droht uns endlich mit Schnee und das Upgrade von Fedora 19 auf Fedora 20 lief gestern Nacht ohne Probleme ab. In freudiger Erwartung einer guten Meldung laß ich den morgendlichen Report meiner Serverfarm. Ok, es ist die Serverfarm meines Arbeitgebers, aber da ich mich morgens drum kümmern muß, ist es meine Farm. Mein System, meine Farm ! Pah.

Ich laß also im Bett die Emails der Nacht und alle Server schienen glücklich zu sein, nur einer meldete um 3 Uhr nachts über 500 Emails in seiner Mailqueue. Ein typischer Fall von Mailspam über ein gehacktes Mailkonto, doch dann wurde mir klar, es ist der Server der gestern sein Upgrade hatte und der hat gar keine Mailkonten die man hacken könnte. Mifft!

Einer ersten Analyse nach, liefen alle Dienste, schon mal ein gutes Zeichen. Dann schaute ich in das Logfiles des Mailserver und stiess auf eine große Anzahl von Fehlermeldungen, da der Mailserver nicht in den Datenbankserver einloggen konnte. Da aber die Emails über diesen Server angekommen waren, schien das nur ein temporäres Problem zu sein:

gave DEFER: MYSQL connection failed: Too many connections

Ohoh… nicht schon wieder.. In 2013 hatte wir nach einem Upgrade ein ähnliches Problem mit dem Httpd, der wollte nach Umstieg auf Systemd auch nicht mehr mit seinen Limits arbeiten. Zum Glück kann man das auf die gleiche Weise lösen, sollte man jedenfalls meinen.

Zunächsteinmal einen Blick in die /etc/my.cnf ob noch alles da ist, man weiß ja nie ..

[mysqld]
max_connections = 2000
max_join_size = 10M

noch alles da. Merkwürdig. Ein Blick ins Mysql-Logfile zeigte dann das hier :

10:26:15 [Warning] Changed limits: max_open_files: 1024  max_connections: 214  table_cache: 400

Das macht der liebe Mysqld, wenn das Open-Files-Limit nicht stimmt, denn Sockets sind auch nur Filedescriptoren. Aber moment, das hatten wir doch beim letzten Upgrade schon mal behoben! Wieso geht das nicht mehr ?

Ein Blick in /etc/systemd/system/mariadb.service zeigt uns: (u.a.)

[Service]
LimitNOFILE=1000000
Type=simple
User=mysql
Group=mysql

Da steht doch, daß er das Filelimit anheben soll, wieso tut er das nicht? Ab dieser Stelle haßte ich den Systemd wiedermal.. wie sich rausstellte, ist das Teil einfach großer „Mifft!“ wie Bernd sagen würde.

Es reicht nicht mehr, das NOFILE Limit ins eigene Servicefile zu packen, man muß es (auch noch) in einer eigenen Limitsdatei eintragen :

# cat /etc/systemd/system/mariadb.service.d/limits.conf 
[Service]
    LimitNOFILE=1000000

Wenn ich jetzt nostalgisch werde, müßt Ihr das verzeihen : Früher war alles besser !

Da gab es son Mist nicht. Der Systemd hat auch Vorteile, daß kann man nicht leugnen, aber für das Teil braucht man ein ganzes Handbuch, wo man vorher einfach mal „ulimit -n 100000“ im Initscript benutzen konnte und die Welt war wieder ok. Das war wirklich besser !

 

Systemd: wenn set-default nicht funktioniert

Fedora empfiehlt auf den eigenen Seiten, daß man das Default.Target mit dem Befehl:

systemctl set-default graphical.target

setzen könnte. Das  graphical.target ist dabei die Desktopoberfläche. Mit dem multi-user.target bekommt man nur die auf Server übliche Textkonsole zusehen.

Leider stimmt das nicht für jede Fedoraversion und z.b. bei Fedora 19 muß man selbst Hand anlegen:

ln -sf /usr/lib/systemd/system/multi-user.target /etc/systemd/system/default.target

Man kann auch den direkten runlevel als Ziel angeben:

z.b.  /etc/systemd/system/default.target -> /lib/systemd/system/runlevel3.target

Im laufenden Betrieb kann man als Root mithilfe des isolate Befehls zwischen den Runleveln umschalten. Das ist zu Debugzwecken ganz praktisch.

systemctl isolate multi-user.target

Systemd schickt alte Einträge zum Syslogd

Die Bild-Zeitung könnte mit der folgenden Schlagzeile öffnen:

„Systemd wahnsinnig – Syslogd kurz vor dem Zusammenbruch“

Wenn man einen Produktivserver im Netz hat, möchte man solche Schlagzeilen lieber nicht lesen, dennoch können Sie passieren. Mit den folgenden kleinen Anweisungen kann man das Desaster beenden.

Aber zunächst mal zum eigentlichen Problem:

Der Syslogd läuft mit 95% CPU Last, aber ansonsten ist auf dem System nichts zu sehen, was die Nachrichten produzieren könnte. Der erste Blick geht daher nach /var/log/messages:

Jul 16 20:21:01 systemd: Started Session 29860 of user root.
Jul 16 20:21:01 systemd: Starting Session 29859 of user munin.
Jul 16 20:21:01 systemd: Started Session 29859 of user munin.
Jul 16 20:21:01 systemd: Starting Session 29862 of user root.
Jul 16 20:21:01 systemd: Started Session 29862 of user root.
Jul 25 07:34:20 rsyslogd-2177: imjournal: begin to drop messages due to rate-limiting

Was wir sehen, sind eine Flut von alten Nachrichten und die Meldung, daß imournal daran gehindert wurde, weitere Nachrichten zu loggen, weil es zu viele wurden. Was Sie oben nicht sehen ist, daß das Ganze mit Nachrichten aus April begonnen hat. 3,7 GB an Logfiles sollten nochmal durch den Syslogd gejagt werden.

Auch wenn die eigentlichen Nachrichten nicht mehr in /var/log/messages auftauchen, so verbraucht der Syslogd trotzdem noch eine Menge CPU Leistung, meistens soviel er bekommt.

Ein Neustart von syslogd machts nur schlimmer, weil die alten Nachrichten dann wieder ins Log geschrieben werden.

Die Lösung:

Man editiere /etc/systemd/journald.conf :

 [Journal]
 #Storage=auto
 #Compress=yes
 #Seal=yes
 #SplitMode=login
 #SyncIntervalSec=5m
 #RateLimitInterval=30s
 #RateLimitBurst=1000
 #SystemMaxUse=
 #SystemKeepFree=
 #SystemMaxFileSize=
 #RuntimeMaxUse=
 #RuntimeKeepFree=
 #RuntimeMaxFileSize=
 #MaxRetentionSec=
 #MaxFileSec=1month
 #ForwardToSyslog=yes
 #ForwardToKMsg=no
 #ForwardToConsole=no
 #TTYPath=/dev/console
 #MaxLevelStore=debug
 #MaxLevelSyslog=debug
 #MaxLevelKMsg=notice
 #MaxLevelConsole=info

in dem man das hier einfügt oder ändert, ganz wie Sie möchten:

[Journal]
 MaxRetentionSec=10day

Wenn man dann den Journaldienst des Systemd neustartet, werden alle alten Files aus /var/log/journal/ entfernt und der Systemd schickt nur noch 10 Tage Logs an den Syslogd. Das ist aber i.d.R.  in wenigen Sekunden durch und die Last des Systems geht auf normal zurück.

 systemctl restart systemd-journald

Als positiver Seiteneffekt werden gleich noch monatealte Logdaten gelöscht. In unserem Fall waren es satte 3 GB.

Das Ende der Orgie erkennt man im Logfile des Syslogds an dieser Meldung:

Jul 25 07:35:13 rsyslogd-2177: imjournal: 229963 messages lost due to rate-limiting

Das wäre früher oder vermutlich sehr viel später auch ohne die Anpassungen im in der journal.conf passiert.

Da aber nach 17 Minuten erst 1 Monat verarbeitet wurde, ist es aus Performancegründen des Servers ratsam das zu beschleunigen.