Vielleicht kennt jeder Programmierer die Worte von Kent Beck: "Lass es funktionieren, mach es richtig, mach es schnell." Zuerst müssen Sie das Programm zum Laufen bringen, dann müssen Sie es zum Laufen bringen und erst dann können Sie mit der Optimierung fortfahren.
Der Autor des Artikels, dessen Übersetzung wir veröffentlichen, sagt, dass er kürzlich beschlossen hat, die Profilerstellung für sein Open-Source-Go-Projekt
Flipt aufzunehmen . Er wollte Code im Projekt finden, der mühelos optimiert werden konnte und dadurch das Programm beschleunigte. Während der Profilerstellung entdeckte er einige unerwartete Probleme im beliebten Open-Source-Projekt, mit dem Flipt Routing und Middleware-Support organisierte. Infolgedessen konnte die von der Anwendung während des Betriebs zugewiesene Speichermenge um das 100-fache reduziert werden. Dies wiederum führte zu einer Verringerung der Anzahl der Müllsammelvorgänge und zu einer Verbesserung der Gesamtleistung des Projekts. So war es.
Hohe Verkehrserzeugung
Bevor ich mit der Profilerstellung beginnen konnte, wusste ich, dass ich zuerst eine große Menge an Datenverkehr generieren musste, die in die Anwendung eintrat, um einige Verhaltensmuster zu erkennen. Hier stieß ich sofort auf ein Problem, da ich nichts habe, was Flipt in der Produktion verwenden und etwas Verkehr bekommen würde, der es mir ermöglicht, die Arbeit des Projekts unter Last zu bewerten. Als Ergebnis fand ich ein großartiges Tool für Lasttestprojekte. Das ist
Vegeta . Die Autoren des Projekts sagen, dass Vegeta ein universelles HTTP-Tool für Lasttests ist. Dieses Projekt entstand aus der Notwendigkeit, HTTP-Dienste mit einer großen Anzahl von Anforderungen zu laden, die mit einer bestimmten Häufigkeit an Dienste gesendet werden.
Das Vegeta-Projekt erwies sich als genau das Werkzeug, das ich brauchte, da es mir ermöglichte, einen kontinuierlichen Strom von Anfragen an die Anwendung zu erstellen. Mit diesen Anforderungen können Sie die Anwendung so oft "schälen", wie dies erforderlich ist, um Indikatoren wie Zuweisung / Speichernutzung auf dem Heap, Funktionen von Goroutinen und Zeitaufwand für die Speicherbereinigung zu ermitteln.
Nachdem ich einige Experimente durchgeführt hatte, ging ich zur folgenden Konfiguration des Vegeta-Starts:
echo 'POST http://localhost:8080/api/v1/evaluate' | vegeta attack -rate 1000 -duration 1m -body evaluate.json
Dieser Befehl startet
Vegeta im
attack und sendet eine Minute lang HTTP-POST-Anforderungen mit einer Geschwindigkeit von 1000 Anforderungen pro Sekunde (was zugegebenermaßen eine ernsthafte Belastung darstellt) an das
REST-API-Flipt . Von Flipt gesendete JSON-Daten sind nicht besonders wichtig. Sie werden nur für die korrekte Bildung des Anforderungskörpers benötigt. Eine solche Anforderung wurde vom Flipt-Server empfangen, der die Anforderungsüberprüfung durchführen konnte.
Bitte beachten Sie, dass ich mich zuerst entschlossen habe, den Flipt
/evaluate Evaluate-
/evaluate zu testen. Tatsache ist, dass der größte Teil des Codes ausgeführt wird, der die Logik des Projekts implementiert, und dass "komplexe" Server-Berechnungen durchgeführt werden. Ich dachte, die Analyse der Ergebnisse dieses Endpunkts würde mir die wertvollsten Daten zu Bereichen der Anwendung liefern, die verbessert werden könnten.
Messungen
Nachdem ich ein Tool zum Generieren eines ausreichend großen Datenverkehrs hatte, musste ich einen Weg finden, um die Auswirkungen dieses Datenverkehrs auf eine ausgeführte Anwendung zu messen. Glücklicherweise verfügt Go über einen ziemlich guten Standardsatz von Tools, mit denen die Programmleistung gemessen werden kann. Es geht um das
pprof- Paket.
Ich werde nicht auf die Details der Verwendung von pprof eingehen. Ich glaube nicht, dass ich es besser machen werde als Julia Evans, die
diesen wunderbaren Artikel über das Profilieren von Go-Programmen mit pprof geschrieben hat (wenn Sie ihn nicht gelesen haben, empfehle ich Ihnen auf jeden Fall, ihn sich anzusehen).
Da der HTTP-Router in Flipt mit
go-chi / chi implementiert ist, war es für mich nicht schwierig, pprof mit dem
entsprechenden Chi-Intermediate-Handler zu aktivieren.
In einem Fenster arbeitete Flipt für mich, und Vegeta füllte Flipt mit Anfragen und arbeitete in einem anderen Fenster. Ich habe das dritte Terminalfenster gestartet, um Heap-Profildaten zu sammeln und zu untersuchen:
pprof -http=localhost:9090 localhost:8080/debug/pprof/heap
Es verwendet das Google pprof-Tool, mit dem Profildaten direkt im Browser angezeigt werden können.
Zuerst habe ich die
inuse_space inuse_objects und
inuse_space überprüft, um zu verstehen, was auf dem Heap passiert. Ich konnte jedoch nichts Bemerkenswertes feststellen. Als ich mich entschied,
alloc_space alloc_objects und
alloc_space , alarmierte mich etwas.
Analyse der Profilierungsergebnisse ( Original )Es gab das Gefühl, dass etwas namens
flate.NewWriter 19370 MB Speicher für eine Minute reservierte. Und das sind übrigens mehr als 19 Gigabyte! Hier geschah offensichtlich etwas Merkwürdiges. Aber was genau? Wenn Sie sich das Original des obigen Diagramms genau ansehen, stellt sich heraus, dass
flate.NewWriter von
gzip.(*Writer).Write , der wiederum von
middleware.(*compressResponseWriter).Write . Mir wurde schnell klar, dass das, was geschah, nichts mit Flipt-Code zu tun hatte. Das Problem lag irgendwo im
Chi- Middleware-Code, der zum Komprimieren der Antworten von der API verwendet wurde.
// r.Use(middleware.Compress(gzip.DefaultCompression))
Ich habe die obige Zeile auskommentiert und die Tests erneut ausgeführt. Wie erwartet ist eine große Anzahl von Speicherzuweisungsoperationen verschwunden.
Bevor ich anfing, eine Lösung für dieses Problem zu finden, wollte ich diese Speicherzuweisungsvorgänge von der anderen Seite betrachten und verstehen, wie sie sich auf die Leistung auswirken. Insbesondere interessierte mich ihre Auswirkung auf die Zeit, die das Programm zum Sammeln von Müll benötigt. Ich erinnere mich, dass Go immer noch ein
Trace- Tool hat, mit dem Sie Programme während ihrer Ausführung analysieren und Informationen über sie für bestimmte Zeiträume sammeln können. Die von trace erfassten Daten umfassen wichtige Indikatoren wie die Heap-Auslastung, die Anzahl der ausgeführten Goroutines, Informationen zu Netzwerk- und Systemanforderungen und, was für mich besonders wertvoll war, Informationen zu der im Garbage Collector verbrachten Zeit.
Um effektiv Informationen über ein laufendes Programm zu sammeln, musste ich die Anzahl der Anfragen pro Sekunde reduzieren, die mit Vegeta an die Anwendung gesendet wurden, da der Server mir regelmäßig
socket: too many open files Fehler bei
socket: too many open files . Ich nahm an, dass dies darauf zurückzuführen ist, dass
ulimit auf meinem Computer zu niedrig
ulimit war, aber ich wollte dann nicht darauf
ulimit .
Also habe ich Vegeta mit folgendem Befehl neu gestartet:
echo 'POST http://localhost:8080/api/v1/evaluate' | vegeta attack -rate 100 -duration 2m -body evaluate.json
Wenn wir dies mit dem vorherigen Szenario vergleichen, wurde nur ein Zehntel der Anforderungen an den Server gesendet, dies wurde jedoch für einen längeren Zeitraum durchgeführt. Dadurch konnte ich qualitativ hochwertige Daten über die Arbeit des Programms sammeln.
In einem anderen Terminalfenster habe ich den folgenden Befehl ausgeführt:
wget 'http://localhost:8080/debug/pprof/trace?seconds=60' -O profile/trace
Als Ergebnis hatte ich eine Datei mit Trace-Daten zur Verfügung, die in 60 Sekunden gesammelt wurden. Sie können diese Datei mit dem folgenden Befehl untersuchen:
go tool trace profile/trace
Die Ausführung dieses Befehls führte zur Entdeckung der gesammelten Informationen im Browser. Sie wurden in einer praktischen grafischen Form für das Studium präsentiert.
Details zu
go tool trace finden Sie in
diesem guten Artikel.
Flipt Trace-Ergebnisse. Ein Sägezahndiagramm der Speicherzuordnung auf dem Heap ist deutlich sichtbar ( Original )In diesem Diagramm ist leicht zu erkennen, dass die auf dem Heap zugewiesene Speicherkapazität in der Regel recht schnell zunimmt. In diesem Fall sollte nach dem Wachstum ein starker Abfall sein. Die Stellen, an denen der zugewiesene Speicherplatz abfällt, sind Speicherbereinigungsvorgänge. Hier sehen Sie die ausgeprägten blauen Spalten im GC-Bereich, die die für die Garbage Collection aufgewendete Zeit darstellen.
Jetzt habe ich alle Beweise für das „Verbrechen“ gesammelt, das ich brauche, und könnte nach einer Lösung für das Problem der Speicherzuweisung suchen.
Lösung
Um den Grund für den Aufruf von
flate.NewWriter herauszufinden, musste ich mir den
Chi- Quellcode ansehen. Um herauszufinden, welche Chi-Version ich verwende, habe ich den folgenden Befehl ausgeführt:
go list -m all | grep chi github.com/go-chi/chi v3.3.4+incompatible
Nachdem ich den Quellcode
chi / middleware / compress.go @ v3.3.4 erreicht hatte , konnte ich die folgende Methode finden:
func encoderDeflate(w http.ResponseWriter, level int) io.Writer { dw, err := flate.NewWriter(w, level) if err != nil { return nil } return dw }
In weiteren Untersuchungen stellte ich fest, dass die Methode
flate.NewWriter über einen Intermediate-Handler für jede Antwort aufgerufen wurde. Dies entsprach der enormen Menge an Speicherzuweisungsvorgängen, die ich zuvor gesehen habe und die API mit tausend Anforderungen pro Sekunde geladen hat.
Ich wollte weder die Komprimierung von API-Antworten verweigern noch nach einem neuen HTTP-Router und einer neuen Middleware-Unterstützungsbibliothek suchen. Aus diesem Grund habe ich mich zunächst entschlossen herauszufinden, ob es möglich ist, mein Problem einfach durch ein Update von Chi zu lösen.
Ich ließ
go get -u -v "github.com/go-chi/chi" laufen, das auf Chi 4.0.2 aktualisiert wurde, aber der Middleware-Code für die Datenkomprimierung sah, wie es mir schien, genauso aus wie zuvor. Als ich die Tests erneut durchführte, verschwand das Problem nicht.
Bevor ich dieses Problem beendete, entschied ich mich, im Chi-Repository nach Problemen oder PR-Nachrichten zu suchen, die so etwas wie „Komprimierungs-Middleware“ erwähnen. Ich bin auf eine PR mit der Überschrift "Middleware-Komprimierungsbibliothek neu geschrieben" gestoßen. Der Autor dieses PR sagte Folgendes: "Darüber hinaus wird sync.Pool für Encoder verwendet, die über eine Reset-Methode (io.Writer) verfügen, die die Speicherlast reduziert."
Hier ist es! Glücklicherweise wurde diese PR zum Hauptzweig hinzugefügt, aber da kein neues Chi-Release erstellt wurde, musste ich folgendermaßen aktualisieren:
go get -u -v "github.com/go-chi/chi@master"
Dieses Update, das mich sehr gefreut hat, war abwärtskompatibel und erforderte keine Änderungen im Code meiner Anwendung.
Ergebnisse
Ich habe die Auslastungstests und die Profilerstellung erneut durchgeführt. Dadurch konnte ich überprüfen, ob das Chi-Update das Problem behoben hat.
Jetzt verwendet flate.NewWriter ein Hundertstel des zuvor verwendeten zugewiesenen Speichers ( Original )Ein erneuter Blick auf die Trace-Ergebnisse zeigt, dass die Heap-Größe jetzt viel langsamer wächst. Außerdem wurde die für die Speicherbereinigung erforderliche Zeit verkürzt.
Auf Wiedersehen - "Säge" ( Original )Nach einiger Zeit habe ich das Flipt-Repository
aktualisiert , da ich mehr Vertrauen habe als zuvor, dass mein Projekt in der Lage sein wird, mit der hohen Last angemessen umzugehen.
Zusammenfassung
Hier sind die Schlussfolgerungen, die ich gezogen habe, nachdem ich die oben genannten Probleme gefunden und behoben habe:
- Sie sollten sich nicht auf die Annahme verlassen, dass Open Source-Bibliotheken (auch populäre) optimiert wurden oder dass sie keine offensichtlichen Probleme haben.
- Ein unschuldiges Problem kann zu schwerwiegenden Konsequenzen führen, zu Manifestationen des "Domino-Effekts", insbesondere unter schwerer Last.
- Wenn möglich, sollten Sie sync.Pool verwenden .
- Es ist hilfreich, die Tools zum Testen und Profilieren von Projekten unter Last bereitzuhalten.
- Go Toolkit und Open Source - Großartig!
Sehr geehrte Leser! Wie recherchieren Sie die Leistung Ihrer Go-Projekte?
