10 jaar geleden werd Google geconfronteerd met een kritisch knelpunt veroorzaakt door extreem lange C++ compilatietijden en had een totaal nieuwe manier nodig om dit op te lossen. De ingenieurs van Google pakten de uitdaging aan door een nieuwe taal te creëren met de naam Go (aka Golang). De nieuwe taal Go leent de beste delen van C++, (met name de prestatie- en beveiligingsfuncties) en combineert deze met de snelheid van Python, zodat Go snel meerdere cores kan gebruiken en tegelijkertijd in staat is om concurrency te implementeren.

Hier, bij Coralogix, ontleden we de logs van onze klanten om ze real-time inzichten, waarschuwingen en meta-data over hun logs te geven. Om dat te kunnen doen, moet de parsing fase, die zeer complex is en geladen met tonnen regels voor elke log line service, extreem snel zijn. Dat is een van de redenen waarom we besloten hebben om Go lang te gebruiken.

De nieuwe service draait nu full-time in productie en terwijl we geweldige resultaten zien, moet het draaien op high-performance machines. Meer dan tientallen miljarden logs worden dagelijks geanalyseerd door deze Go-service die draait op een AWS m4.2xlarge instance met 8 CPU’s en 36 GB geheugen.

In dit stadium hadden we er een punt achter kunnen zetten met het gevoel dat alles goed liep, maar dat is niet hoe we het hier bij Coralogix doen. We wilden meer mogelijkheden (performance, etc) met minder (AWS instances). Om te verbeteren, moesten we eerst de aard van onze knelpunten begrijpen en hoe we ze kunnen verminderen of volledig elimineren.

We besloten om wat Golang-profilering op onze service uit te voeren en te controleren wat precies het hoge CPU-verbruik veroorzaakte om te zien of we kunnen optimaliseren.

Voreerst hebben we een upgrade naar de nieuwste stabiele Go-versie uitgevoerd (een belangrijk onderdeel van de software-levenscyclus). We waren op Go versie v1.12.4, en de nieuwste was 1.13.8. De 1.13 release had, volgens de documentatie, belangrijke verbeteringen in de runtime library en een paar andere componenten die voornamelijk het geheugengebruik gebruikten. Kortom, het werken met de laatste stabiele versie was nuttig en bespaarde ons heel wat werk →

Hierdoor verbeterde het geheugengebruik van ongeveer ~800MB naar ~180MB.

Ten tweede, om een beter inzicht in ons proces te krijgen en te begrijpen waar we tijd en middelen aan besteden, zijn we begonnen met profileren.

Profileren van verschillende diensten en programmeertalen lijkt misschien complex en intimiderend, maar het is eigenlijk vrij eenvoudig in Go en kan worden beschreven in een paar commando’s. Go heeft een speciale tool genaamd ‘pprof’ die moet worden ingeschakeld in uw app door te luisteren naar een route (standaard poort- 6060) en gebruik het Go-pakket voor het beheer van http-verbindingen:

import _ "net/http/pprof"

Initialiseer vervolgens het volgende in uw hoofdfunctie of onder uw route-pakket:

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

Nu kunt u uw service starten en verbinding maken met

http://localhost:6060/debug/pprof

Volledige documentatie van Go kan hier worden gevonden.

De standaard profilering voor pprof zal een 30 seconden sampling van CPU-gebruik zijn. Er zijn een paar verschillende paden die sampling mogelijk maken voor CPU gebruik, heap gebruik en meer.

We richtten ons op ons CPU-gebruik, dus we namen een 30 sec profiling in productie en ontdekten wat je ziet in de afbeelding hieronder (herinnering: dit is na het upgraden van onze Go-versie en het verkleinen van de interne onderdelen van Go tot het minimum):

Go profiling – Coralogix

Zoals u kunt zien, vonden we veel runtime package activiteit, die specifiek wees op GC activiteit → Bijna 29% van onze CPU (alleen al de top 20 meest verbruikte objecten) wordt gebruikt door GC. Aangezien Go GC vrij snel is en behoorlijk geoptimaliseerd, is de beste praktijk om het niet te veranderen of aan te passen en aangezien ons geheugengebruik erg laag was (vergeleken met onze vorige Go versie) was de belangrijkste verdachte een hoge object allocatie rate.

Als dat het geval is, zijn er twee dingen die we kunnen doen:

  • Tune Go GC activiteit om zich aan te passen aan ons service gedrag, wat betekent – vertraag de trigger om de GC minder vaak te activeren. Dit zal ons dwingen om te compenseren met meer geheugen.
  • Vind de functie, het gebied of de regel in onze code die te veel objecten toewijst.

Kijkend naar ons instance type, was het duidelijk dat we veel geheugen over hadden en we zijn momenteel gebonden aan de CPU van de machine. Dus hebben we die verhouding gewoon omgedraaid. Golang, sinds zijn begindagen, heeft een vlag waar de meeste ontwikkelaars zich niet bewust van zijn, genaamd GOGC. Deze vlag, met een standaardwaarde van 100, vertelt het systeem eenvoudig wanneer het GC proces te starten. De standaardwaarde zal het GC proces starten wanneer de heap 100% van zijn initiële grootte bereikt. Het veranderen van die waarde naar een hoger getal zal de GC trigger vertragen en het verlagen ervan zal GC sneller triggeren. We begonnen een paar verschillende waarden te benchmarken en de beste prestatie voor ons doel werd bereikt bij gebruik van: GOGC=2000.

Dit verhoogde onmiddellijk ons geheugengebruik van ~200MB naar ~2.7GB (Dat is nadat het geheugengebruik verminderde door onze Go versie update) en verminderde ons CPU gebruik met ~10%.
De volgende schermafbeelding toont de benchmark resultaten:

GOGC =2000 resultaten – Coralogix benchmark

De top 4 van functies die CPU verbruiken zijn de functies van onze service, wat logisch is. Het totale GC-gebruik is nu ~13%, minder dan de helft van het vorige verbruik(!)

We hadden het hierbij kunnen laten, maar besloten om te ontdekken waar en waarom we zoveel objecten toewijzen. Vaak is daar een goede reden voor (bijvoorbeeld in het geval van stream-verwerking, waar we veel nieuwe objecten maken voor elk bericht dat we krijgen en die we kwijt moeten raken omdat ze niet relevant zijn voor het volgende bericht), maar er zijn gevallen waarin er een eenvoudige manier is om het maken van objecten te optimaliseren en drastisch te verminderen.

Om te beginnen, laten we hetzelfde commando uitvoeren als voorheen met een kleine wijziging om de heap dump te nemen:

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

Om het resultaat bestand te doorzoeken kun je het volgende commando uitvoeren in je code map om de dump te analyseren:

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

onze momentopname zag er als volgt uit:

Alles leek redelijk, behalve de derde rij, die een bewakingsfunctie is die aan het einde van elke Coralogix-regelparsingfase aan onze prometheus-exporteur rapporteert. Om dieper te gaan, voerden we het volgende commando uit:

list <FunctionName>

Bijvoorbeeld:

list reportRuleExecution

En toen kregen we het volgende:

Reageren

Het e-mailadres wordt niet gepubliceerd.