Postmortem zum 73-stündigen Ausfall von Roblox im vergangenen Jahr

Zusammenfassung des Ausfalls

• Der Ausfall dauerte 72 Stunden.

• Es gab zwei Grundursachen.

  • Durch die Aktivierung der neuen Streaming-Funktion von Consul in einer Situation mit ungewöhnlich hoher Lese-/Schreiblaste kam es zu übermäßiger Contention und Performance-Einbußen.

  • Unter bestimmten Lastbedingungen verursachte die Open-Source-Datenbank BoltDB, die Consul zur Verwaltung des Write-Ahead-Logs für Leader Election und Datenreplikation verwendet, Performance-Probleme.

• Ein einzelner Consul-Cluster verschärfte die Auswirkungen dieser Probleme.

• Der Ausfall verlängerte sich, weil diese beiden scheinbar unabhängigen Probleme in der Consul-Implementierung erst gefunden werden mussten.

• Das Monitoring-System, das eigentlich eine bessere Sichtbarkeit der Ursache hätte liefern sollen, war wie Consul selbst von betroffenen Systemen abhängig und machte die Fehlersuche dadurch noch schwieriger.

Cluster-Umgebung und HashiStack

• Roblox betreibt 18.000 Server und 170.000 Container.

• Verwendet werden Nomad, Consul und Vault, üblicherweise als HashiStack bezeichnet.

Damals aktualisierte Roblox Consul von 1.9 auf 1.10, um die Streaming-Funktion zu nutzen.

Erste Erkennung (10/28 13:37)

Am 18. Oktober nahm die Performance von Vault ab, und auf einem Consul-Server stieg die CPU-Last stark an.

Erste Eingrenzung (10/28 13:37 – 10/29 02:00)

• In den Metriken des Consul-Clusters stieg die Schreiblatenz an.

• Zunächst wurde ein Hardware-Performanceproblem vermutet, und einer der Consul-Cluster-Knoten wurde ersetzt.

• Mitarbeitende von HashiCorp stiegen mit ein und arbeiteten gemeinsam an der Analyse.

• Auch nach dem Hardwaretausch verschlechterte sich die Consul-Performance weiter, und um 16:35 fiel die Zahl der Spieler auf 50 % des Normalwerts.

• Da Consul für Service Discovery verwendet wurde und auch Nomad und Vault auf Consul angewiesen waren, war Consul ein SPoF.

• Zu diesem Zeitpunkt entstand die neue Hypothese, dass der Traffic die Ursache sei. Man ging davon aus, dass Consul die hohe Last nicht mehr bewältigen konnte.

• Alle Knoten des Consul-Clusters wurden durch leistungsfähigere Systeme ersetzt (doppelt so viele Kerne, schnellere NVME-SSDs).

• Die Migration von Consul war fast abgeschlossen, aber der Cluster kehrte nicht in einen normalen Zustand zurück.

Versuch 1 zur Wiederherstellung des Dienstes (10/29 02:00 – 04:00)

• Es wurde beschlossen, auf einen Snapshot des Consul-Clusters von vor dem Ausfall zurückzugehen.

• Die Benutzerdaten waren in Ordnung, und ein teilweiser Verlust von Systemdaten wurde als akzeptabel eingeschätzt.

• Nach der Snapshot-Wiederherstellung wurde der Zugriff per iptables blockiert, um zu verhindern, dass Systeme, die kontinuierlich mit Consul kommunizierten, direkt wieder Last erzeugen und neue Probleme auslösen.

• Nach der Snapshot-Wiederherstellung sahen die Kennzahlen zunächst gut aus, aber sobald die iptables-Sperre aufgehoben wurde, kehrte der ursprüngliche Ausfallzustand zurück.

Versuch 2 zur Wiederherstellung des Dienstes (10/29 04:00 – 10/30 02:00)

• Externer Traffic wurde blockiert und nicht essenzielle Nutzung entfernt, sodass Dienste, die zuvor mit Hunderten von Instanzen liefen, auf eine einstellige Zahl reduziert wurden.

• Ein weiterer Wiederherstellungsversuch wurde unternommen, aber Consul geriet erneut in einen anormalen Zustand.

• Es wurde klar, dass es neben den anfangs vermuteten Performance-Faktoren noch etwas anderes geben musste, und der Blick richtete sich nicht mehr nur auf Consul aus Roblox-Perspektive, sondern auf die internen Abläufe von Consul selbst.

Analyse der Contention (10/30 02:00 – 10/30 12:00)

• Nach weiteren 10 Stunden Analyse wurde klar, dass Consul-Schreibvorgänge über längere Zeit blockiert waren.

• Die genaue Ursache der Contention war noch unbekannt, aber man kam zu dem Schluss, dass die anfängliche Erhöhung von 64 auf 128 CPU-Kerne die Contention noch verschärft hatte.

• Es wurde entschieden, wieder auf 64 Kerne zurückzugehen, doch das half nicht.

Entdeckung der Grundursache (10/30 12:00 – 10/30 20:00)

• Die Streaming-Funktion von Consul war bereits seit einigen Monaten aktiviert und wurde schrittweise ausgerollt, weil sie CPU-Auslastung und Netzwerkbandbreite reduzierte.

• Am 27. um 14:00 Uhr, also einen Tag vor dem Ausfall, wurde die Funktion im Backend für das Traffic Routing aktiviert.

• Weil sie nach der Aktivierung am Vortag problemlos funktioniert hatte, wurde sie zunächst nicht als Ursache in Betracht gezogen.

• Nach der Performance-Analyse fand man Hinweise darauf, dass der Streaming-Code eine hohe CPU-Last verursachte.

• Nach der Deaktivierung des Streamings und Abschluss des Deployments verringerte sich die KV-Schreiblatenz von Consul endlich.

• HashiCorp erklärte, dass Streaming zwar effizienter sei, in der Implementierung aber statt Long Polling weniger Concurrency-Control-Elemente (Go-Channels) verwendet wurden -> unter hoher Last verschärfte die Contention auf einem einzelnen Go-Channel die Ineffizienz.

• Es gab zwar einen Durchbruch, doch weiterhin wurden sporadische Leader Elections beobachtet, und einige Leader zeigten ähnliche Latenzprobleme wie zuvor.

• Da der Cluster als normal angesehen wurde, solange bestimmte Leader nicht gewählt wurden, konzentrierte man sich darauf, den Dienst wieder in einen stabilen Zustand zu bringen.

• Danach untersuchte HashiCorp die Grundursache weiter und fand heraus, dass das Problem langsamer Leader bei einigen Knoten auf BoltDB zurückzuführen war.

Wiederherstellung des Cache-Dienstes (10/30 20:00 – 10/31 05:00)

• Nach 54 Stunden Ausfall war man bereit, den Dienst wiederherzustellen.

• Während des Ausfalls war die Datenbank in Ordnung, aber das Cache-System, das 1 Milliarde Requests pro Sekunde verarbeitet, befand sich in einem anormalen Zustand.

• Nach der Wiederherstellung dieses Caches und der Bestätigung des Normalbetriebs waren seit Beginn des Ausfalls 61 Stunden vergangen.

Rückkehr der Nutzer (10/31 05:00 – 10/31 16:00)

• Am 31. um 5 Uhr begann die Vorbereitung für die Wiederinbetriebnahme und wurde um 10 Uhr abgeschlossen.

• Die Zahl der über DNS zugreifenden Spieler wurde überwacht und schrittweise erhöht.

• Nach 73 Stunden konnten wieder alle Spieler auf den Dienst zugreifen.

Weitere Analyse und Änderungen infolge des Ausfalls

• HashiCorp und Roblox entwickelten einen "Kompressions"-Prozess, um die Performance-Probleme zu beheben.

• Verbesserte Telemetrie: Zwischen dem Telemetrie-System und Consul bestand eine zyklische Abhängigkeit, sodass bei Problemen mit Consul zu wenig Daten verfügbar waren. Diese zyklische Abhängigkeit wurde entfernt, damit das Telemetrie-System nicht mehr von den Systemen abhängt, die es überwacht.

• Ausbau von Availability Zones und Rechenzentren.

• Aufräumen unnötiger KV-Daten bzw. Entfernen von Daten aus Consul, obwohl andere Storage-Systeme verfügbar waren.

• Eine neue Version von Consul, die den BoltDB-Nachfolger bbolt verwendet, wird getestet.

• Da der Bootstrap-Prozess die Wiederherstellung verzögerte, wird dieser automatisiert und es werden neue Tools und Prozesse entwickelt.

[xguru]

Vielen Dank für die gute Übersetzung.

Ein Ausfall von 72 Stunden in dieser Größenordnung ist wirklich beängstigend.