Vor 10 Jahren sah sich Google mit einem kritischen Engpass konfrontiert, der durch extrem lange C++-Kompilierungszeiten verursacht wurde, und brauchte einen völlig neuen Weg, um dieses Problem zu lösen. Die Google-Ingenieure nahmen die Herausforderung an, indem sie eine neue Sprache namens Go (auch bekannt als Golang) entwickelten. Die neue Sprache Go borgt sich die besten Teile von C++ (vor allem seine Leistungs- und Sicherheitsfunktionen) und kombiniert sie mit der Geschwindigkeit von Python, um Go in die Lage zu versetzen, schnell mehrere Kerne zu nutzen und gleichzeitig Gleichzeitigkeit zu implementieren.

Bei Coralogix analysieren wir die Protokolle unserer Kunden, um ihnen Einblicke, Warnungen und Metadaten zu ihren Protokollen in Echtzeit zu geben. Um das zu erreichen, muss die Analysephase, die sehr komplex ist und eine Vielzahl von Regeln für jeden Log-Line-Service enthält, extrem schnell sein. Das ist einer der Gründe, warum wir uns für Go lang entschieden haben.

Der neue Dienst läuft jetzt Vollzeit in der Produktion, und obwohl wir großartige Ergebnisse sehen, muss er auf Hochleistungsmaschinen laufen. Mehr als zehn Milliarden Protokolle werden jeden Tag von diesem Go-Service analysiert, der auf einer AWS m4.2xlarge-Instanz mit 8 CPUs und 36 GB Arbeitsspeicher läuft.

In diesem Stadium hätten wir mit dem guten Gefühl, dass alles gut läuft, Feierabend machen können, aber so sind wir hier bei Coralogix nicht vorgegangen. Wir wollten mehr Funktionen (Leistung usw.) mit weniger Mitteln (AWS-Instanzen). Um uns zu verbessern, mussten wir zunächst die Art unserer Engpässe verstehen und herausfinden, wie wir sie reduzieren oder ganz beseitigen können.

Wir beschlossen, ein Golang-Profiling für unseren Service zu erstellen und zu prüfen, was genau den hohen CPU-Verbrauch verursacht, um zu sehen, ob wir ihn optimieren können.

Zuerst haben wir auf die neueste stabile Go-Version aktualisiert (ein wichtiger Teil des Software-Lebenszyklus). Wir arbeiteten mit der Go-Version v1.12.4, und die neueste war 1.13.8. Die Version 1.13 enthielt laut Dokumentation wichtige Verbesserungen in der Laufzeitbibliothek und einigen anderen Komponenten, die hauptsächlich die Speichernutzung betrafen. Unterm Strich war es hilfreich, mit der neuesten stabilen Version zu arbeiten, was uns einiges an Arbeit erspart hat →

Damit verbesserte sich der Speicherverbrauch von etwa ~800MB auf ~180MB.

Zweitens, um ein besseres Verständnis unseres Prozesses zu bekommen und zu verstehen, wo wir Zeit und Ressourcen verbrauchen, haben wir begonnen, Profile zu erstellen.

Die Erstellung von Profilen für verschiedene Dienste und Programmiersprachen mag komplex und einschüchternd erscheinen, aber in Go ist es eigentlich ziemlich einfach und kann mit wenigen Befehlen beschrieben werden. Go hat ein spezielles Tool namens ‚pprof‘, das in deiner App aktiviert werden sollte, indem du eine Route abhörst (Standard-Port 6060) und das Go-Paket für die Verwaltung von http-Verbindungen verwendest:

import _ "net/http/pprof"

Dann initialisiere Folgendes in deiner Hauptfunktion oder unter deinem Route-Paket:

go func() {log.Println(http.ListenAndServe("localhost:6060", nil))}()

Jetzt kannst du deinen Dienst starten und dich mit

http://localhost:6060/debug/pprof

Die vollständige Dokumentation von Go findest du hier.

Das Standard-Profiling für pprof ist eine 30-Sekunden-Stichprobe der CPU-Auslastung. Es gibt ein paar verschiedene Pfade, die Sampling für CPU-Nutzung, Heap-Nutzung und mehr ermöglichen.

Wir haben uns auf die CPU-Auslastung konzentriert, also haben wir ein 30-Sekunden-Profiling in der Produktion durchgeführt und das entdeckt, was Sie im Bild unten sehen (zur Erinnerung: dies ist nach dem Upgrade unserer Go-Version und der Reduzierung der internen Teile von Go auf das Minimum):

Go profiling – Coralogix

Wie Sie sehen können, haben wir eine Menge Laufzeit-Paket-Aktivität gefunden, die speziell auf GC-Aktivität hindeutet → Fast 29% unserer CPU (nur die Top 20 der am meisten verbrauchten Objekte) wird von GC verwendet. Da Go GC recht schnell und ziemlich optimiert ist, ist es die beste Praxis, es nicht zu ändern oder zu modifizieren, und da unser Speicherverbrauch sehr niedrig war (im Vergleich zu unserer vorherigen Go-Version), war der Hauptverdächtige eine hohe Objekt-Allokationsrate.

Wenn das der Fall ist, gibt es zwei Dinge, die wir tun können:

  • Die Go GC-Aktivität so einstellen, dass sie sich an das Verhalten unseres Dienstes anpasst, d.h. – ihren Auslöser verzögern, um die GC weniger häufig zu aktivieren. Dies wird uns zwingen, mit mehr Speicher zu kompensieren.
  • Finden Sie die Funktion, den Bereich oder die Zeile in unserem Code, die zu viele Objekte alloziert.

Bei der Betrachtung unseres Instanztyps war klar, dass wir viel Speicher übrig hatten und derzeit an die CPU der Maschine gebunden sind. Also haben wir einfach das Verhältnis geändert. Golang hat seit seinen Anfängen ein Flag, das den meisten Entwicklern nicht bekannt ist: GOGC. Dieses Flag, mit einer Voreinstellung von 100, teilt dem System einfach mit, wann GC ausgelöst werden soll. Der Standardwert löst den GC-Prozess aus, wenn der Heap 100% seiner ursprünglichen Größe erreicht. Das Ändern dieses Wertes auf eine höhere Zahl verzögert den GC-Auslöser und ein niedrigerer Wert löst GC früher aus. Wir haben mit dem Benchmarking verschiedener Werte begonnen und die beste Leistung für unsere Zwecke erzielt, wenn wir: GOGC=2000.

Dies erhöhte sofort unsere Speichernutzung von ~200MB auf ~2,7GB (das ist, nachdem der Speicherverbrauch durch unser Go-Versionsupdate gesunken ist) und verringerte unsere CPU-Nutzung um ~10%.
Der folgende Screenshot zeigt die Benchmark-Ergebnisse:

GOGC =2000 Ergebnisse – Coralogix Benchmark

Die Top 4 der CPU-verbrauchenden Funktionen sind die Funktionen unseres Dienstes, was Sinn macht. Die gesamte GC-Nutzung beträgt jetzt ~13%, weniger als die Hälfte des früheren Verbrauchs(!)

Wir hätten hier aufhören können, beschlossen aber, herauszufinden, wo und warum wir so viele Objekte zuweisen. In vielen Fällen gibt es einen guten Grund dafür (z.B. bei der Verarbeitung von Datenströmen, wo wir für jede Nachricht, die wir erhalten, viele neue Objekte erstellen und sie loswerden müssen, weil sie für die nächste Nachricht irrelevant sind), aber es gibt Fälle, in denen es einen einfachen Weg gibt, die Erstellung von Objekten zu optimieren und drastisch zu verringern.

Zunächst führen wir denselben Befehl wie zuvor aus, mit einer kleinen Änderung, um den Heap-Dump zu erstellen:

http://localhost:6060/debug/pprof/heap

Um die Ergebnisdatei abzufragen, können Sie den folgenden Befehl in Ihrem Code-Ordner ausführen, um den Dump zu analysieren:

go tool pprof -alloc_objects <HEAP.PROFILE.FILE>

Unser Snapshot sah wie folgt aus:

Alles schien vernünftig zu sein, bis auf die dritte Zeile, bei der es sich um eine Überwachungsfunktion handelt, die am Ende jeder Coralogix-Regelparsing-Phase an unseren Prometheus-Exporter berichtet. Um tiefer einzusteigen, führten wir den folgenden Befehl aus:

list <FunctionName>

Zum Beispiel:

list reportRuleExecution

Und dann erhielten wir folgendes:

Leave a comment

Deine E-Mail-Adresse wird nicht veröffentlicht.