Reboot tut (nicht immer) gut
TLDR: Es gab heute um 13:15 einen ungeplanten Reboot und eine damit verbundene, sehr kurze Downtime bei allen U7-Hosts. Grund war, dass wir wegen einem journald-Bug einen Reboot benötigt haben, diesen aber (intern) nicht sauber kommuniziert haben: Code ausgerollt, zack Reboot! Das tut uns leid und sollte in Zukunft nicht mehr passieren. Mehr dazu weiter unten.
Heute am 22.01.2018 gegen 13:15 wurden alle unsere Uberspace 7 Hosts nicht 100% geplant rebootet. Die meisten Hosts waren nach weniger als zwei Minuten wieder da; geplant oder gar angekündigt war der kurze Ausfall allerdings dennoch nicht. Wir möchten euch in diesem Blogpost darlegen, wie es überhaupt dazu gekommen ist.
Unser Deployment-Setup sieht es vor, dass manche Ansible-Rollen einen Reboot triggern dürfen. Bisher wurde diese Funktionalität nur von der Quota-Rolle genutzt, die Mount-Flags der Root-Partition umsetzen muss. Das geht bei unserem Datensystem und Setup eben nur mit einem Reboot. Im Normalfall passiert das während dem initialen Deployment des Systems - also lange bevor User ihre Accounts darauf bekommen.
The curious case of journald
Das Problem war eigentlich ganz einfach: Die systemd-Logs im journald wurden zu schnell gelöscht, wir wollten die gerne länger aufheben. Dazu gibt es natürlich ein Config-File und eine passende Option SystemMaxUse=, die beschreibt wie viel Platz maximal durch die Log-Files belegt werden darf. Wir haben diese Option also angepasst, den journald neugestartet (reloads unterstützt er nämlich nicht) und siehe da: Die Logs sind auf unserem Test-Systemen länger verfügbar. Alles gut.
Alles gut, bis wir versucht haben die Änderung zu integrieren. Plötzlich ist nämlich unser IMAP/POP3-Server dovecot beim Reload der Config unerwartet verstorben. Nach einem systemclt restart dovecot hat allerdings alles wie gewohnt funktioniert. Zunächst war uns der Zusammenhang zwischen einer journald-Änderung und einem Dovecot-Reload recht schleierhaft. Als wir uns allerdings mit strace an den Prozess gehängt haben, wurde die Sache klarer:
(...)
write(2, "Jan 18 11:30:39 master: Warning:"..., 75) = -1 EPIPE (Broken pipe)
(...)
+++ exited with 81 +++
Dovecot versucht während dem Reload etwas nach stderr (also File-Deskriptor 2) zu schreiben und scheitert dabei, weil die Pfeife kaputt ist. Grund ist, dass unsere Version von journald durch einen Bug nicht in der Lage ist bei einem Restart die schon offenen Log-Handles der laufenden Services an die neue Instanz weiterzugeben. Alle Prozesse, die also nach dem journald-Restart etwas ins systemd-Log schreiben möchten, müssen also mit dieser Situation umgehen. Dovecot tut es, indem er sich beendet. Dieser Bug ist neueren Versionen von systemd bereits gefixt, auf CentOS 7 allerdings nicht.
Die einzig saubere Möglichkeit dem journald eine neue Config zu geben, ist in unserem spezifischen Setup also ein Reboot. Zum Glück müssen wir gerade diese Config nur einmalig, oder nie wieder anfassen, sodass ein Reboot an sich kein großes Problem darstellt.
Kommunikation, Kommunikation, Kommunikation
Nachdem Janto und ich das zugrunde liegende journald-Problem gefunden haben, hat die journald-Config einen Reboot-Trigger bekommen, die Tests liefen durch und wir waren glücklich. Moritz hat ein paar Tage später (so wie immer) ein Release zusammengepackt, das Changelog geschrieben und vertwittert, dass es jetzt ein Uberspace 7.0.25 gibt. Was aber niemand außer uns beiden Devs wusste, ist, dass dieses Release einen Reboot auslöst. Hier sehen wir unser großes Versäumnis, das letzten Endes zu der oben beschrieben kleinen Downtime geführt hat.
Die Moral von der Geschicht'
Wir haben in diesem Fall Glück im Unglück, weil die meisten Hosts in unter 2 Minuten wieder verfügbar waren. Wir haben den “Ausfall” also großteils selbst erst mitbekommen, als er schon wieder vorbei war. Dennoch ist es absolut nicht in unserem Interesse unangekündigt und solange die Sonne scheint Hosts zu rebooten.
Damit das in Zukunft nicht wieder passiert, haben wir uns darauf verständigt in unserem internen Changelog Änderungen, die einen Reboot triggern können, klar als solche zu kennzeichnen. So können wir die Reboots, wie fast alle anderen in der Vergangenheit auch, via Twitter ankündigen und zu einer weit ruhigeren Zeit spät nachts durchführen.
Auch wenn wir mit unserem Kommunikationsfail nur eine sehr kurze Downtime erzeugt haben, die von den allermeisten vermutlich nicht mal registriert wurde, möchten wir hiermit um Entschuldigung bitten. Wir haben daraus gelernt und werden versuchen solche Fälle in der Zukunft zu vermeiden.