W naszych projektach stosujemy architekturę mikroserwisową. W przypadku wystąpienia wąskich gardeł w wydajności spędzamy dużo czasu na monitorowaniu i analizie logów. Gdy rejestrujemy czasy poszczególnych operacji w pliku logów, zazwyczaj trudno jest zrozumieć, co spowodowało wywołanie tych operacji, śledzić sekwencję działań lub przesunięcie czasowe jednej operacji w stosunku do drugiej w różnych serwisach.
Aby zminimalizować ręczną pracę, postanowiliśmy skorzystać z jednego z narzędzi do śledzenia. W tym artykule opowiemy, jak i do czego wykorzystać śledzenie oraz jak to zrobiliśmy.
Jakie problemy można rozwiązać za pomocą śledzenia.
- Zidentyfikować wąskie gardła w wydajności zarówno w obrębie jednego serwisu, jak i w całym drzewie wykonania między wszystkimi zaangażowanymi serwisami. Na przykład:
- Wiele krótkich, kolejnych wywołań między serwisami, takich jak geokodowanie lub zapytania do bazy danych.
- Długie oczekiwania na wejście/wyjście, na przykład przesyłanie danych przez sieć czy odczyt z dysku.
- Długie parsowanie danych.
- Długie operacje wymagające CPU.
- Fragmenty kodu, które nie są potrzebne do uzyskania końcowego wyniku i można je usunąć lub uruchomić z opóźnieniem.
- Wizualnie zrozumieć, w jakiej kolejności co jest wywoływane i co się dzieje, gdy wykonywana jest operacja.
Widać, że na przykład zapytanie trafiło do serwisu WS -> serwis WS uzupełnił dane przez serwis R -> następnie wysłał zapytanie do serwisu V -> serwis V załadował dużo danych z serwisu R -> poszedł do serwisu P -> serwis P jeszcze raz zapytał serwis R -> serwis V zignorował wynik i przeszedł do serwisu J -> i dopiero potem zwrócił odpowiedź do serwisu WS, w międzyczasie kontynuując obliczenia w tle.
Bez takiego śladu lub szczegółowej dokumentacji całego procesu bardzo trudno jest zrozumieć, co się dzieje, widząc kod po raz pierwszy, a kod jest rozproszony po różnych serwisach i ukryty za wieloma binami i interfejsami. - Zbieranie informacji o drzewie wykonania do późniejszej analizy. Na każdym etapie wykonania można do śladu dodać informacje, które są dostępne na danym etapie, a następnie zrozumieć, jakie dane wejściowe doprowadziły do takiego scenariusza. Na przykład:
- ID użytkownika
- Uprawnienia
- Typ wybranej metody
- Log lub błąd wykonania
- Przekształcenie trace'ów w podzbiór metryk, a następnie analiza w postaci metryk.
Co potrafi logować śledzenie. Span
W śledzeniu istnieje pojęcie spanu, które jest odpowiednikiem jednego logu w konsoli. Span ma:
- Nazwa, zazwyczaj to nazwa metody, która była wykonywana
- Nazwa usługi, w której został wygenerowany span
- Własny unikalny ID
- Jakąś metainformację w postaci key/value, którą zalogowano. Na przykład, parametry metody lub informacja, czy metoda zakończyła się błędem, czy nie
- Czas rozpoczęcia i zakończenia wykonania tego spanu
- ID parent span
Każdy span jest wysyłany do kolektora spanów, aby został zapisany w bazie w celu późniejszego przeglądania, gdy tylko zakończy swoje wykonanie. Można później zbudować drzewo wszystkich spanów, łącząc je po ID rodzica. Podczas analizy można znaleźć na przykład wszystkie spany w danej usłudze, które zajmowały więcej niż określony czas. Następnie, przechodząc do konkretnego spanu, można zobaczyć całe drzewo powyżej i poniżej tego spanu.
Opentrace, Jaeger i jak zrealizowaliśmy to w naszych projektach
Istnieje ogólny standard , który opisuje, jak i co powinno być zbierane, nie wiążąc śledzenia z konkretną implementacją w jakimkolwiek języku. Na przykład w Javie cała praca z trace'ami jest realizowana za pośrednictwem wspólnego API Opentrace, a pod nim może się kryć na przykład Jaeger lub pusta domyślna implementacja, która nic nie robi.
U nas używa się jako implementacji Opentrace. Składa się z kilku komponentów:
- Jaeger-agent — lokalny agent, który zazwyczaj znajduje się na każdej maszynie i do którego logują usługi na lokalny domyślny port. Jeśli agenta brakuje, to trace'y wszystkich usług na tej maszynie są zazwyczaj wyłączone
- Jaeger-collector — do niego wszyscy agenci wysyłają zebrane trace'y, a on zapisuje je w wybranej bazie danych
- Baza danych — preferowaną bazą danych jest Cassandra, ale u nas używa się Elasticsearch, istnieją implementacje także dla kilku innych baz danych oraz realizacja w pamięci, która nic nie zapisuje na dysku
- Jaeger-query — to usługa, która przeszukuje bazę danych i zwraca już zebrane trace'y do analizy
- Jaeger-ui — to interfejs webowy do wyszukiwania i przeglądania trace'ów, który łączy się z jaeger-query
Odseparowanym komponentem można nazwać implementację Opentrace Jaeger pod konkretne języki, przez którą spany są wysyłane do jaeger-agent.
Polega na zaimplementowaniu interfejsu io.opentracing.Tracer, po czym wszystkie ślady będą przesyłane przez niego do rzeczywistego agenta.
Można również podłączyć do komponentów Springa oraz implementację od Jaeger która automatycznie skonfiguruje śledzenie wszystkiego, co przechodzi przez te komponenty, na przykład zapytania http w kontrolerach, zapytania do bazy danych przez jdbc itd.
Logowanie śladów w Javie
Na najwyższym poziomie powinien być utworzony pierwszy Span, co może być zrobione automatycznie, na przykład przez kontroler Springa w momencie otrzymania żądania, lub ręcznie, jeśli takiego nie ma. Następnie jest on przekazywany przez Scope niżej. Jeśli jakiś metod niżej chce dodać Span, pobiera aktualny activeSpan z Scope, tworzy nowy Span i informuje, że jego rodzicem jest otrzymany activeSpan, oraz ustawia nowy Span jako aktywny. Przy wywołaniach zewnętrznych serwisów przekazywany jest im aktualny aktywny span, a te serwisy tworzą nowe spany związane z tym spanem.
Cała praca przebiega przez instancję Tracera, której można uzyskać przez mechanizm DI lub GlobalTracer.get() jako zmienną globalną, jeśli mechanizm DI nie działa. Domyślnie, jeśli tracer nie został zainicjalizowany, zostanie zwrócony NoopTracer, który nic nie robi.
Następnie z tracera przez ScopeManager pobierany jest aktualny scope, tworzony jest nowy scope z aktualnym powiązanym nowym spanem, a później zamykany jest utworzony scope, który zamyka utworzony span i przywraca poprzedni scope do aktywnego stanu. Scope jest powiązane z wątkiem, dlatego w programowaniu wielowątkowym należy pamiętać o przekazywaniu aktywnego spanu do innego wątku, aby następnie aktywować scope w inny wątku z powiązaniem z tym spanem.
io.opentracing.Tracer tracer = ...; // GlobalTracer.get()
void DoSmth () {
try (Scope scope = tracer.buildSpan("DoSmth").startActive(true)) {
...
}
}
void DoOther () {
Span span = tracer.buildSpan("someWork").start();
try (Scope scope = tracer.scopeManager().activate(span, false)) {
// Wykonaj rzeczy.
} catch(Exception ex) {
Tags.ERROR.set(span, true);
span.log(Map.of(Fields.EVENT, "error", Fields.ERROR_OBJECT, ex, Fields.MESSAGE, ex.getMessage()));
} finally {
span.finish();
}
}
void DoAsync () {
try (Scope scope = tracer.buildSpan("ServiceHandlerSpan").startActive(false)) {
...
final Span span = scope.span();
doAsyncWork(() -> {
// KROK 2 POWYŻEJ: reaktywuj Span w wywołaniu zwrotnym, przekazując true do
// startActive(), jeśli/kiedy Span ma zostać zakończony.
try (Scope scope = tracer.scopeManager().activate(span, false)) {
...
}
});
}
}Dla programowania wielowątkowego istnieje również TracedExecutorService i podobne opakowania, które automatycznie przekazują bieżący span do wątku przy uruchamianiu asynchronicznych zadań:
private ExecutorService executor = new TracedExecutorService(
Executors.newFixedThreadPool(10), GlobalTracer.get()
);Do zewnętrznych zapytań HTTP dostępny jest
HttpClient httpClient = new TracingHttpClientBuilder().build();Problemy, z którymi się spotkaliśmy
- Biny i DI nie zawsze działają, jeśli tracer nie jest używany w serwisie lub komponencie, wtedy Tracer może nie działać i trzeba będzie użyć GlobalTracer.get().
- Adnotacje nie działają, jeśli nie jest to komponent lub serwis, lub jeśli wywołanie metody odbywa się z sąsiedniej metody tej samej klasy. Należy być ostrożnym, sprawdzić, co działa i korzystać z ręcznego tworzenia trace'a, jeśli @Traced nie działa. Można również dodać dodatkowy kompilator dla adnotacji java, wtedy powinny działać wszędzie.
- W starszym springu i spring boot nie działa automatyczna konfiguracja opentracing spring cloud z powodu błędów w DI, więc jeśli chcemy, aby trace'y w komponentach springa działały automatycznie, możemy to zrobić na podobieństwo
- W groovy nie działa try with resources, trzeba koniecznie użyć try finally.
- Każdy serwis powinien mieć swoją spring.application.name, pod którą będą logowane trace'y. Należy również wprowadzić osobną nazwę dla środowiska produkcyjnego i testowego, aby się nie mieszały.
- Jeśli używasz GlobalTracer i tomcata, to wszystkie serwisy uruchomione w tym tomcat mają jeden GlobalTracer, więc wszystkie będą miały tę samą nazwę serwisu.
- Dodając trace'y do metody, należy upewnić się, że nie jest ona wywoływana w pętli wiele razy. Należy dodać jeden wspólny trace do wszystkich wywołań, który zaloguje łączne czasy wykonania. W przeciwnym razie będzie generowana zbędna obciążenie.
- Raz w jaeger-ui zrobiliśmy zbyt duże zapytania o dużą liczbę trace'ów i ponieważ nie czekaliśmy na odpowiedź, wykonaliśmy je ponownie. W rezultacie jaeger-query zaczął zużywać dużo pamięci i spowalniał elastika. Pomógł restart jaeger-query.
Próbkowanie, przechowywanie i przeglądanie trace'ów
Są trzy typy :
- Const, który wysyła i zapisuje wszystkie trace'y.
- Probabilistic, który filtruje trace'y z określoną prawdopodobieństwem.
- Ratelimiting, który ogranicza liczbę śladów na sekundę. Można skonfigurować te parametry na kliencie, albo na jaeger-agent, albo w kolektorze. Obecnie w naszym stosie walidatorów używamy const 1, ponieważ nie ma zbyt wielu zapytań, ale zajmują one dużo czasu. W przyszłości, jeśli to będzie wywierać zbyt dużą presję na system, można to ograniczyć.
Jeśli używasz Cassandry, domyślnie przechowuje ona ślady tylko przez dwa dni. U nas używana jest i ślady są przechowywane przez cały czas i nie są usuwane. Tworzony jest osobny indeks na każdy dzień, na przykład jaeger-service-2019-03-04. W przyszłości należy skonfigurować automatyczne czyszczenie starych śladów.
Aby zobaczyć ślady, należy:
- Wybrać usługę, według której chcesz filtrować ślady, na przykład tomcat7-default dla usługi, która działa w Tomcat i nie może mieć swojej nazwy.
- Następnie wybierz operację, okres czasu i minimalny czas trwania operacji, na przykład od 10 sekund, aby wziąć tylko długie wykonania.
- Przejdź do jednego ze śladów i zobacz, co tam opóźniało.
Jeśli znany jest jakiś id zapytania, można znaleźć ślad po tym id za pomocą wyszukiwania po tagach, jeśli ten id jest logowany w śladzie.
Dokumentacja
- Dokumentacja opentracing
- Dokumentacja jaeger
- Podłączenie jaeger java
- Podłączenie spring opentracing
Artykuły
- Jaeger Opentracing i Mikrousługi w rzeczywistym projekcie na PHP i Golang
- Evolving Distributed Tracing at Uber Engineering
- Uruchamianie Jaeger Agent na gołej maszynie
Wideo
- Jak użyliśmy Jaeger i Prometheus do błyskawicznych zapytań użytkowników — Bryan Boreham
- Wprowadzenie: Jaeger — Yuri Shkuro, Uber & Pavol Loffay, Red Hat
- Serghei Iakovlev, "Mała historia wielkiego zwycięstwa: OpenTracing, AWS i Jaeger"
Źródło: habr.com
