Słowem wstępu

OpenTelemetry to zbiór SDK i interfejsów API, który pozwala gromadzić, generować i eksportować logi, metryki i trace’y aplikacji.

OpenTelemetry umożliwia instrumentowanie rozproszonych usług. Instrumentacją nazywamy przechwytywanie danych telemetrycznych ze zdarzeń i operacji w systemie rozproszonym. Jest to niezbędne do tego, aby zrozumieć i zbadać zachowanie systemu, znajdować błędy czy debugować problemy związane z wydajnością.

Dla lepszego zrozumienia OpenTelemetry warto wyjaśnić znaczenie następujących pojęć:

Span - reprezentuje akcję/operację, która miała miejsce w systemie. Może to być żądanie HTTP lub operacja bazy danych, która rozciąga się w czasie. Span zazwyczaj jest rodzicem/dzieckiem innego spana.

Trace - reprezentuje drzewo spanów połączonych w relacji dziecko/rodzic. Opisuje postęp żądań w różnych usługach i komponentach w systemie (baza danych, źródła danych, kolejki itp.).

Koncepcję spanów i trace’ów można przedstawić za pomocą diagramu:

Dlaczego warto stosować OpenTelemetry?

Wśród zalet stosowania OpenTelemetry można wyróżnić:

• przechowywanie danych telemetrycznych w jednym miejscu,
• wykorzystanie automatycznej instrumentacji,
• łatwa integracja z eksporterem.

Dane telemetryczne w jednym miejscu

OpenTelemetry służy jako pojedyncza biblioteka gromadząca dane w ramach jednej specyfikacji. Mamy więc możliwość zebrania w jednym miejscu:

• logów,
• metryk,
• trace’ów

wykorzystując do tego jedno narzędzie.

Automatyczna instrumentacja

Integracja OpenTelemetry z naszą aplikacją w ramach automatycznej instrumentacji jest bardzo prosta. W przypadku aplikacji w Javie wystarczy dołączyć do niej agenta JAR. W ten sposób będzie wstrzykiwany kod bajtowy w celu przechwytywania danych telemetrycznych.

Przykładowa konfiguracja:

java -javaagent:ścieżka/do/opentelemetry-javaagent.jar -jar moja_aplikacja.jar

Dla większości przypadków taka instrumentacja out-of-the-box jest całkowicie wystarczająca i nie trzeba nic więcej robić. Czasami jednak jest potrzeba tworzenia ręcznie dedykowanych spanów w kodzie, w tym celu OpenTelemetry dostarcza mechanizm manualnej instrumentacji.

Przykładowy kod:

import io.opentelemetry.api;
 
//...
 
Tracer tracer =
    openTelemetry.getTracer("instrumentation-library-name", "instrumentation-library-version");
 
Span span = tracer.spanBuilder("custom_span").startSpan();
 
try (Scope ss = span.makeCurrent()) {
  // miejsce na modyfikację spana
} finally {
    span.end();
}

Eksporter

Po utworzeniu spana musimy gdzieś go dostarczyć, OpenTelemetry pozwala np. na zapisanie go w pamięci, wysyłkę do danych wyjściowych konsoli lub narzędzia takiego jak Jaeger czy Zipkin.

Przykład obrazujący uruchomienie OpenTelemetry spiętego z Jaegerem:

OTEL_SERVICE_NAME=my-service OTEL_TRACES_EXPORTER=jaeger OTEL_EXPORTER_JAEGER_ENDPOINT=http://localhost:14250 java -javaagent:./opentelemetry-javaagent.jar -jar moja_aplikacja.jar

gdzie OTEL_EXPORTER_JAEGER_ENDPOINT to endpoint pod którym wystawiony został Jaeger

Zastosowanie OpenTelemetry w praktyce

Chcielibyśmy zaprezentować 2 przypadki, w których OpenTelemetry był w stanie pomóc nam znaleźć przyczynę nieefektywnego działania funkcjonalności naszego systemu.

Przypadek nr 1

Zauważyliśmy problem polegający na pewnym długo wykonującym się zapytaniu. Aby znaleźć przyczynę przeprowadziliśmy analizę w następujących krokach:

1. W narzędziach deweloperskich przeglądarki, w ruchu sieciowym znaleźliśmy problematyczne, długo wykonujące się zapytanie:

   Czas jego wykonania wyniósł ok. 20 sekund:

2. Dysponując informacją, które zapytanie stanowi problem mieliśmy dwa wyjścia:
   • dokonać dogłębnej analizy kodu, metoda po metodzie, w celu znalezienia problematycznego fragmentu kodu,
   • podpiąć na środowisku OpenTelemetry i Zipkina, w celu wyłapania przez nich problematycznego miejsca. To rozwiązanie zostało przez nas wybrane.
3. W Zipkinie bardzo szybko znaleźliśmy powyższe zapytanie:
4. Na wykresie widać od razu, że problematyczne okazały się dwa zapytania do bazy danych, każde z nich trwało po ok. 8 sek:
5. Analiza zapytania wykazała, że jest ono nieoptymalne. Po wykonaniu poprawki ponowiliśmy testy i uzyskaliśmy lepsze rezultaty:

Przypadek nr 2

Postanowiliśmy przeprowadzić testy wydajnościowe w naszej aplikacji. Przy dużej liczbie użytkowników zauważyliśmy, że niektóre przypadki wykonywały się bardzo długo albo wręcz kończyły niepowodzeniem. Przeprowadziliśmy analizę w następujących krokach:

1. Na początku podpięliśmy Zipkina, OpenTelemetry oraz VisualVM na środowisku, na którym planowaliśmy uruchomić testy wydajnościowe.

2. Uruchomiliśmy testy - w rezultacie widzieliśmy kilka przypadków, które nie zakończyły się poprawnie z powodu długich czasów zapytań. Poszukaliśmy ich w Zipkinie, w ten sposób byliśmy w stanie namierzyć taki request, trwający niespełna 45 sekund:

3. OpenTelemetry w ramach automatycznej instrumentacji wspiera bardzo wiele bibliotek, frameworków czy serwerów aplikacji (pełną listę znajdziemy tutaj). Niestety, w tym przypadku problem znajdował się na niższym poziomie a OpenTelemetry nie był w stanie wyłapać bezpośredniego źródła naszych problemów. Tutaj z pomocą przyszło nam narzędzie VisualVM. W Zipkinie widzieliśmy numer wątku, który przetworzył nasze zapytanie (tag thread.name w prawym dolnym rogu na zrzucie w punkcie 2), teraz pozostało znaleźć go w VisualVM

4. Analizując stacktrace’y wywołań wykonywanych na wątku o numerze 223 szybko wyłapaliśmy kilka problemów, m.in. problem spędzenia przez nasz wątek aż 54 sekund na zapisie linijki logu:

   Teraz wystarczyło potwierdzić, że długi czas wykonywania metody writeBytes() ma wpływ na nasz problem. Poszukaliśmy więc na wątku o numerze 223 stacktrace’a wykonywanego przez zapytanie wskazane przez Zipkina w punkcie 2 - /webforms-rest/formservice/getnextpage. Zagłębiając się w niego, znaleźliśmy w końcu podejrzewaną przez nas o problemy wydajnościowe metodę writeBytes(). VisualVM pokazał, że wykonywała się ona kilka sekund:

5. Ostatecznie wyciągnęliśmy następujące wnioski: Długi czas oczekiwania na odpowiedź systemu wynikał z zastosowania nieefektywnego systemu logowania. Każde ze zdarzeń ze wszystkich wątków było wysyłane na strumień standardowego wyjścia a następnie było przekierowane do pliku. W momencie wysłania na standardowe wyjście zakładany był lock tak, aby inny wątek nie wykonał tego w tym samym czasie. Przy tak dużej ilości wątków oraz zdarzeń oczekiwanie na swoją kolej wynosiło ok. 3-4 sekundy co przy kilku-kilkunastu zdarzeniach logowania podczas jednej operacji systemu znacznie obniżyło prędkość jego działania.

Podsumowanie

OpenTelemetry to narzędzie dające wiele możliwości w monitorowaniu, analizie i zarządzaniu dystrybuowanymi systemami, dzięki czemu przydaje się w środowiskach chmurowych, mikrousługach i innych zaawansowanych architekturach systemowych.