Zaczynając od przykładu – tutaj znajdziesz kod serwera opartego o ServerSocket. Po uruchomieniu serwera i znalezieniu jego PID. za pomocą komendy (gdzie 12108 to PID):
jcmd 12108 Thread.print > filezostał wygenerowany następujący Thread Dump:
12108:
2023-01-01 19:35:11
Full thread dump OpenJDK 64-Bit Server VM (18+36-2087 mixed mode, sharing):
Threads class SMR info:
_java_thread_list=0x000001c2b574d700, length=13, elements={
0x000001c286952200, 0x000001c2b0aa8060, 0x000001c2b0aaaa10, 0x000001c2b0ac57d0,
0x000001c2b0ac6080, 0x000001c2b0ac6930, 0x000001c2b0ac71e0, 0x000001c2b0ac83d0,
0x000001c2b0ac8cc0, 0x000001c2b0acb030, 0x000001c2b55c2890, 0x000001c2b569f660,
0x000001c2b5729940
}
"main" #1 prio=5 os_prio=0 cpu=109.38ms elapsed=822.64s tid=0x000001c286952200 nid=17908 runnable [0x000000c1e36fe000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.Net.accept(java.base@18/Native Method)
at sun.nio.ch.NioSocketImpl.accept(java.base@18/NioSocketImpl.java:752)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:673)
at java.net.ServerSocket.platformImplAccept(java.base@18/ServerSocket.java:639)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:615)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:572)
at java.net.ServerSocket.accept(java.base@18/ServerSocket.java:530)
at Server.start(Server.java:23)
at ServerStarter.main(ServerStarter.java:10)
"Reference Handler" #2 daemon prio=10 os_prio=2 cpu=0.00ms elapsed=822.63s tid=0x000001c2b0aa8060 nid=1548 waiting on condition [0x000000c1e3dff000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@18/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@18/Reference.java:253)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@18/Reference.java:215)
"Finalizer" #3 daemon prio=8 os_prio=1 cpu=0.00ms elapsed=822.63s tid=0x000001c2b0aaaa10 nid=13488 in Object.wait() [0x000000c1e3eff000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@18/Native Method)
- waiting on <0x000000065e00b950> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@18/ReferenceQueue.java:155)
- locked <0x000000065e00b950> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@18/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@18/Finalizer.java:183)
"Signal Dispatcher" #4 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=822.62s tid=0x000001c2b0ac57d0 nid=15268 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Attach Listener" #5 daemon prio=5 os_prio=2 cpu=46.88ms elapsed=822.62s tid=0x000001c2b0ac6080 nid=8808 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" #6 daemon prio=9 os_prio=0 cpu=0.00ms elapsed=822.62s tid=0x000001c2b0ac6930 nid=1652 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Monitor Deflation Thread" #7 daemon prio=9 os_prio=0 cpu=0.00ms elapsed=822.62s tid=0x000001c2b0ac71e0 nid=19412 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #8 daemon prio=9 os_prio=2 cpu=46.88ms elapsed=822.62s tid=0x000001c2b0ac83d0 nid=15076 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"C1 CompilerThread0" #16 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=822.62s tid=0x000001c2b0ac8cc0 nid=3536 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"Sweeper thread" #20 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=822.62s tid=0x000001c2b0acb030 nid=16404 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Common-Cleaner" #21 daemon prio=8 os_prio=1 cpu=15.62ms elapsed=822.59s tid=0x000001c2b55c2890 nid=6220 in Object.wait() [0x000000c1e46ff000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@18/Native Method)
- waiting on <0x000000065e0f2d40> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@18/ReferenceQueue.java:155)
- locked <0x000000065e0f2d40> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@18/CleanerImpl.java:140)
at java.lang.Thread.run(java.base@18/Thread.java:833)
at jdk.internal.misc.InnocuousThread.run(java.base@18/InnocuousThread.java:162)
"Monitor Ctrl-Break" #22 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=822.54s tid=0x000001c2b569f660 nid=3340 runnable [0x000000c1e49fe000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.SocketDispatcher.read0(java.base@18/Native Method)
at sun.nio.ch.SocketDispatcher.read(java.base@18/SocketDispatcher.java:46)
at sun.nio.ch.NioSocketImpl.tryRead(java.base@18/NioSocketImpl.java:258)
at sun.nio.ch.NioSocketImpl.implRead(java.base@18/NioSocketImpl.java:309)
at sun.nio.ch.NioSocketImpl.read(java.base@18/NioSocketImpl.java:347)
at sun.nio.ch.NioSocketImpl$1.read(java.base@18/NioSocketImpl.java:800)
at java.net.Socket$SocketInputStream.read(java.base@18/Socket.java:966)
at sun.nio.cs.StreamDecoder.readBytes(java.base@18/StreamDecoder.java:270)
at sun.nio.cs.StreamDecoder.implRead(java.base@18/StreamDecoder.java:313)
at sun.nio.cs.StreamDecoder.read(java.base@18/StreamDecoder.java:188)
- locked <0x000000065e2e2818> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(java.base@18/InputStreamReader.java:176)
at java.io.BufferedReader.fill(java.base@18/BufferedReader.java:162)
at java.io.BufferedReader.readLine(java.base@18/BufferedReader.java:329)
- locked <0x000000065e2e2818> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(java.base@18/BufferedReader.java:396)
at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:49)
"Notification Thread" #23 daemon prio=9 os_prio=0 cpu=0.00ms elapsed=822.54s tid=0x000001c2b5729940 nid=10316 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"VM Thread" os_prio=2 cpu=0.00ms elapsed=822.63s tid=0x000001c286a1d370 nid=6512 runnable
"GC Thread#0" os_prio=2 cpu=0.00ms elapsed=822.64s tid=0x000001c2869f86f0 nid=4608 runnable
"G1 Main Marker" os_prio=2 cpu=0.00ms elapsed=822.64s tid=0x000001c286a07550 nid=2228 runnable
"G1 Conc#0" os_prio=2 cpu=0.00ms elapsed=822.64s tid=0x000001c286a09490 nid=12904 runnable
"G1 Refine#0" os_prio=2 cpu=0.00ms elapsed=822.64s tid=0x000001c286972f00 nid=17708 runnable
"G1 Service" os_prio=2 cpu=15.62ms elapsed=822.64s tid=0x000001c2b0957a00 nid=3804 runnable
"VM Periodic Task Thread" os_prio=2 cpu=0.00ms elapsed=822.54s tid=0x000001c2b572f280 nid=4024 waiting on condition
JNI global refs: 22, weak refs: 0
Struktura
1. Pierwsza część to ogólny opis zawierający: PID, datę wygenerowania oraz opis JDK:
12108:
2023-01-01 19:35:11
Full thread dump OpenJDK 64-Bit Server VM (18+36-2087 mixed mode, sharing)
2. Teoretycznie (według wielu opisów znalezionych w Internecie) dostajemy informacje na temat wątków związanych z bezpiecznym odzyskiwaniem pamięci. Jak dla mnie to jest to najzwyklejsza lista adresów każdego z wątków opisanego dokładnie poniżej (każdy adres odpowiada konkretnemu wątkowi).
Threads class SMR info:
_java_thread_list=0x000001c2b574d700, length=13, elements={
0x000001c286952200, 0x000001c2b0aa8060, 0x000001c2b0aaaa10, 0x000001c2b0ac57d0,
0x000001c2b0ac6080, 0x000001c2b0ac6930, 0x000001c2b0ac71e0, 0x000001c2b0ac83d0,
0x000001c2b0ac8cc0, 0x000001c2b0acb030, 0x000001c2b55c2890, 0x000001c2b569f660,
0x000001c2b5729940
}3. W dalszej części są opisane wątki widoczne z poziomu aplikacji:
"main" #1 prio=5 os_prio=0 cpu=109.38ms elapsed=822.64s tid=0x000001c286952200 nid=17908 runnable [0x000000c1e36fe000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.Net.accept(java.base@18/Native Method)
at sun.nio.ch.NioSocketImpl.accept(java.base@18/NioSocketImpl.java:752)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:673)
at java.net.ServerSocket.platformImplAccept(java.base@18/ServerSocket.java:639)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:615)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:572)
at java.net.ServerSocket.accept(java.base@18/ServerSocket.java:530)
at Server.start(Server.java:23)
at ServerStarter.main(ServerStarter.java:10)
[...]4. Pod koniec opisane są wątki wewnętrzne JVMa (charakteryzują się nie posiadaniem identyfikatorów (poprzedzone są one znakiem # – patrz Struktura opisu wątku)
"VM Thread" os_prio=2 cpu=0.00ms elapsed=822.63s tid=0x000001c286a1d370 nid=6512 runnable
"GC Thread#0" os_prio=2 cpu=0.00ms elapsed=822.64s tid=0x000001c2869f86f0 nid=4608 runnable
"G1 Main Marker" os_prio=2 cpu=0.00ms elapsed=822.64s tid=0x000001c286a07550 nid=2228 runnable
[...]5. Kilka linii niżej mamy informacje na temat globalnych referencji JNI oraz słabych referencji
JNI global refs: 22, weak refs: 06. * Czasami Thread Dump zawiera dodatkowe informacje, takie jak na przykład informacje na temat zakleszczeń (Thread Dump wygenerowany wykorzystując https://github.com/damianradowiecki/deadlock-example):
Found one Java-level deadlock:
=============================
"Thread-0":
waiting to lock monitor 0x00000191fe99b090 (object 0x000000065e291c10, a java.lang.Object),
which is held by "Thread-1"
"Thread-1":
waiting to lock monitor 0x00000191fe99ad10 (object 0x000000065e291c00, a java.lang.Object),
which is held by "Thread-0"
Java stack information for the threads listed above:
===================================================
"Thread-0":
at pl.damianradowiecki.Main.lambda$main$0(Main.java:14)
- waiting to lock <0x000000065e291c10> (a java.lang.Object)
- locked <0x000000065e291c00> (a java.lang.Object)
at pl.damianradowiecki.Main$$Lambda$14/0x0000000800c031f0.run(Unknown Source)
at java.lang.Thread.run(java.base@18/Thread.java:833)
"Thread-1":
at pl.damianradowiecki.Main.lambda$main$1(Main.java:24)
- waiting to lock <0x000000065e291c00> (a java.lang.Object)
- locked <0x000000065e291c10> (a java.lang.Object)
at pl.damianradowiecki.Main$$Lambda$15/0x0000000800c033f8.run(Unknown Source)
at java.lang.Thread.run(java.base@18/Thread.java:833)
Found 1 deadlock.Struktura opisu wątku (aplikacji)
Znajduje się tutaj opis pojedynczego wątku aplikacji. Wątki aplikacji zawierają więcej informacji niż wewnętrzne wątki JVM, stąd tutaj opisane są te pierwsze.
"main" #1 prio=5 os_prio=0 cpu=109.38ms elapsed=822.64s tid=0x000001c286952200 nid=17908 runnable [0x000000c1e36fe000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.Net.accept(java.base@18/Native Method)
at sun.nio.ch.NioSocketImpl.accept(java.base@18/NioSocketImpl.java:752)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:673)
at java.net.ServerSocket.platformImplAccept(java.base@18/ServerSocket.java:639)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:615)
at java.net.ServerSocket.implAccept(java.base@18/ServerSocket.java:572)
at java.net.ServerSocket.accept(java.base@18/ServerSocket.java:530)
at Server.start(Server.java:23)
at ServerStarter.main(ServerStarter.java:10)- Na początku w cudzysłowach wypisana jest nazwa (w tym wypadku – main)
- Następnie mamy id wątku (w tym wypadku – #1)
- Po nim mamy priorytet w JVM (w tym wypadku – 5)
- I znów priorytet, ale tym razem w odniesieniu do systemu operacyjnego (w tym wypadku – 0)
- Następnie podany jest skumulowany czas (od momentu uruchomienia aplikacji) przez jaki dany wątek używał procesora (w tym wypadku – 109.38ms)
- Kolejny parametr (elapsed) informuje o tym ile czasu minęło od uruchomienia danego wątku (w tym wypadku wątek już pracuje przez 882.64 sekund)
- Skrót tid podpowiada, że może to być thread id (id wątku), ale tak w rzeczywistości nie jest (Thread.getId() zwraca id z punktu drugiego). Parametr ten wygląda na adres wątku w pamięci (w tym wypadku – 0x000001c286952200)
- Parametr nid to identyfikator przypisany wątkowi przez system operacyjny (w tym wypadku – 17908)
- Następnie dostajemy status wątku (w tym wypadku runnable)
- Na końcu pierwszego wiersza mamy wskaźnik na ostatni element stosu (w tym wypadku – 0x000000c1e36fe000)
- Od drugiego wiersza rozpoczyna się cały stos wywołań