Observability in gedistribueerde systemen

Vinden van de speld in een hooiberg

Het achterhalen van problemen in een monoliet kan al lastig zijn, laat staan in een gedistribueerd landschap met allerlei microservices. Hoe vind je nu waar een probleem is ontstaan en waarom dit gebeurt? Hoe vind je uit waar de vertraging zit? Een mogelijk hulpmiddel hiervoor is het gebruik van Tracing. Wat is tracing en hoe kan het je helpen om problemen op te sporen? Wat moet je er voor doen om dit in te regelen? In dit artikel gaan we daar op in.

Auteur: Mark van der Walle

Als er iets misgaat in productie dan kunnen we vaak niet eenvoudig achterhalen wat nu de oorzaak is van een probleem. Meestal duiken we dan in de logs die we hopelijk op een centrale doorzoekbare plaats hebben staan. We proberen dan vaak aan de hand van timestamps logregels aan elkaar te knopen. Maar wat als er nou zoveel logregels zijn dat dit niet meer te doen is? Iets wat we kunnen doen is bij elk http request een id genereren en deze bij elke logregel meegeven.

Dat is nuttig, maar geeft ons niet altijd de juiste informatie. We hebben meer nodig. Dus gaan we onze logs uitbreiden met meer en meer informatie. Hierdoor wordt het echter alleen maar meer zoeken naar een speld in een hooiberg. Daarnaast is het veel handmatig werk.

Tracing

Tracing geeft de mogelijkheid om naast het genereren van een id nog meer zaken voor je te regelen. Maar wat is tracing nu precies? Een trace is een verzameling van spans. Een span is eigenlijk niet heel veel anders dan het begin en het eind van een operatie. Een http verzoek afhandelen bijvoorbeeld. Of een een database aanroep. Wat deze spans nu een trace maakt is dat ze elkaar opvolgen.

Als er bijvoorbeeld een http-verzoek binnenkomt starten we een span. Deze span eindigt vlak voordat we het antwoord terugsturen. Een span heeft zowel een id als een parent id. Dit geeft ons al wat interessante informatie zoals de tijd die het verzoek duurde. Verder kunnen we op elk moment in onze applicatie een child span maken. Deze nieuwe span heeft als parent onze eerste span en heeft ook een begin en een eind en zijn eigen id om te loggen. Bij de initiële span of root span is het parent id gelijk aan het span id. Doordat we zowel het parent id als de span id van de huidige span loggen kunnen we alle operaties aan elkaar koppelen en ook losse onderdelen van de aanroep.

Op deze manier ontstaat een boomstructuur waarbij elke span mogelijk meerdere kinderen heeft. Hiermee kun je gericht zoeken op verschillende onderdelen van je applicatie. Dat geeft ons al meer houvast, maar het wordt nog beter.

OpenTracing en terminologie

Een bekend raamwerk voor het regelen van tracing in een applicatie is OpenTracing [1]. OpenTracing kent een aantal concepten waar we eerst even naar gaan kijken voor we verder gaan. Hieronder nemen we een aantal van deze concepten door.

Trace

Een trace is een verzameling van spans die bij elkaar horen. Een trace heeft één of meerdere spans.

Span

Een span omvat de staat van een operatie. Een span heeft in ieder geval een operatie naam, een start timestamp en een eind timestamp. Verder heeft een span een SpanContext. Naast de verplichte velden zijn er nog een aantal optionele velden die spans erg nuttig maken.

Logs

Een span kan ook nog eigen log entries hebben. Dit zijn niet logs zoals je deze in log file zou zetten, maar key value pairs met een bijbehorende timestamp. Dit zijn events die je nog aan de span wil koppelen.

SpanContext

Een span heeft ook een span context. Deze context geeft aan wat de relatie is van de span tot andere spans. De span context bevat ook het span id, maar ook een eventuele relatie met zijn parent en welke relatie dat is. OpenTracing kent op dit moment de ChildOf en FollowsFrom relatie. ChildOf is redelijk duidelijk. FollowsFrom is een wat meer losse relatie. Deze komt later nog terug als we het gaan hebben over propagatie.

Bagage

Waarbij tags specifiek voor een span zijn, kan het nuttig zijn om informatie over de hele of een deel van de trace te hebben. Denk hierbij aan de naam van het business process dat de keten triggerde. Of de gebruiker die het verzoek initieerde.

Meer dan 1000 woorden

Op dit moment hebben we een hoop informatie kunnen opslaan in spans, tags, logs en meer. We moeten hier natuurlijk ook iets mee gaan doen. Het is belangrijk om deze informatie ergens centraal op te slaan. Een goede tool die hiervoor gebruikt kan worden is Zipkin [3]. Zipkin zorgt zowel voor het ontvangen van tracing data via http of kafka als het opslaan en het visualiseren van een trace. In afbeelding 1 is een voorbeeld te zien van een trace over meerdere applicaties. Onze trace heeft zes zichtbare spans met verschillende tags. In dit nogal versimpelde voorbeeld kunnen we al heel snel zien wat het gevolg is van een aanroep naar een applicatie.

Afbeelding1 – Simpele trace met meerdere spans.

De trace in de afbeelding heeft eigenlijk 8 spans. Dit komt doordat spans in het overzicht samengevoegd kunnen worden. De in het overzicht samengevoegde spans ontstaan door een aanroep vanuit de ene applicatie naar de andere. De zogenaamde client span wordt samengevoegd met de server span. Dit omdat ze dezelfde operatie omvatten. Doordat de aanroep wel als twee losse spans wordt opgeslagen is het ook mogelijk de netwerk latency te zien door het verschil in starttijd van de beide spans te bekijken. Deze informatie is in de Zipkin interface te zien door op een span te klikken.

Naast individuele traces is het mogelijk om service maps te laten zien. Hierdoor is het mogelijk om de afhankelijkheden van services in kaart te brengen en een hoog over beeld van de staat van het landschap te genereren. Een simpel voorbeeld is te zien in afbeelding 2.

Afbeelding 2 – Simpele service map met drie services.

Propagatie

Tracing wordt pas echt interessant als het wordt gedistribueerd. In de afbeeldingen hebben we al laten zien dat dat mogelijk is. Het realiseren van distributie is eigenlijk vrij eenvoudig. Bij elke integratie moet er een beetje informatie worden meegeven. Gelukkig ondersteunen de meeste integraties het concept van headers. De standaard headers die hiervoor gebruikt worden zijn:

x-b3-traceid – Het id van de root span
x-b3-spanid – Het id van de actieve span
x-b3-parentspanid – Het id van de parent van de actieve span
x-b3-sampled – De sample state van gehele trace

Deze headers zijn door te geven op zowel http verzoeken als message headers in JMS.

Wat het grote voordeel is van propagatie is door middel van standaarden is dat je hiermee heel goed kan integreren met allerlei andere tools en programmeertalen zoals Python, Ruby en Golang.

Als laatste is er nog propagatie binnen een applicatie over threads heen. Daar gaan we in dit artikel niet verder op in.

Sampling

Op het moment dat er heel veel verkeer is kan een tracing implementatie gaan samplen. Dit houd in dat niet alle informatie naar Zipkin of een andere opslag wordt gestuurd. Deze sample rate is vaak te configureren. Om te zorgen dat je geen halve traces krijgt wordt ook de sample state in de propagatie doorgeven. Dit wordt gedaan door de eerder al genoemde header x-b3-sampled.

Instrumentatie

Het zorgen voor het inrichten van een tracer, het starten en stoppen van spans, het propageren van de trace en zorgen dat traces blijven werken over thread boundaries is een hoop code. Gelukkig hoeven we dat in de meeste situaties niet zelf te regelen. Binnen Spring is er Spring Cloud Sleuth [4].

Spring Cloud Sleuth zorgt voor het automatisch opzetten van de tracer, het starten van spans voor binnenkomende en uitgaande http verzoeken en messages via bijvoorbeeld JMS. Daarnaast worden database aanroepen geïnstrumenteerd zodat je ook de performance van de sql queries kan zien.

Automatisch propageren van de trace en span context over threads heen wordt in veel gevallen al automatisch gedaan of is eenvoudig in te regelen. In de gevallen waar je wel echt je eigen Runnables of Callables maakt kun je die wrappen om zo propagatie te blijven houden.

Instrumentatie voor andere frameworks is afhankelijk van het framework. Voor allerlei andere tools en software zijn er libraries of modules. Bijvoorbeeld als je gebruik maakt van Nginx [5] als API gateway dan kun je met de OpenTracing module al op een vroeg moment de trace starten.

Ook andere programmeertalen dan Java hebben verschillende libraries voor het instrumenteren van je applicatie. Denk hierbij aan bijvoorbeeld Python en Golang, maar ook NodeJS en Ruby. Hierdoor is het mogelijk om in een landschap met een verscheidenheid aan tools en programmeertalen over het hele landschap heen problemen op te lossen.

Op de opentracing [1] website is een overzicht te vinden van implementaties en modules in het opentracing ecosysteem.

Samenvatting

Met het gebruik van opentracing is op een vrij eenvoudige manier enorm veel informatie te verzamelen over het gedrag van een gedistribueerd landschap. Door goed gebruik van tags en het propageren van informatie naar allerlei systemen en de mogelijkheid tot correleren met log files is het analyseren zonder in te grijpen op een applicatie erg eenvoudig geworden.

Doordat OpenTracing is geïmplementeerd in allerlei talen en tools is uitrollen in een heterogeen landschap goed mogelijk.

Referenties

[1] OpenTracing https://opentracing.io/

[2] OpenTracing conventies https://github.com/opentracing/specification/blob/master/semantic_conventions.md

[3] Zipkin https://zipkin.io/

[4] Spring Cloud Sleuth https://spring.io/projects/spring-cloud-sleuth

[5] Nginx OpenTracing https://github.com/opentracing-contrib/nginx-opentracing

Bio

Mark van der Walle is Software Architect bij Sogeti. Hij houdt zich veel bezig met cloud

native development, cloud transities en CI/CD. Daarnaast geeft hij leiding aan het Java Core team van Sogeti.

NLJUG – Nederlandse Java User Group NLJUG – de Nederlandse Java User Group – is opgericht in 2003. De NLJUG verenigt software ontwikkelaars, architecten, ICT managers, studenten, new media developers en haar businesspartners met algemene interesse in alle aspecten van Java Technology.