Systemd: Aus den Wirren des Paketmanagements

„Aus den Wirren der Paketabhängigkeiten im Dschungel von Systemd“ man könnte einen Roman damit betiteln 🙂  Gestern abend, es war mal wieder Serverupdatezeit, flutschte eine Anzeige eines Fedora-Paketes, daß keinen Sinn machte, über den Bildschirm: qrencode-libs

QR Codes auf einem Server?

Ja, wenn man eine Webseite hat, die z.b. QR Codes ausgibt, weil eine HandyApp einen Bestätigungscode haben will, warum nicht. Dummerweise hatte dieser Server genau einen Job und der hatte nichts mit QR Codes zu tun. „Naja,ok, das wird jemand mal irgendwann für was ausprobiert haben… kann weg!“ denkste Dir so.. und dann kommt das Erwachen: „Wieso will dnf jetzt systemd löschen?“

$ sudo dnf erase qrencode-libs
[sudo] Passwort für  ….. :
Fehler:
Problem: The operation would result in removing the following protected packages: systemd

Das kommt so …

Der Systemd hat eine harte Abhängigkeit auf die lib von dem qrencoder :

$ rpm -q -R systemd | grep qrenc
libqrencode.so.3()(64bit)

ganz genau genommen ist es journalctl:

$ ldd /usr/bin/journalctl |grep qrenc
libqrencode.so.3 => /lib64/libqrencode.so.3 (0x00007fef36540000)

„Kann mir bitte einer erklären, wieso journalctl QR CODES bauen können müßte ?????“

Kann ja wohl nur ein Fehler sein 😉   Der Maintainer bei Redhat war da jetzt anderer Meinung:

What do you mean "wrongfully"? It's "rightfullly" linking against qrencode-libs because that functionality is used by journalctl.
While somewhat unfortunate, it's correct.

Steht aber allein da, denn auch bei Manjaro Linux ist das schon mal jemandem vor mir aufgefallen und siehe:

https://forum.manjaro.org/t/systemd-238-51-1-has-picked-up-a-dependency-on-qrencode/43070

Could this be due to a dirty chroot?

$ ldd `which journalctl`
	linux-vdso.so.1 (0x00007fff47fc9000)
	libpthread.so.0 => /usr/lib/libpthread.so.0 (0x00007f55fd82e000)
	libc.so.6 => /usr/lib/libc.so.6 (0x00007f55fd477000)
	libsystemd-shared-238.so => /usr/lib/systemd/libsystemd-shared-238.so (0x00007f55fd027000)
	libqrencode.so.4 => not found

I’m pretty certain journalctl doesn’t need qrencode?

Das sehe ich auch so, trotzdem habe ich mal etwas geforscht und die Ursache gefunden:

journalctl .c

#if HAVE_QRENCODE
/* If this is not an UTF-8 system don’t print any QR codes */
if (is_locale_utf8()) {
fputs(„\nTo transfer the verification key to your phone please scan the QR code below:\n\n“, stderr);
print_qr_code(stderr, seed, seed_size, n, arg_interval, hn, machine);
}
#endif

Jetzt wirds spannend:

Wozu wird das benutzt?

Um, wenn es ein UTF8-System ist UND der Code mit dem QR Support kompiliert wurde, einen Verifikations Schlüssel als QR CODE fürs Handy auszugeben, um mit dem Versiegelungs-Schlüssel abgesicherte Journaleinträge zu prüfen.

Das Verfahren heißt bei Systemd Forward Secure Sealing (FSS).  Keine Ahnung wer das Feature von Journald nutzt. Es klingt jedenfalls nach einer brauchbaren Idee, falls ein Hacker die Einträge manipuliert. Ich bezweifle aber stark, daß der Key dabei per QR Code an ein Handy übermittelt werden muß, statt per SCP an einen anderen Server.

Für diese eine Zeile Code da oben, die kaum jemand jemals einsetzen wird (Bitte Zahlen liefern, wer welche hat), immer noch diese Lib mit sich rumschleppen… was solls, GB sind billig  😉

Systemd : The Revenge of Mariadb III

Ich möchte Euch heute eine kleine Weihnachtsgeschichte erzählen, die sich so im Linux Lande Fedora zugetragen hat. Um diese Geschichte zu verstehen, solltet Ihr Euch in diese Vorgeschichte von Mariadb eingelesen haben. Die Geschichte wird Euch lehren, Euch nicht mit dem SystemD anzulegen, denn er wird Euer Ende sein ..

Also, sprach der Admin …

Es ist mal wieder kurz vor Weihnachten. Der erste Schnee fiel schon auf den Boden, da trug es sich zu, daß ein älteres Fedora-System ein Upgrade brauchte. Also hisste der Admin die Wartungsflagge des Servers und begab sich an die Konsole. „Hmm..“  sprach er zu seinem Monitor, „der Server ist alt, und wir könnten zwei Versionen überspringen, und damit viel Zeit sparen.“ Auf dem Monitor lächelte ihn seine Reflektion erfreut an und so ward dnf beauftragt, die OS-Release um zunächst zwei Stufen anzuheben.

Dnf tat wie ihm befohlen und ackerte um die gewünschten Pakete zu installieren. Nach 20 Minuten, war das Werk getan und der Admin beauftragte den Server sich neu zu starten. Er tat wie befohlen.

Nach dem Reboot, ist vor dem nächsten Reboot

In freudiger Erwartung, loggte sich der Admin wieder auf seinen Server ein. Tomcat lief, Cron lief, die Datenbank… lief.. und so startete der Admin die Post-Reboot Prozeduren, um die neue MariaDB Version zu initialisieren, das PHP zu setupen, die Chroot zu füllen und sich seinem eigentlichen Ziel, dem DNS Server zu widmen.

Nach einiger Zeit sagte sein treuer Freund pstree erstaunt zu Ihm : „Aber oh Herr, siehe. Der PowerDNS will nicht antworten, obwohl er läuft.“ Der Admin war geneigt an einen kleinen Post-Upgrade Bug zu glauben und startete den PowerDNS neu. Aber auch das zeigte keine Wirkung. Der Prozess blieb stumm. Wieder war es pstree, das aufgeregt zu ihm rief:  „Meister, Mariadb läuft gar nicht, wie soll PowerDNS da antworten?“

Und so befahl der Admin dem SystemD MariaDB neu zu starten. Er tat wie ihm geheißen, kehrte aber nicht von seinem Auftrage zurück. Auch nach 5 Minuten, blieb der SystemD auf dem Wege der Arbeit verschollen. Unruhe machte sich beim Admin breit. Wieso kam SystemD nicht von seinem Job zurück? Was konnte ihm nur passiert sein?

Auf der Suche nach dem Timeout

Also fragt der Admin den journald, was denn dem Systemd zugestoßen sein könnte. Aber der journald wußte es nicht. Ihm hatte keiner einen Fehler gemeldet. Unterdessen meldete sich pstree und sagte: „Herr, so freue Dich. MariaDB ist wieder da. Und PowerDNS antwortet auch wieder! “ . Der Admin schaute auf den Monitor und brummte ein „Hmmmm“ vor sich hin, als der Job endlich zurück kam. Aber was war das ? Weder MariaDB noch PowerDNS funktionierten noch.

Ein schnelles „systemctl status mariadb“ zeigte nur einen „Fehler 203/Exited“ an, und meinte es sei per Signal beendet worden. Wieder dieses „hmmm“ , diesmal von Reflex auf dem Monitor. „Danke“, sagte der Admin laut. pstree sprang aufgeregt durch die Konsole, nichts ging mehr, das war zuviel für ihn. „Komm wieder runter Tree, ich starts nochmal“. Aber auch das brachte nur das gleiche Ergebnis.

Der SystemD war, oder?

Dann durchfuhr es den Admin wie einen Blitz: „Das ist das verdammte Prozesslimit vom SystemD! Das wars doch beim letzten mal auch !“ Gesagt, geändert. Kein Erfolg! Der Admin wurde nervös. Tree hatte sich bereits in die weit entfernteste Konsole zurückgezogen. „Wir haben doch damals eine eigene Limit.conf gemacht.. wo war die nochmal .. ach ja, /etc/systemd/system/mariadb.d/ … könnte es sein, daß sich das Servicefile geändert hat und jetzt irgendeinen Timeoutmist macht ? “ murmelte der Admin zu seinem Abbild auf dem Monitor.

Ein kurzes „diff /usr/lib/systemd/system/mariadb.service /etc/systemd/system/mariadb.service “ erhellte die Mine des Admin.. „JA, DAS WARS“. Endlich. Das eigene Unitfile war derart veraltet, weil es für zwei OS Releases früher gemacht war, daß der Systemd einen falschen Weg zum Start einschlagen mußte. Als der Admin das File entfernte und den Dienst startete, sprang Tree jubilierend aus seiner Konsole. Es war geschafft !

Merke, wenn es um MariaDB geht, versteht der SystemD keinen Spaß. Also halte Dich immer an die Anleitung, wenn Du die Limits konform einbauen willst. Außerdem: MariaDB macht immer nur Ärger beim Update ! Aber wieso immer zu Weihnachten ??!?!?! 😀

 

Ein MCP namens SystemD

Bunte Linien kreisen vor meinen Augen und bilden bunte Muster. Die Augen schmerzen. Der Kopf schmerzt und auch das Gehirn hat Schaden genommen. Die Welt ist dunkel, aber bunt.  Ich öffne die Augen. Ein rötlich strahlender Wächter stößt mich mit einer Energielanze an: „Aufstehen, Programm!“ Er will, daß ich mit ihm komme. Wir beschreiten Wege aus Energie… bunter Energie, seltsam neonfarbend und doch schwarz, wie die Nacht. Unterwegs treffen wir andere „Programme“ mit Ihren „Wächtern“. Bald stehe ich vor einem Kopf aus Licht: Der MCP, es gibt ihn wirklich!!!!!!

Verstört wache ich auf. Ein Computeradminalptraum, mitten am Tag, vermutlich am Keyboard eingenickt. Aber was könnte mir so einen Schrecken eingejagt haben, daß ich davon einen Tron .. ähm… traum hatte ?

Es fällt mir wieder ein, ich war grade dabei den Beitrag „Revenge of MariaDB“ Part II zu schreiben. Ja, MariaDB, was war doch gleich … achja.. ging mal wieder nicht nach dem Wechsel von F23 auf F24. Einer unserer Datenbankserver  macht merkwürdige Dinge. Die Webanwendung produzierte sporadisch „Kann nicht in die Datenbank verbinden“ Fehlermeldungen und brachte damit die QA vom Kunden an den Rand des Nervenzusammenbruchs.

Die Analyse geschaltete sich schwierig, weil die Admins immer erst nach einem Vorfall gerufen wurden, aber da ging es wieder. Erst eine zeitnahe Analyse des Netzwerkverkehrs bracht dann den ersten Hinweis: „Can’t create a new Thread. If you have enough free memory, check if … “

Damit konnte man etwas anfangen, ein Blick in eine spezielle Überwachungsdatei brachte dann den Hinweis, daß statt 40.000 Datenbankprozessen, nur wenige Hundert liefen. Also half nur ein Testlauf, mit einer Software, die Verbindungen in die Datenbank aufbaut und offen hält. Sowas kann man schnell in PHP, Perl oder Java schreiben:

import ordb.*;

public class Test {

    public static void main(String[] args) {

        Httpd[] liste = new Httpd[100000];
        for(int i=0;i< Integer.parseInt( args[0] );i++) {
            System.out.println("i="+i);
            liste[i] = new Httpd();
        }
        try {
            Thread.sleep(30000);
        } catch(Exception e) {

            e.printStackTrace();
            System.out.println(e);
        }

    }

}

In einer zweiten Konsole, kann man dann den Datenbankserver überwachen :

strace -e send,read,write -s 1024 -f -p `pidof mysqld`

Damit hat man alle Datenbankserverinstanzen im Blick, was die so Lesen und Schreiben und tatsächlich bestätigte dies den Anfangsverdacht, daß der Datenbankserver nicht genug Prozesse spawnen kann. Er setzte bei 512 Prozessen aus, viel zu wenig für unsere Anwendung.

Der schwierige Teil : Limits prüfen

Als erstes denkt man natürlich, daß sich bei den Limits aus Systemd und die Limits : The Revenge of Mariadb etwas geändert hätte, hatte es aber nicht. Wenn man das OS updatet können aber noch ganz andere Dinge passieren, also muß man hier nach „neuen“ Limits suchen.  Um überhaupt die Limits eines Prozesses Live einsehen zu können, muß man ins /proc/ eintauchen:  cat /proc/`pidof mysqld`/limits

Das kann dann so aussehen:

Limit                     Soft Limit           Hard Limit           Units     
Max cpu time              unlimited            unlimited            seconds   
Max file size             unlimited            unlimited            bytes     
Max data size             unlimited            unlimited            bytes     
Max stack size            unlimited            unlimited            bytes     
Max core file size        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             unlimited            unlimited            processes 
Max open files            65536                65536                files     
Max locked memory         65536                65536                bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       32195                32195                signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us

Dummerweise sagt dies genau, was man nicht hören will: Alles ok, es gibt keine Limits bei den Prozessen.

Und jetzt steht man da, wo zum Geier kommt dieses 512 Prozesse Limit her?

Es gibt eine Datei namens:  /etc/security/limits.conf

In der könnte man Limits für User eintragen, was aber nicht der Fall war. Außerdem wäre das in der Auflistung genau dieser Limits aufgefallen. Wo kommt dann das Limit her ?

An der Stelle muß man dann praktisch zu Denken anfangen, weil Docs lesen bringt einen fast nicht weiter, weil man gar nicht damit rechnet, daß es noch mehr Limitmöglichkeiten gibt, also auch nicht weiß in welcher Richtung man suchen sollte. Ein gesunder Pragmatismus ist jetzt hilfreich, vielleicht wars auch eine Verzweiflungstat :  grep -r 512 /etc/ /proc/sys/

Also in allen Dateien von ETC und PROC nach einer EIntragung mit 512 zu suchen. Und genau das hat zum Erfolg geführt, so daß ich jetzt eine Anklage wegen Ruhestörung und einen Abdruck meiner Hand an der Stirn habe 😀

Der SystemD macht mehr als er sollte

Im SystemD gibt es eine Konfigurationsdatei : /etc/systemd/system.conf

Der Auslieferungszustand bei Fedora ist, daß dort alle Werte auskommentiert sind, also ungültig sind. Dort fand sich eine 512 Eintragung und der Name der Option war … DefaultTasksMax=512 !

Aber die Option war abgeschaltet, also ist doch die erste Annahme, daß es kein Limit gibt, oder? Tja, Pech gehabt! Der Wert ist nur Deko, weil als Default in den SystemD einkompiliert 🙁

Zum Glück kann man den Wert in dieser Config ändern, den SystemD + MariaDB neustarten und dann wird der neue, unlimitierte Wert auch übernommen. Er taucht in keiner ( mir bekannten ) Procdatei auf. (Hinweise willkommen)

Alles in allem eine Änderung die wohl zu einer heftigen Reaktion seitens der Betroffenen geführt hat, weil die Systemd Entwickler das in einer neueren Version auf 15% der möglichen Prozesse eines Systems limitiert haben. In  unserem Fall wäre das noch schlimmer gewesen, weil wir so noch schlechter hätten Debuggen können, weil es sehr viel seltener passiert wäre.

Warum gibt es das Limit überhaupt ? Ja, weil es Bomben gibt. Das sind z.b. Bashscripte die sich selbst starten und dabei von der Shell abforken, so daß nach kurzer Zeit alle Resourcen eines Systems aufgebraucht sind. Hackt man also einen Server, könnte man den so intern dosen. Damit das nicht geht, gibt wenigstens ein Limit 😉 Das mal jemand Fedora als Server benutzt und dann auch noch als High Performance, damit hatte wohl niemand gerechnet 😀

Meiner Meinung nach, sollte sich der SystemD auf das Starten von Programmen konzentrieren, denn da ist er bedingt besser als SystemV. Aber die ganzen anderen Anmaßungen die das Teil so vornimmt, sind nicht so schön. Der SystemD kann einen echt fertig machen 😉

Ich bin mal gespannt, was beim nächsten OS Upgrade auf uns wartet 😉

Wie man die TMP Ramdisk entfernt

Auf normalen Desktopsystemen ist es eine gute Sache, wenn der /tmp/ Ordner im RAM liegt. Auf /tmp/ wird sehr häufig und meistens eher kleinteilig zugegriffen, so das man diese Zugriffe  am besten von der Festplatte oder der SSD fern hält. Auf einem Server kann das aber auch von Nachteil sein.

[root@server ~]# df -h
Dateisystem    Größe Benutzt Verf. Verw% Eingehängt auf
devtmpfs        5,0G       0  5,0G    0% /dev
tmpfs           5,0G       0  5,0G    0% /dev/shm
tmpfs           5,0G    532K  5,0G    1% /run
tmpfs           5,0G       0  5,0G    0% /sys/fs/cgroup
/dev/xvda1      245G    178G   56G   77% /
tmpfs           5,0G     38M  5,0G    1% /tmp
tmpfs          1012M       0 1012M    0% /run/user/0

Im obigen Beispiel von einem unserer Server, kann man sehen, daß für die „tmpfs“ Laufwerke 5 GB maximale Größe angegeben ist. DEV, RUN, SYS werden das niemals erreichen, die sind eher im KB Bereich angesiedelt. Über die Sinnhaftigkeit, dann 5 GB als MAX Größe zu nehmen, kann man sicher streiten. Ist aber für die Betrachtung egal, denn es handelt sich um eine dynamische Speicherbelegung, deswegen auch „maximale Größe“. In Real sind die genau so groß, wie die Daten darin das brauchen. Lege ich dort 1 MB ab, ist es 1 MB und ein bisschen was für die Verwaltung groß.

An der „Verwendung“ in Prozent bzw. „Benutzt“ kann man auch sehen, das oben keins der TmpFS Ramdrives übermäßig belegt war. Die Ramdrives haben also bei dem Stand zusammen grade mal 39 MB echten Speicher belegt.

So weit, so gut.

Das obige Serversystem hat 10 GB Speicher zur Verfügung, was es üblicherweise auch braucht. d.h. es sind permanent mehrere GB an RAM in realer Benutzung.

Datenbankserver wie MariaDB erlauben es den Benutzern bei Abfragen sogenannte TEMP-Tables zu erstellen. Das wird vorzugsweise im RAM gemacht. Wenn aber das RAM nicht reicht, weil jemand einen TEMP-Table zusammen baut, der mehrere GB groß ist, dann wird das in den /tmp/ Ordner ausgelagert. Und man glaubt gar nicht wie unsensible mache Anwendungsentwickler im Umgang mit solchen Temp-Tables sind. „Killer SQL-Anweisungen“ in Shops, die „ein bisschen mehr und schneller“  gewachsen sind, als die Hersteller das erwartet haben, sind keine Seltenheit. Schlechtes Datenbankdesign sowieso nicht 😉  Und damit fängt der Ärger dann üblicherweise auch an.

Was bei einem Killer-SQL passieren kann …

Der Hauptspeicher des Datenbankserver hatte schon nicht ausgereicht um den Temp-Table anzulegen, und über die Ramdisk wird jetzt versucht den Speicher zusätzlich nochmal zu belegen, der vorher schon nicht ausreichend da war. Der Kernel wird jetzt versuchen diese Datenmengen zu swappen und kann das vielleicht nicht, weil die SWAP Partition zu klein ist. Nun kommt es zum „OOM“ dem Out-of-Memory-Error. d.h. der Kernel fängt an, scheinbar wahllos Prozesse zu killen, die viel Speicher belegen, aber noch nicht lange laufen. Eine genauere Analyse nimmt der Kernel leider nicht vor.

Wie kommt man jetzt aus der Falle wieder raus ?

Verantwortlich für das Erzeugen der Ramdisk ist diese Systemd Unit : /usr/lib/systemd/system/tmp.mount

#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.

[Unit]
Description=Temporary Directory
Documentation=man:hier(7)
Documentation=http://www.freedesktop.org/wiki/Software/systemd/APIFileSystems
ConditionPathIsSymbolicLink=!/tmp
DefaultDependencies=no
Conflicts=umount.target
Before=local-fs.target umount.target

[Mount]
What=tmpfs
Where=/tmp
Type=tmpfs
Options=mode=1777,strictatime

Die kann man mit einem kurzen Befehl an den Systemd abschalten, allerdings erst ab dem nächsten Bootvorgang:

# systemctl mask tmp.mount
Created symlink from /etc/systemd/system/tmp.mount to /dev/null.
# ls -la /etc/systemd/system/tmp.mount
lrwxrwxrwx 1 root root 9 14. Nov 11:45 /etc/systemd/system/tmp.mount -> /dev/null

Danach muß man das also Rebooten. Am Ende ist /tmp/ dann wieder ein normaler Ordner auf der Festplatte, der keiner Größenbeschränkung unterliegt und in dem der Datenbankserver dann auch wieder fast beliebig große Temp-Tables erzeugen kann, ohne das gleich ein unschuldiger Prozess dran glauben muß.

 

Systemd: wie man Journals sicher verkleinert

Privat wird man das Problem eher seltener anfinden, aber wenn man eine Linux Serverfarm betreibt, kommt es häufiger vor, daß Server wenig Platz auf den Platten melden. I.d.R. passiert das unabsichtlich, weil irgendwelche Logfiles oder selbstgebauten Sicherungssysteme der Kunden jeden Tag Daten auf die Platte kippen, welche die Kunden schon lange vergessen haben.

Bei der Suche nach Platz benutzt man auf einem Server eher selten Baobab, dafür meistens „du -sh /*|grep G“ .

Irgendwann bei der Suche, stolpert man über die großen Mengen Speicherplatz die in /var/log verwendet werden und hier ist i.d.R. der Syslogd der Platzkiller. Nun will man natürlich auch ältere Logs haben, damit darin nach Fehlern suchen kann. Insofern ist es ok, wenn die Logs etwas größer sind. Damit man aber schnell mal 2 GB Platz auf der Platte für andere Sachen gewinnt, kann man z.b. folgende Befehle benutzen:

journalctl --vacuum-time=10d
journalctl --vacuum-size=1G

Der erste Befehl löscht alle Logs, die älter als 10 Tage sind. Der zweite Befehl löscht alles weg, was mehr als 1 GB belegt. Ein 1 GB Log sollte für alle jüngeren Problemfälle reichen.

Jetzt könnte man die Größe des Logfiles in der Systemd Konfiguration dauerhaft hinterlegen, oder man nutzt den freien Platz nur temporär. Wenn man sich für letzteres entscheidet, darf man das Problem nicht auf die Lange Bank schieben, sondern sollte schnellstmöglich eine Entlastung der Platte durch Löschen anderer Daten herbeiführen.

Systemd Änderungen brechen langlaufende Prozesse ab

Für die Version 230 vom Systemd sind Anpassungen umgesetzt worden, die noch nicht alle Distributionen erreicht haben, aber jetzt schon Ihre Schatten vorraus werfen.

Das Defaultverhalten zu langlaufenden Prozessen wird geändert, was bedeutet, daß Prozesse, die per Screen(und anderen Tools) gestartet wurden, beim Logout des Users beendet werden. Screen ist aber gerade dafür da, daß man sich während der Prozess läuft, ausloggen kann,

Das neue Verhalten führte bei Debian bereits zu ersten Beschwerden der User. Zum Glück kann man das leicht abschalten:

Ladet die Datei /etc/systemd/login.d.conf in einen Texteditor und kommentiert die Zeile(n):

KillUserProcesses=no
KillOnlyUsers=
KillExcludeUsers=root

ein. Damit ist wieder alles wie vorher. ( A.d.R. ggf. ist ein Neustart des Loginds nötig, sprich ein Reboot )

 

 

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.

Systemd und die Limits

„Jedes System kommt irgendwann an seine Grenzen.“ Einer meiner Server hatte die Grenze heute überschritten. Die Folge, der Apache stieg mit dieser Meldung aus :

„apache (24)Too many open files: couldn’t spawn child process:“

Jetzt können Sie soviel googlen wie Sie wollen, alles was zu dem Fehler kommt ist nicht hilfreich. Alle Hinweise  von RedHat zu limitfiles auf  /etc/security/limits.conf  oder /proc/sys/fs/file-max können Sie getrost vergessen, die greifen in dem Fall gar nicht.

Wenn Sie jetzt ein System V haben, ist /etc/init.d/httpd für Sie da. Tragen Sie dort einfach ulimit -n 100000 ein und starten Sie den Apache neu. Fall erledigt.

Für den Systemd, wie ihn Fedora seit FC 16 einsetzt, sieht die Sache ähnlich einfach aus, wenn man weiß wo man suchen muß. Aber mal ehrlich, würden SIe als Linuxer darauf kommen, daß „man systemd.exec“ die Hilfeseite zum Systemd öffnet? Ich nicht, .exe oder ähnliche Erweiterungen sind Windows Extentions.

Die Manpage liefert eine Übersicht zu den Variblen  die man im Unitfile benutzen kann und eine davon ( immerhin 5 Bildschirmseiten voll davon gibt es ) ist Ihr Freund: „LimitNOFILE

Suchen Sie mit „locate httpd.service“ ihr Unitfile, das ist üblicherweise unter /usr/lib/systemd/system/httpd.service zu finden. Tragen Sie dort im Servicebereich die Variable ein :

[Service]
Type=forking
PIDFile=/var/run/httpd/httpd.pid
LimitNOFILE=1000000
EnvironmentFile=/etc/sysconfig/httpd

Führen Sie noch die zwei Zeilen aus :

systemctl –system daemon-reload
systemctl restart httpd

und Ihr Apache rennt wieder 🙂

Ursachenanalyse:

Jedes Apache Child öffnet alle Domainlogs auf dem Server. Wenn Sie nun einen Multidomainwebserver haben, so wie meine Kunden, dann kommen dort schnell 1000 Vhosts zusammen. Das macht 1000 Files pro httpd-Child und damit viel mehr offene Files als Fedora defaultmäßig bereitstellt.

Hier wäre natürlich ein Logfilebroker für Apache die richtige Lösung, aber da brauchen wir wohl seitens Apache nicht drauf hoffen.