Analiza zrzutów stosu i heap dumpów: praktyczny warsztat Java developera

0
81
Rate this post

Dlaczego zrzuty stosu i heap dumpy są tak cenne dla Java developera

Twarda diagnostyka zamiast zgadywania

Przy problemach wydajnościowych i błędach w aplikacjach Java łatwo wpaść w pułapkę „domysłów”: może baza wolna, może GC, może sieć. Thread dump i heap dump odcinają spekulacje. Pokazują dokładny stan JVM w konkretnym momencie: które wątki co robią, jakie obiekty zajmują pamięć, na jakich blokadach proces się zatrzymał.

Zamiast gdybać, dlaczego usługa REST nagle odpowiada po 30 sekundach, można zobaczyć, że wszystkie wątki serwera aplikacyjnego utknęły na tym samym wywołaniu HTTP do zewnętrznego systemu, albo blokują się na jednym globalnym zamku. Albo że sterta jest wypełniona milionami instancji tej samej klasy DTO, które nigdy nie są zwalniane.

Analiza zrzutów stosu i heap dumpów to podejście w stylu „dowody zamiast teorii”. Daje to dwie rzeczy naraz: szybszą diagnozę oraz spokojną głowę podczas rozmów z innymi zespołami („na zrzucie widać, że wszystkie wątki czekają na odpowiedź z API płatności” brzmi dużo lepiej niż „wydaje się, że problem jest u was”).

Typowe kryzysy produkcyjne, w których zrzuty ratują dzień

Najczęstsze sytuacje, gdy analiza thread dumpów i heap dumpów jest kluczowa:

  • Aplikacja „zamiera”, CPU nisko – użytkownicy widzą time-outy, ale serwer nie „mieli” na 100% CPU. Klasyczny przypadek wątków uwięzionych w WAITING, TIMED_WAITING lub BLOCKED. Thread dump ujawnia, na czym blokują się wątki.
  • Pamięć ucieka, rośnie GC – krzywa pamięci w monitoringu pnie się w górę, GC pracuje coraz częściej, aż w końcu pojawia się OutOfMemoryError. Heap dump pozwala znaleźć wycieki pamięci JVM: obiekty, które „nigdy nie umierają”, i ścieżki referencji trzymające je przy życiu.
  • Nietypowe skoki opóźnień – aplikacja generalnie działa, ale co jakiś czas następuje kilka minut dramatycznie dłuższych odpowiedzi. Seria thread dumpów oraz korelacja z GC logami pokazują, czy to GC stop-the-world, zator na jednym monitorze, czy np. długa operacja I/O.
  • Nagłe restarty JVM – brak pełnych logów, ale jest core dump lub zrzut heapu. Analiza pozwala zrekonstruować, co działo się tuż przed awarią.

W praktyce często łączy się te przypadki. Aplikacja może jednocześnie mieć wyciek pamięci i problemy z blokadami – jeden problem maskuje drugi. Zrzuty dostarczają kompletny obraz, który można systematycznie „rozplątywać”.

Most między kodem a pamięcią procesu JVM

Thread dump i heap dump są jak rentgen i tomografia dla procesu JVM. Z jednej strony masz wysokopoziomowy kod Javy: klasy, metody, frameworki. Z drugiej – niskopoziomową rzeczywistość procesu: stosy wątków, stertę, zarządzanie pamięcią.

Thread dump:

  • pokazuje stos każdego wątku – dokładną sekwencję wywołań metod, włącznie z ramkami natywnymi,
  • prezentuje stan wątku (RUNNABLE, WAITING itd.),
  • ujawnia monitor locks, semafory, miejsca parkowania (LockSupport.park).

Heap dump:

  • reprezentuje cały graf obiektów na stercie w konkretnym momencie,
  • umożliwia analizę histogramu obiektów – ile jest instancji poszczególnych klas i ile pamięci zajmują,
  • pozwala śledzić ścieżki referencji do „wyciekających” obiektów.

Dzięki temu można przejść od objawu („pamięć rośnie”) do bardzo konkretnej diagnozy („instancje com.example.SessionCache są przetrzymywane w statycznej mapie, która nigdy nie czyści wygasłych wpisów”).

Pytania, na które zrzuty odpowiadają – i te, na które nie

Thread dump i heap dump świetnie nadają się do rozstrzygania pytań typu:

  • Co teraz robią wątki? Na czym realnie czekają?
  • Czy występuje deadlock na poziomie Javy (monitory, ReentrantLock)?
  • Które fragmenty kodu są wykonywane przez najwięcej wątków?
  • Jakie typy obiektów dominują na stercie?
  • Co trzyma w pamięci obiekty, które „powinny” zostać zutylizowane przez garbage collector?

Są jednak rzeczy, których zrzuty nie powiedzą bezpośrednio:

  • Dlaczego użytkownik kliknął coś pięć razy pod rząd – zrzut pokaże tylko stan JVM, nie zachowanie użytkownika.
  • Jak długo dana operacja trwa w ujęciu historycznym – to domena metryk i logów, zrzut to migawka.
  • Pełne dane o natywnej pamięci (native heap) – heap dump koncentruje się na stercie JVM, nie na całości pamięci procesu.

Dlatego analiza zrzutów jest najskuteczniejsza, gdy łączy się ją z logami aplikacji, metrykami (CPU, GC, latency) i obserwacją ruchu. Zrzut to bardzo szczegółowe zdjęcie, ale tylko jedno ujęcie; warto je wpiąć w szerszy film z życia aplikacji.

Kolorowy kod Java na ciemnym ekranie podczas analizy pamięci
Źródło: Pexels | Autor: Markus Spiske

Krótkie przypomnienie: stos, sterta i pamięć w procesie JVM z perspektywy niskopoziomowej

Stos wątku: ramki wywołań i życie metod

Każdy wątek JVM ma własny stos wątku. To struktura pamięci, w której JVM zapisuje:

  • ramki wywołań metod (ang. stack frames),
  • lokalne zmienne,
  • adres powrotu do wywołującej metody,
  • informacje pomocnicze dla JIT/GC (mapy lokalnych referencji).

Kiedy wywołujesz metodę, JVM „dokłada” nową ramkę na szczyt stosu; gdy metoda się kończy – ramka znika. Thread dump to nic innego jak tekstowa reprezentacja zawartości tych ramek dla wszystkich wątków w danym momencie: od metody na samym dole (start wątku), po tę na górze, która aktualnie się wykonuje lub czeka.

Stos jest relatywnie mały, ale bardzo szybki. Błędy takie jak StackOverflowError wynikają z przepełnienia stosu (np. przy nieskończonej rekurencji). Thread dump pokazuje wtedy długą, powtarzającą się sekwencję metod, co pozwala łatwo namierzyć problematyczny fragment kodu.

Sterta (heap): magazyn obiektów zarządzany przez GC

Sterta JVM to duży obszar pamięci, w którym żyją wszystkie obiekty tworzone przez new. Dobrym obrazowym porównaniem jest magazyn z regałami:

  • Każdy obiekt dostaje swój „karton” na półce (adres w pamięci).
  • Gdy obiekt nie jest już nigdzie referencjonowany, GC może karton wyrzucić i zwolnić miejsce.
  • Magazyn jest podzielony na sekcje (young/old generation), co optymalizuje sprzątanie.

Heap dump to z kolei dokładny spis kartonów w magazynie wraz z ich połączeniami (referencjami). Można w nim znaleźć:

  • listę wszystkich instancji danej klasy,
  • rozmiar w bajtach zajmowany przez dane typy,
  • ścieżkę od „korzeni” (GC roots) do każdego obiektu.

Garbage collector a heap dump – tu widać ważne powiązanie. GC sprząta wszystko, do czego nie da się już dojść z GC roots. Jeśli obiekt jest cały czas w zasięgu chociaż jednej referencji, pozostaje na stercie. Analiza heap dumpu to tak naprawdę inspekcja, dlaczego GC nie mógł czegoś wyrzucić.

Inne obszary pamięci JVM: Metaspace, Code Cache, native heap

Sterta i stos to tylko część obrazu pamięci procesu JVM. Poza nimi są:

  • Metaspace – przechowuje metadane klas (odpowiednik dawnego PermGena). Przepełnienie Metaspace powoduje OutOfMemoryError: Metaspace. Heap dump standardowo go nie obejmuje, ale niektóre narzędzia potrafią pokazać liczbę załadowanych klas.
  • Code Cache – miejsce, gdzie JIT umieszcza skompilowany do kodu maszynowego fragmenty Javy. Problemy z Code Cache objawiają się spadkami wydajności i specyficznymi błędami.
  • Native heap – pamięć alokowana poza stertą, np. przez JNI, biblioteki natywne, Bufory DirectByteBuffer, sterowniki baz danych. Heap dump (Java) nie pokazuje tej pamięci; do analizy native heapu używa się innych narzędzi (np. pmap, jemalloc tools, jhsdb).

Kiedy pojawia się OutOfMemoryError, dobrze ustalić, których obszarów dotyczy. Parametry JVM i log błędu zwykle wskazują, czy problem jest w Java heap space, Metaspace czy native memory. Heap dump pomaga tylko w tym pierwszym obszarze, ale i tak jest to zdecydowana większość problemów wycieków w typowych aplikacjach businessowych.

Proces JVM na poziomie systemu operacyjnego

Dla systemu operacyjnego JVM to zwykły proces, który używa wirtualnej pamięci. Sterta, stosy wątków, Metaspace i wszystkie inne segmenty są odwzorowane na strony pamięci, które mogą być przerzucane między RAM a swapem.

Z tego wynikają praktyczne konsekwencje:

  • Obserwując RES i VIRT w narzędziach typu top czy ps, widzisz sumę: heap + stacks + metaspace + native heap + inne.
  • OutOfMemoryError: Java heap space może się pojawić, mimo że system ma jeszcze wolną pamięć – bo limituje cię ustawione -Xmx.
  • Z kolei system może zabić proces (OOM killer), mimo że Java nie rzuca OOME – bo większość pamięci „uciekła” do native heapu poza kontrolą GC.

Zrozumienie tego mapowania ułatwia interpretację zrzutów. Jeżeli monitoring hosta pokazuje zużycie pamięci bliskie 100%, a heap dump jest relatywnie niewielki, trzeba patrzeć szerzej niż tylko na stertę – w grę wchodzi natywna pamięć, rozmiar stosów wątków, buffery, cache w bibliotece sieciowej itd.

Rodzaje zrzutów w Javie i kiedy których używać

Thread dump vs heap dump – co w środku siedzi

Dwa podstawowe typy zrzutów w diagnostyce JVM:

  • Thread dump (zrzut stosu wątków) – tekstowy opis wszystkich wątków JVM: nazwa, identyfikator, stan, pełny stos metod, aktualne blokady. Niewielki rozmiar pliku, szybki do wygenerowania, mało inwazyjny.
  • Heap dump (zrzut sterty) – binarny plik w formacie HPROF (lub podobnym), zawierający cały graf obiektów na stercie. Może ważyć setki megabajtów lub kilka gigabajtów. Generacja jest bardziej obciążająca, może na chwilę „zamrozić” JVM.

W uproszczeniu:

  • thread dump służy do analizy blokad, wątków, CPU vs I/O,
  • heap dump służy do analizy pamięci: wycieki, rozmiary, struktury danych.

Często najbardziej owocne są scenariusze, w których korzysta się z obu: thread dump pokazuje, który wątek coś trzyma, heap dump pokazuje, co jest trzymane.

Zrzuty ręczne i automatyczne – jak to skonfigurować

Zrzuty można generować ręcznie lub pozwolić JVM robić to automatycznie w określonych warunkach.

Ręczne metody:

  • jstack <pid> – generuje thread dump danego procesu JVM.
  • jcmd <pid> GC.heap_dump / Thread.print – uniwersalne narzędzie dostarczane z JDK.
  • kill -3 <pid> (Linux/Unix) – wysyła sygnał SIGQUIT; JVM wypisuje thread dump na standardowe wyjście (zwykle w logach).
  • Przyciski „Thread Dump” czy „Heap Dump” w konsolach administracyjnych serwerów aplikacyjnych (Tomcat, WebLogic, WebSphere, WildFly).

Automatyczne generowanie zrzutów jest kluczowe przy rzadkich, trudnych do złapania problemach:

  • -XX:+HeapDumpOnOutOfMemoryError – JVM tworzy heap dump przy OutOfMemoryError.
  • -XX:HeapDumpPath=<ścieżka> – określa miejsce, gdzie zapisać heap dump.
  • Opcje -XX:+UnlockDiagnosticVMOptions -XX:+LogVMOutput -XX:LogFile=... – pozwalają przechwycić thread dumpy do dedykowanego pliku przy niektórych zdarzeniach.

Przy automatycznych zrzutach dobrze już na starcie zaplanować, co się wydarzy, gdy pliki osiągną spore rozmiary. Jedna maszyna z produkcji z setkami mikroserwisów i kilkoma OutOfMemoryError w nocy potrafi zapełnić dysk szybciej, niż administrator zdąży zareagować. Dlatego parametry typu rotacja logów, osobny filesystem na dumpy czy prosty job czyszczący stare pliki są tak samo ważne, jak samo włączenie HeapDumpOnOutOfMemoryError. Rozsądny kompromis to trzymanie tylko kilku ostatnich zrzutów, spakowanych i zarchiwizowanych poza hostem.

Do rzadkich problemów wydajnościowych przydaje się też podejście „profilera offline”: cyklicznie zbierać thread dumpy co kilka sekund przez krótki okres, a potem zlepić je w jedną historię wykonania. Można to zrobić prostym skryptem z jstack albo bardziej wyrafinowanymi narzędziami (np. async-profiler, Flight Recorder). Taki pakiet zrzutów daje znacznie pełniejszy obraz niż pojedynczy snapshot, bo pokazuje, jak wątki „wędrują” między stanami RUNNABLE, BLOCKED i WAITING.

Czasem najbardziej praktycznym rozwiązaniem jest integracja z istniejącą infrastrukturą: przy powtarzających się alertach z APM można dodać mały hook, który po przekroczeniu określonego czasu odpowiedzi wywoła jcmd Thread.print i zapisze wynik obok logów. Dzięki temu nie trzeba czekać, aż problem „znowu się wydarzy”, żeby mieć materiał do analizy – system sam tworzy ślad, gdy tylko aplikacja zaczyna się dławić.

Dobrze poukładany warsztat pracy ze zrzutami – od podstawowej wiedzy o stosie i stercie, przez umiejętność szybkiego wygenerowania dumpa, aż po wygodne narzędzia do wizualizacji – sprawia, że wiele z pozoru „magicznych” problemów aplikacyjnych staje się zwykłymi zadaniami inżynierskimi do odhaczenia. Zamiast zgadywać, co dzieje się w JVM, zaglądasz do środka i po prostu to sprawdzasz.

Zbliżenie kolorowego kodu Java na ekranie monitora
Źródło: Pexels | Autor: Godfrey Atima

Thread dump w praktyce: jak wykonać i nie zabić produkcji

Jak thread dump wpływa na JVM – co się dzieje „pod maską”

Thread dump kojarzy się z lekką operacją – i w większości przypadków tak jest. JVM zatrzymuje na chwilę świat, przechodzi po wszystkich wątkach, zrzuca ich stosy i rusza dalej. Ta pauza zwykle trwa od ułamków do kilku–kilkunastu milisekund. Przy aplikacjach o niskich wymaganiach czasowych jest to praktycznie nieodczuwalne.

Problem zaczyna się przy bardzo dużej liczbie wątków (setki, tysiące) lub przy JVM już przeciążonej (wysokie CPU, GC w panice). Wtedy zrobienie kilku dumpów z rzędu może być tym słomianym źdźbłem, które łamie wielbłądowi kręgosłup – sam proces debugowania dokłada obciążenie.

Z tego powodu thread dumpy na produkcji warto robić:

  • rzadko, ale konkretnie – kilka dumpów w odstępie kilku sekund zamiast niekończącej się pętli,
  • w momentach faktycznego problemu (timeouty, rosnące czasy odpowiedzi, spike CPU),
  • narzędziem, które dobrze znasz – mniej czasu spędzasz na „walce z konsolą”, więcej na zebraniu tego, co potrzebne.

Bezpieczne sposoby wykonania thread dumpu

Najczęściej używane ścieżki są trzy. W codziennej praktyce dobrze mieć opanowane wszystkie, bo w różnych środowiskach różne są dostępne.

  1. Sygnał do procesu: kill -3 <pid> (Linux/Unix)
    JVM przechwytuje sygnał SIGQUIT i wypisuje thread dump na standardowe wyjście – najczęściej w głównym logu aplikacji (np. catalina.out w Tomcacie, stdout kontenera).
    Zaletą jest prostota: nie trzeba mieć JDK na serwerze, wystarczy uprawnienie do wysłania sygnału.
    Pułapką bywa miejsce docelowe – ogromny dump w „zwykłym” logu utrudnia analizę, a przy dużym ruchu logi mogą się rotować zanim ktoś je skopiuje.
  2. jstack <pid> – klasyka z JDK
    Narzędzie jstack łączy się z działającą JVM i wypisuje stack trace wszystkich wątków. Można przekierować wynik do osobnego pliku:
    jstack <pid> > thread-dump-$(date +%s).txt
    W razie poważnych problemów (JVM „zamrożona”) przydaje się flaga -F, która wymusza atak „z boku” (attach do procesu przez debugger). Trzeba jednak wiedzieć, że jstack -F jest bardziej inwazyjny – potrafi dodatkowo obciążyć proces i system.
  3. jcmd <pid> Thread.print – szwajcarski scyzoryk
    jcmd jest nowsze, wspiera wiele poleceń diagnostycznych. Thread dump uzyskasz tak:
    jcmd <pid> Thread.print > thread-dump.txt
    Dodatkowo można poprosić JVM o zrzut statystyk blokad czy własności wątków; format bywa bogatszy niż w jstack.

W kontenerach Dockera pid procesu JVM często jest równy 1. Warto sprawdzić, czy narzędzia typu jcmd są w ogóle dostępne w obrazie – w wielu „odchudzonych” buildach jest tylko JRE, bez binarek z JDK. Wtedy pozostaje sygnał kill -3 lub zdalne narzędzia (np. JMX).

Ile dumpów zebrać i w jakich odstępach

Jeden thread dump to fotografia. Żeby mieć film, trzeba kilku klatek. Przy typowych problemach wydajnościowych dobrze sprawdza się prosty schemat:

  • 3–5 dumpów,
  • odstęp 3–5 sekund między kolejnymi zrzutami.

Jeżeli zakładasz typowy „zastój” (np. wątek trzyma lock i nic się nie dzieje), ten prosty zestaw pokazuje, czy sytuacja jest trwała, czy dynamiczna. Wątki zmieniające stan z RUNNABLE na BLOCKED, pojawiające się i znikające, od razu zwrócą uwagę.

Przy długotrwałym „zamulaniu” (np. kilkuminutowy spike CPU) sensowna bywa seria dumpów robiona automatem, np. co 10–15 sekund przez 2–3 minuty. Tego nie trzeba wykonywać ręcznie – prosty skrypt bashowy wystarczy:

for i in {1..10}; do
  jstack <pid> > thread-dump-$(date +%s).txt
  sleep 10
done

Ryzyka na produkcji i jak je minimalizować

Najczęstsze obawy przy zrzutach na produkcji to: „Czy to nie zwiesi JVM?” oraz „Czy nie zalejemy dysku?”. W przypadku thread dumpów, przy rozsądnej liczbie wątków, pierwsze ryzyko jest niewielkie. Drugie – jak najbardziej realne.

Dump wątków kilku tysięcy wątków może mieć kilkanaście megabajtów. Przy serii kilkudziesięciu zrzutów i braku rotacji logów dysk potrafi się wypełnić zaskakująco szybko. Dlatego przy dłuższych sesjach diagnostycznych:

  • zapisuj dumpy do osobnego katalogu,
  • po zebraniu materiału spakuj je (proste tar.gz redukuje rozmiar kilkukrotnie),
  • przenieś pliki z hosta produkcyjnego na maszynę analityczną możliwie szybko.

W środowiskach, gdzie IO jest krytyczne (np. JVM współdzieląca wolny dysk sieciowy), lepszym rozwiązaniem może być wysyłanie dumpów na zewnętrzny storage lub wykorzystanie wbudowanych mechanizmów APM, które same przechwytują stack trace’y „gorących” wątków bez generowania pełnego dumpa.

Anatomia zrzutu stosu: jak czytać pojedynczy wątek

Podstawowe sekcje wpisu wątku

Większość narzędzi generuje podobny format. Typowy wpis jednego wątku (przykład skrócony) może wyglądać tak:

"http-nio-8080-exec-47" #123 daemon prio=5 os_prio=0 tid=0x00007f8c580b9000 nid=0x4f2b runnable [0x00007f8c1c2f9000]
   java.lang.Thread.State: RUNNABLE
        at com.example.dao.UserDao.findById(UserDao.java:57)
        at com.example.service.UserService.getUser(UserService.java:34)
        at com.example.web.UserController.handleGet(UserController.java:21)
        ...
   Locked ownable synchronizers:
        - <0x00000007d9c9d1d8> (a java.util.concurrent.ThreadPoolExecutor$Worker)

Z takiego bloku da się wyciągnąć sporo informacji:

  • Nazwa wątku – tu: http-nio-8080-exec-47; zwykle wskazuje na pulę wątków (Tomcat, Spring, scheduler).
  • Identyfikatory: tid (Thread ID w JVM), nid (Native ID z perspektywy systemu). nid przydaje się, gdy korelujesz wątki z narzędziami systemowymi (np. top -H).
  • Stan: RUNNABLE, BLOCKED, WAITING, TIMED_WAITING, NEW, TERMINATED.
  • Stos metod – od najnowszej (na górze) do starszych wywołań w dół.
  • Informacje o blokadach – sekcja „Locked ownable synchronizers” oraz ewentualnie linie „- locked <…>” przy konkretnych wywołaniach.

Kluczowe stany wątków i ich znaczenie diagnostyczne

Sama lista metod niewiele mówi, jeśli nie zwrócisz uwagi na stan wątku. Z czasem człowiek zaczyna je rozpoznawać „na oko”.

  • RUNNABLE – wątek aktywnie wykonuje kod albo czeka w natywnym wywołaniu (np. I/O). Wbrew nazwie nie oznacza zawsze wysokiego CPU – może też wisieć w blokującym read() z gniazda sieciowego.
    Klucz: linie at java.net.SocketInputStream.socketRead0, at sun.nio.ch.SocketChannelImpl.read sugerują czekanie na sieć; z kolei intensywne wywołania własnego kodu wskazują na pętlę obliczeniową lub algorytm „mielący” dane.
  • BLOCKED (on object monitor) – wątek chce wejść do sekcji synchronized, ale ktoś inny trzyma monitor. Jeśli wiele wątków jest BLOCKED na tym samym obiekcie, to sygnał, że jeden wątek „zawłaszczył” lock i nie oddaje go wystarczająco szybko.
  • WAITING – wątek czeka bez limitu czasu, najczęściej przez Object.wait(), LockSupport.park() lub mechanizmy java.util.concurrent (np. take() na pustej kolejce).
    Dla długotrwałego WAITING ważne jest, czy ktoś w ogóle ma szansę go obudzić.
  • TIMED_WAITING – jak powyżej, tylko z limitem czasu (np. Thread.sleep, wait(timeout), poll(timeout)). Często normalna sytuacja w schedulerach i pulach połączeń.

Przy pierwszym kontakcie z thread dumpami dobrym nawykiem jest przejechanie wzrokiem po wszystkich wątkach i policzenie, ile jest w poszczególnych stanach. Zdziwienie, że połowa puli HTTP jest BLOCKED na jednym zamku, bywa bardzo edukujące.

Czytanie stosu „od góry do dołu”

Na górze stosu masz miejsce, w którym wątek faktycznie „stoi”. To tam spędza czas w chwili zrzutu. Reszta to historia dojścia do tego miejsca. Analiza zwykle idzie od góry:

  1. Określ, co wątek robi teraz – na jakiej metodzie się zatrzymał, jakiego typu jest to operacja (I/O, lock, obliczenia, synchronizacja).
  2. Zobacz kilka metod niżej – logiczną ścieżkę wywołania. Często dopiero tam widać, że np. to zapytanie bazodanowe pochodzi z konkretnego endpointu REST albo konkretnej ścieżki w kodzie biznesowym.
  3. Sprawdź, czy wątek nie trzyma żadnych istotnych locków (sekcja „Locked synchronizers” lub linie „- locked”). To bywa istotniejsze niż to, gdzie on sam stoi.

Przykład: stos kończący się na java.sql.DriverManager.getConnection mówi niewiele. Ale kilka linii niżej widzisz MyConnectionPool.borrowConnection, a jeszcze niżej OrderService.placeOrder. Od razu wiadomo, która ścieżka biznesowa czeka na bazę, a wątek można połączyć z konkretnymi logami HTTP.

Ślady I/O, baz danych i HTTP w dumpie

Specyficzne biblioteki zostawiają charakterystyczne ślady. Po kilku analizach wiesz, że:

  • JDBC/baza – stack z java.sql.*, com.zaxxer.hikari, org.postgresql.jdbc, oracle.jdbc.driver oznacza zapytanie do bazy lub czekanie na połączenie z puli.
  • HTTP klientorg.apache.http.impl.conn, okhttp3.internal.connection, java.net.HttpURLConnection; w RUNNABLE z native socketRead0 to czekanie na odpowiedź z zewnętrznego serwisu.
  • HTTP serwerorg.apache.coyote, org.apache.tomcat.util.net w dolnej części stosu plus twój kontroler na górze.

Dzięki temu można rozłożyć „wąskie gardło” na kawałki: ile wątków stoi obecnie w bazie, ile czeka na inne serwisy, ile kręci intensywne obliczenia w JVM.

Zbliżenie ekranu laptopa z kodem Java i analizą danych
Źródło: Pexels | Autor: Daniil Komov

Znajdowanie zakleszczeń i gorących miejsc w thread dumpach

Automatyczne wykrywanie deadlocków przez JVM

JVM sama potrafi wykryć klasyczne zakleszczenia monitorów (czyli takich locków, które pochodzą z synchronized i java.util.concurrent.locks.ReentrantLock). W thread dumpie pojawia się wtedy wyraźna sekcja:

Found one Java-level deadlock:
=============================
"thread-1":
  waiting to lock monitor 0x00000007d9c9d1d8 (object 0x00000007d9c9d1f0, a java.lang.Object),
  which is held by "thread-2"
"thread-2":
  waiting to lock monitor 0x00000007d9c9d208 (object 0x00000007d9c9d220, a java.lang.Object),
  which is held by "thread-1"

To prezent od JVM – masz od razu wypisane, które wątki są w impasie i jakie obiekty blokad są w to zamieszane. Po tej sekcji znajdziesz pełne stack trace’y tych wątków; to one zazwyczaj prowadzą do newralgicznych fragmentów kodu, gdzie ktoś w niefortunnej kolejności łapie kilka locków.

Deadlocki nieklasyczne – kolejki, future’y, bariery

Istnieją też „miękkie” zakleszczenia, których JVM nie rozpoznaje jako deadlock. Na przykład:

Dwa wątki czekają na siebie nawzajem, ale nie na ten sam monitor, tylko np. na wynik z kolejki albo zakończenie obliczeń. Dla JVM wszystko wygląda legalnie: nikt nie blokuje monitora drugiego wątku, nie ma klasycznego cyklu locków, więc w sekcji „Found one Java-level deadlock” nic się nie pojawi.

Typowe scenariusze to: wątek A robi future.get() na wyniku, który ma dostarczyć wątek B, podczas gdy B próbuje wrzucić coś do kolejki, na której z kolei wisi A; albo dwa komponenty RPC, które wywołują się nawzajem i oba czekają na odpowiedź. W dumpie widać wtedy stosy pełne Future.get(), CountDownLatch.await(), BlockingQueue.take(), ale bez klasycznego komunikatu o deadlocku.

Jak to rozpoznać? Po pierwsze, patrz na wątki w stanie WAITING / TIMED_WAITING z wywołaniami await(), get(), take(). Po drugie, porównaj, kto kogo powinien „budzić” – np. wątek pracownika, który nigdy nie ma szansy odłożyć wyniku do kolejki, bo sam czeka na wynik innego wątku. Przydaje się tu kilka dumpów zrobionych co kilkanaście sekund: jeśli układ wątków i ich stany są identyczne za każdym razem, a ruchu w systemie nie brak, masz mocną poszlakę miękkiego zakleszczenia.

Bardzo pomaga ręczne śledzenie przepływu: od konsumenta, który czeka na dane, do producenta, który ma je dostarczyć. Jeśli oba kończą na czymś w stylu „czekam na sygnał od kogoś innego”, krąg się zamyka. Narzędzia nie załatwią tego za ciebie – tutaj kluczowa jest znajomość własnej architektury i świadomość, które wątki pełnią rolę „silników”, a które są tylko klientami czekającymi na efekt pracy innych.

Gorące miejsca: wątki, które „długo nie oddają”

Drugie ważne zastosowanie thread dumpów to śledzenie gorących miejsc – fragmentów kodu, w których wątki spędzają podejrzanie dużo czasu. Prosty trik: robisz serię dumpów (np. co 10–20 sekund) i patrzysz, które wątki „zastygają” na tych samych liniach. Jeśli ten sam wątek trzy razy z rzędu stoi na OrderService.recalculatePrices(), a klient czeka na odpowiedź, masz dobry trop na wolną metodę.

Podobnie z lockami: jeśli w każdym zrzucie widzisz grupę wątków BLOCKED na tym samym monitorze, a jeden wątek konsekwentnie trzyma ten lock w środku długiej operacji I/O albo rozbudowanej pętli, to właśnie tam „gotuje się” aplikacja. Czasem wystarczy wynieść I/O poza sekcję krytyczną albo podzielić długą operację na mniejsze kawałki, żeby korek zniknął jak ręką odjął.

W praktyce dobrze jest wyrobić sobie oko na powtarzające się wzorce: powolne pętle z logiką biznesową, masywne mapy przetwarzane w jednym wątku, globalne zamki na jedną kolekcję używaną przez pół aplikacji. Thread dump nie poda gotowej odpowiedzi, ale pokazuje, gdzie naprawdę spędzany jest czas żądania – a to często więcej warte niż najbardziej wyszukane metryki.

Jak wygodnie przeszukiwać i wizualizować zrzuty wątków

Ręczne czytanie jednego krótkiego dumpa jest jeszcze do przełknięcia. Problem zaczyna się wtedy, gdy masz plik z setkami wątków albo całą serię dumpów robionych co kilka sekund. Bez narzędzi człowiek dość szybko się w tym gubi.

Na początek wystarczy zwykły edytor tekstu z porządnym wyszukiwaniem. Dobrze mieć swoje ulubione „kotwice”: nazwy pul wątków (np. http-nio, ForkJoinPool, AsyncExecutor), nazwy kluczowych klas biznesowych czy fragmenty pakietów (com.mycompany.order). Proste wyszukiwanie „ile razy pojawia się BLOCKED” potrafi szybko pokazać skalę problemu z jedną blokadą.

Kiedy prosty edytor przestaje wystarczać, wchodzą do gry wyspecjalizowane narzędzia: FastThread, TDey, wtyczki do IntelliJ czy nawet webowe analizatory dumpów. One grupują wątki po identycznych stackach, zliczają je, pokazują statystyki typów stanów. Zamiast przeglądać 300 wątków po kolei, od razu widzisz: „120 wątków stoi na tym samym locku, 80 czeka na bazę, reszta śpi”. To jest różnica jak między patrzeniem w surowy log a dashboardem z wykresem.

Przy dużych systemach dobrze sprawdza się podejście „profilera offline”. Zrzuty z kilku minut wrzucasz do narzędzia, które potrafi je zestawić: pokazać, które stosy są stałe, a które pojawiają się tylko chwilowo. Niektóre rozwiązania (np. komercyjne APM-y) pozwalają nawet odtworzyć coś w rodzaju filmiku: jak zmienia się obraz wątków w czasie. Dla długich, okresowo przycinających się procesów batchowych to często jedyny sensowny sposób, żeby złapać, co faktycznie je dusi.

Sporo można też ugrać, stosując proste konwencje w kodzie jeszcze zanim pojawi się problem. Nazwy pul wątków, czytelne nazwy executorów, oddzielne grupy dla zadań CPU i I/O – wszystko to sprawia, że w dumpie nie widzisz anonimowego „pool-7-thread-3”, tylko np. „db-writer-3” albo „price-recalc-2”. Do tego lekka dyscyplina przy logowaniu: dopisanie identyfikatora żądania czy klienta pozwala później skleić wątki z konkretnymi wpisami w logach i odtworzyć pełną historię jednego requestu.

Z czasem thread dump przestaje być „ostatnią deską ratunku”, a staje się normalnym narzędziem diagnostycznym – takim samym jak logi czy metryki. Dobrze oswojony daje do ręki rzadką kombinację: surową prawdę o stanie JVM w danym momencie i bardzo konkretną ścieżkę do fragmentu kodu, który warto wziąć na warsztat. Gdy dołożysz do tego heap dumpy i monitoring, zaczynasz patrzeć na produkcję nie jak na czarną skrzynkę, tylko jak na system, w którym można świadomie, krok po kroku, usuwać najsłabsze ogniwa.