确诊 Java 运用的过程中, 咱们经常要去看线程的相关信息. 比方当时 JVM 有多少线程, 从发动到现在已经创立过多少线程, 线程的 CPU 运用率, 线程是不是产生了死锁, CPU 运用率过高是哪些代码导致的. 这要求咱们对 Java 的线程必须有一定的了解, 才能比较有针对性的剖析这些问题. 下面咱们就从剖析 Thread dump 开始介绍 Thread 相关的信息.
怎么检查当时Java运用线程的信息
最快速的办法便是取得当时运用的 Thread dump, 然后运用文本的办法检查. 比方:
$ jps
49048 Jps
3499 Pycharm
$ jcmd 3499 Thread.print > /tmp/thread.txt
$ cat /tmp/thread.txt
上面的比方中, 咱们先是运用 jps
检查当时的用户的 Java 进程, 然后咱们运用 jcmd <pid> Thread.print
指令来输出 Thread dump. 默许状况下, 这个指令会打印到当时控制台, 咱们重定向到一个本地文件. 然后运用 cat
指令来检查具体的线程内容(假如你是桌面形式, 能够运用任何文本编辑器检查).
咱们把整个 Thread dump 的信息, 分红3部分来别离解说:
- 头部 JVM 及线程 Summary 部分
- 常规线程具体信息部分
- 尾部特殊线程及其它部分
Thread dump 头部 JVM 及线程ID列表
在最开始部分, 咱们看到相似下面的信息:
3499:
2023-04-01 08:41:33
Full thread dump OpenJDK 64-Bit Server VM (17.0.5+1-b653.25 mixed mode):
Threads class SMR info:
_java_thread_list=0x000060000b029f00, length=113, elements={
0x00007fc18981e800, 0x00007fc18a01ee00, 0x00007fc18a01cc00, 0x00007fc18a8bea00,
... ...
0x00007fc1878f0200, 0x00007fc1410d6600, 0x00007fc18a489600, 0x00007fc131aefa00,
0x00007fc131ad4a00
}
榜首行是当时进程的进程号(pid), 第二行是产生 Thread dump的体系时间, 第三行首要是JDK的信息, 然后是一切线程的线程ID(tid)的列表,以及线程的数量(113). 上面SMR是 Safe Memory Reclamation 的缩写. 这部分信息通常状况下价值不大, 大部分有用的信息都在线程具体内容部分.
Thread dump 常规线程具体信息
接下来便是每个线程的具体元数据部分和线程栈部分. 咱们拿其中一个比方来阐明:
"pool-4-thread-1" #191 prio=5 os_prio=31 cpu=4012.76ms elapsed=313903.17s allocated=1229K defined_classes=23 tid=0x00007fc1898a8000 nid=0x23757 in Object.wait() [0x000070000a4d5000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@17.0.5/Native Method)
- waiting on <no object reference available>
at java.io.PipedInputStream.read(java.base@17.0.5/PipedInputStream.java:326)
- eliminated <0x0000000782139b00> (a java.io.PipedInputStream)
at java.io.PipedInputStream.read(java.base@17.0.5/PipedInputStream.java:377)
- locked <0x0000000782139b00> (a java.io.PipedInputStream)
at com.jetbrains.python.console.transport.TCumulativeTransport.read(TCumulativeTransport.kt:46)
at com.jetbrains.python.console.transport.server.TNettyServerTransport$TNettyTransport.readAll(TNettyServerTransport.kt:243)
at org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:455)
at org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:354)
at org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:243)
at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:27)
at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:313)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@17.0.5/ThreadPoolExecutor.java:1136)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@17.0.5/ThreadPoolExecutor.java:635)
at java.lang.Thread.run(java.base@17.0.5/Thread.java:833)
Locked ownable synchronizers:
- <0x0000000782139ef8> (a java.util.concurrent.ThreadPoolExecutor$Worker)
榜首行是当时线程的元数据信息, 包含许多有用的信息, 咱们逐一来解释一下:
-
"pool-4-thread-1"
: 是当时线程的名字 -
#192
: 表明这是运用发动后创立的第192个线程, 咱们能够看到这个数字在咱们的 Thread dump 从上到下是顺序添加的, 假如你发现中间某个数字没有, 阐明那个线程已经死亡了. -
prio=5
: 这是线程的优先级. Java 线程优先级是1~10, 默许是5. -
os_prio=31
: 这是当时线程在操作体系层面的优先级, 这儿是31. -
cpu=4012.76ms
: 表明当时线程从开始运转到生成Thread dump 时共运用了4012.76ms CPU 时间. -
elapsed=313903.17s
: 表明当时线程已经存活了313903.17s秒. -
allocated=1229K
: 表明当时线程共分配了1229K的内存. -
defined_classes=23
: 表明当时线程共新定义了23个新类. -
tid=0x00007fc1898a8000
: 当时线程的ID, 和榜首部分的线程ID对应. -
nid=0x23757
: 当时线程在操作体系层面的ID(在Linux里,线程是一个轻量级的进程(LWP)). -
in Object.wait()
: 表明当时线程最终运转在Obect
类的wait()
办法里面. -
[0x000070000a4d5000]
: 最终的栈指针(SP)地址, 一般确诊顶用不到这个信息.
第二行告知咱们当时线程的状况: TIMED_WAITING
, 而且是等着目标的 monitor
上.
接着是线程的栈信息, 以 at
最初的行告知咱们当时栈帧履行的类和办法, 括号里面的内容告知咱们这个类的源文件名及当时在履行的行号, 假如前面有 /
, 斜线前面表明代码归于的模块及版本.
另外有些行是以 -
最初的, 比方下面的每一行的栈帧都跟着一行以 -
最初的一行:
at java.lang.Object.wait(java.base@17.0.5/Native Method)
- waiting on <no object reference available>
at java.io.PipedInputStream.read(java.base@17.0.5/PipedInputStream.java:326)
- eliminated <0x0000000782139b00> (a java.io.PipedInputStream)
at java.io.PipedInputStream.read(java.base@17.0.5/PipedInputStream.java:377)
- locked <0x0000000782139b00> (a java.io.PipedInputStream)
首要, 咱们最下面2行看起, 第5行表明在履行 PipedInputStream
的 377 行的 read()
办法的时分, 当时线程取得了一把锁, 这把锁是归于一个 java.io.PipedInputStream
目标的. 下面是截取的 JDK 这个版本的 PipedInputStream
类的377 行邻近的源代码:
能够看到, 这个办法是一个 synchronized
办法, 要履行到377行, 必须先取得当时目标的锁.
然后咱们看第3, 4 行, 它表明在履行PipedInputStream
的326 行的 read()
办法的时分, 当时线程临时开释(eliminated) 了上层栈帧(第5行)取得的那把锁, 依据锁的ID能够看出锁是同一把.
然后咱们看326行邻近的源代码:
进入这个办法也需要取得当时目标的锁, 但是上层栈帧已经取得了这个锁, 所以这次能够直接进入这个办法. 然后在326行, 当时线程调用当时目标的 wait()
办法, 而且给了1000
ms 的参数, 意思是: 当时线程要临时抛弃具有这个锁, 而且参加这个锁的wait行列. 在这个wait行列里, 假如没被 notify()
, notifyAll()
提早唤醒进入等候行列, 那么至多等候1000ms, 就能够进入这个锁的block行列(关于 syncronized 锁, wait(), notify(), notifyAll() 办法以及 block行列 和 wait 行列, 请查询相关信息), 然后就能够竞争再次取得这个锁.
进入 wait()
办法之后, 就进入了非Java写的 native code, 拿不到目标的地址, 所以这儿尽管显现等着, 但是没有目标的引证能够给咱们看.
最终, 每个线程尾部, 都有一段是关于Locked ownable synchronizers
的部分. 有的线程具有这种一个或多个同步器, 有的没有(none), 假如有就显现在这儿.
Locked ownable synchronizers:
- <0x0000000782139ef8> (a java.util.concurrent.ThreadPoolExecutor$Worker)
在 Java 里面但凡运用 java.util.concurrent.locks.AbstractOwnableSynchronizer
或其子类完成同步功能的同步器, 而且被某个线程取得这个同步器锁的, 这个同步器就会显现在这段 Locked ownable synchronizers
里面. Java 里面的2个完成类别离是: ReentrantLock
和 ReentrantReadWriteLock
在 Java 里面, 一个锁(lock)能够是一个内置的(built-in) monitor, 也能够是一个 ownable synchronizer
, 也能够是一个与同步器关联的 java.util.concurrent.locks.Condition
目标.
尾部特殊线程及其它
在整个 Thread dump 的最下面, 咱们能够看到一些信息十分简单的线程, 比方下面这种:
"VM Thread" os_prio=31 cpu=10486.47ms elapsed=314111.17s tid=0x00007fc188405460 nid=0x7c03 runnable
"GC Thread#0" os_prio=31 cpu=71683.40ms elapsed=314111.18s tid=0x00007fc188507c80 nid=0x4203 runnable
"GC Thread#1" os_prio=31 cpu=71692.01ms elapsed=314110.89s tid=0x00007fc18800dd80 nid=0xe403 runnable
"G1 Conc#0" os_prio=31 cpu=295753.03ms elapsed=314111.18s tid=0x00007fc188508ba0 nid=0x4403 runnable
"G1 Conc#1" os_prio=31 cpu=295775.82ms elapsed=314110.87s tid=0x00007fc136f0aa20 nid=0x1050b runnable
"VM Periodic Task Thread" os_prio=31 cpu=49667.04ms elapsed=314111.09s tid=0x00007fc188529b50 nid=0x6c03 waiting on condition
这种线程根本都是 JVM 自身的一些线程, 不去处理咱们写的业务逻辑, 首要用来维护 JVM 体系自身. 它的元数据跟咱们上面介绍的线程元数据相同, 信息更少, 由于许多都是 native 代码编写, 也没有Java 的栈帧信息.
最终, Java Native Interface(JNI)相关的一些信息. 比方:
JNI global refs: 2777, weak refs: 6388
死锁信息
假如在做 Thread dump 的时分, 有死锁的存在, Thread dump 里面最终面会标明线程死锁的相关信息, 比方:
Found one Java-level deadlock:
=============================
"Thread-0":
waiting to lock monitor 0x0000600003a000d0 (object 0x000000061f613348, a java.io.PrintStream),
which is held by "Thread-1"
"Thread-1":
waiting to lock monitor 0x0000600003a185b0 (object 0x000000061f54ddd8, a ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy),
which is held by "Thread-0"
Java stack information for the threads listed above:
===================================================
"Thread-0":
at java.io.PrintStream.write(java.base@17.0.2/PrintStream.java:696)
- waiting to lock <0x000000061f613348> (a java.io.PrintStream)
at java.io.PrintStream.print(java.base@17.0.2/PrintStream.java:877)
... 省掉 ...
"Thread-1":
at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:234)
- waiting to lock <0x000000061f54ddd8> (a ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy)
... 省掉 ...
咱们会在后续的文章中单独介绍死锁, 所以关于死锁的确诊, 产生的或许状况, 这儿就不介绍了.
怎么取得 Thread dump
上面具体介绍了 Thread dump 里面的一些信息, 那么有哪些办法能够取得线程这些信息呢?
jcmd
jcmd 是 JDK 自带的指令, 经过 jcmd <pid> Thread.print
就能够得到
jstack
jstack 也是 JDK 自带的指令, 经过 jstack -l -e <pid>
也能够取得
其它办法检查线程的信息
jconsole
jconsole 是 JDK 自带的一个桌面工具, 它和 jcmd/jstack 相同, 也在 JDK 的 bin 目录下, 连接上对应的JVM 之后, 它就能够检查线程的相关信息, 还能够检测死锁.
编程办法获取线程信息
经过运用 ThreadMXBean 接口, 能比较容易的在代码中取得Java 线程的相关信息, 大家能够尝试运用如下代码:
public static void main(String[] args) {
ThreadInfo[] threadInfos = ManagementFactory.getThreadMXBean()
.dumpAllThreads(true, true);
Arrays.stream(threadInfos).forEach(System.out::println);
}
监控 JVM Thread 的一些目标
监控 Java 运用线程的相关目标对于咱们观察运用的健康状况很重要, 那么有哪些跟线程相关的目标呢?
- 当时活泼的线程数目以及从发动到现在的一切创立的线程数目;
- 按照线程的状况(blocked, running, waiting, timed_waiting)来分类的活泼线程数目;
- 按照线程是不是 daemon 线程的来分类;
- 死锁线程的数目;
prometheus 的官方 git 下有个 client_java repo, 专门针对 hotspot JVM 线程的目标: github.com/prometheus/…