原来jdk自带了这么好玩的工具 ＞ 使用 jstack定位死循环
Posted java叶新东老师
tags:
篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了原来jdk自带了这么好玩的工具 ＞ 使用 jstack定位死循环相关的知识，希望对你有一定的参考价值。
什么是jstack
- jstack的主要作用是查看或者导出java线程的堆栈信息(快照)；用于堆栈跟踪，当我们使用jstack命令时，它会将指定进程内的所有线程中方法的调用栈打印出来。
线程快照是java虚拟机内每一个线程正在执行的方法堆栈的集合，生成线程快照的主要目的是用于定位线程出现问题的位置；常见的问题有
- 响应时间长
- 线程死锁
- 死循环
当线程停顿的时候通过jstack来查看各个线程的调用堆栈，就可以知道线程的执行过程中在后台做了哪些事，在等待哪些资源造成的卡顿。
使用方法
命令格式
jstack [options] <pid>
options 参数说明
jstack的option参数并不多，真正用到的也就三个，接下来我们一个个介绍一下
-F：当线程挂起(Suspended)时，使用jstack -l pid命令是不会打印堆栈信息的，使用-F则可以强制输出线程堆栈；但是会停止但-l：打印的信息除了堆栈外，还会显示锁的附加信息；-m：同时输出java和C/C++的堆栈信息；在java的系统类库里面，有很多方法都是native修饰的，这些native修饰的方法你在java层面是看不到源码的，因为这些方法都是C/C++实现的；
状态说明
在线程的堆栈中，需要特别留意以下几种状态：
-
Deadlock： 死锁(重点关注) -
Waiting on condition： 等待资源(重点关注) -
Waiting on monitor entry： 等待获取监视器(重点关注) -
Blocked：阻塞(重点关注) Runnable：执行中Suspended： 暂停Object.wait()或TIME_WAITING：对象等待中Parked： 停止
no option 参数
不带option参数的命令
jstack 12771
打印结果如下
# ......忽略其他堆栈信息我们只关注main线程的堆栈
"main" #1 prio=5 os_prio=31 tid=0x00007fee9101a000 nid=0x2903 runnable [0x00007000085aa000]
java.lang.Thread.State: RUNNABLE
at java.io.FileInputStream.readBytes(Native Method)
at java.io.FileInputStream.read(FileInputStream.java:255)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
- locked <0x000000076ab1ead0> (a java.io.BufferedInputStream)
at com.test.Test.main(Test.java:12)
# .......忽略其他堆栈信息我们只关注main线程的堆栈
第一行各个单词的解析，
- "main"：线程名称 。
- prio：线程优先级
- tid：指Java Thread id。
- nid：指native线程的id。。
- [0x00007000085aa000]：线程栈起始地址。
-l 打印锁的附加信息
这里我们使用2个窗口，分别使用以下2个命令来测试
# 第一个窗口执行
jstack -l 12771
# 第二个窗口中执行
jstack 12771
通过2个窗口对比可以看到，加了-l的命令多打印了锁的信息；
导出堆栈文件
一般情况下，如果程序出错了， 都不会直接在生产环境的服务器上找错误，这个时候就可以用到一个非常实用的功能，将堆栈快照导出来，然后copy到别的电脑上看，命令如下
jstack -l 2289 > jstackDump.txt
执行后，就可以看到文件已经导出来了
通过cat命令可以看到，里面的内容和我们在命令行输出的内容是一样的
实战一 、 找出cpu占用最高的线程（linux系统）
首先我们准备好一个死循环的线程，在线程内定一个while的死循环，并且给这个线程起个名字为：Thread-yexindogn，阿里巴巴的开发规范里面有一个规定，就是每个线程必须起一个名字，起名字就是为了 以后程序出问题的时候好找错误；
public static void main(String[] args) throws InterruptedException {
new Thread(new Runnable() {
@Override
public void run() {
while(true){
System.out.println(112);
}
}
},"yexindong").start();
System.out.println("我执行了");
}
接着我们将此代码打成jar包扔到linux服务器上运行，直接输入 java -jar Test.jar 命令即可运行，运行后我们可以看到控制台一直在输出112这个字符，这就代表程序已经在运行了；
接着在看下CPU的运行情况，使用top命令查看cpu占用情况，排在第一位的是进程号为30328的进程，占用了6.6%的cpu； 这边我使用了2个命令行连到同一台服务器，一个窗口用来运行刚刚的jar包，另一个窗口用来查找错误；
找线程 - 第一种方式
知道进程号了，接着就是找线程了，输入以下命令
top -Hp 30328
打印结果如下，这里有一点需要注意，在我们加上-Hp指令后，PID展示就是线程的id了，这时候我们看到占用CPU最高的线程id是30365；
找线程 - 第二种方式
还有另一种方式，就是使用ps命令来查找线程
ps -mp 30328 -o THREAD,tid,time| sort -n -k1 -r
通过这个命令我们可以看到这边占用最高的线程id也是30365 ;
以上的方式我们成功找到了占用cpu高的线程id是11631，但这个id是十进制的，在这里需要先转为16进制，输入命令
printf "%x\\n" 30365
计算出对应的16进制为：769d
当然也可以用其他的计算工具，比如mac系统自带计算器就支持进制之间的转换
使用jstack分析堆栈快照
在命令行输入以下命令
jstack 30328
打印结果如下
[root@VM_0_5_centos ~]# jstack 30328
2021-07-14 23:40:34
Full thread dump OpenJDK 64-Bit Server VM (25.232-b09 mixed mode):
"Attach Listener" #10 daemon prio=9 os_prio=0 tid=0x00007effa4001000 nid=0x12f9 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"DestroyJavaVM" #9 prio=5 os_prio=0 tid=0x00007effd004b800 nid=0x7679 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"yexindong" #8 prio=5 os_prio=0 tid=0x00007effd0182000 nid=0x769d runnable [0x00007effbea0f000]
java.lang.Thread.State: RUNNABLE
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:326)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
- locked <0x00000000ecd6ea10> (a java.io.BufferedOutputStream)
at java.io.PrintStream.write(PrintStream.java:482)
- locked <0x00000000ecd65a10> (a java.io.PrintStream)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
- locked <0x00000000ecd659c8> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
at java.io.PrintStream.newLine(PrintStream.java:546)
- locked <0x00000000ecd65a10> (a java.io.PrintStream)
at java.io.PrintStream.println(PrintStream.java:737)
- locked <0x00000000ecd65a10> (a java.io.PrintStream)
at com.test.Test$1.run(Test.java:13)
at java.lang.Thread.run(Thread.java:748)
"Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007effd013e800 nid=0x769b runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007effd013b800 nid=0x769a waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007effd012d000 nid=0x768b waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007effd012a800 nid=0x7689 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007effd0101000 nid=0x7683 in Object.wait() [0x00007effbf906000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000ecd66260> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
- locked <0x00000000ecd66260> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)
"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007effd00fc000 nid=0x767f in Object.wait() [0x00007effbfa07000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000ecd66418> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x00000000ecd66418> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
"VM Thread" os_prio=0 tid=0x00007effd00f2800 nid=0x767d runnable
"VM Periodic Task Thread" os_prio=0 tid=0x00007effd0141000 nid=0x769c waiting on condition
JNI global references: 5
接着我用刚刚计算出来的16进制复制出来在这里搜索一下，经过查看就知道是我们刚刚起了名字为yexindong的线程出错了，出错的位置在Test.java的第13行代码
我们看看java代码，确实是第13行这里的死循环导致的
实战二、 找出cpu占用最高的线程（windows系统）
首先打开任务管理器，因为默认windows的任务管理器是不显示进程pid的，所以我们需要设置一下，选择 查看 → 选择列(S)...
选中PID进程表示符后点击确定按钮
查进程号pid
然后我们就可以看到占用CPU最高的java进程PID为：976
查线程号TID
因为windows不能直接查看java进程中的线程信息，所以我们需要借助一个工具，这个工具是微软自己开发的，叫做Process Explorer ，网上很多，需要的童鞋请自行百度，打开后找到pid为976的进程右击选择 → 属性
在弹出的窗口中找到线程这一栏，它的排序默认就是按照cpu占用的率倒序排列的，所以最上面的就是占用cpu最高的线程了，记住它的线程id：3548
线程id转16进制
刚刚拿到的进程id是十进制的，但是我们导出的jstack信息里面，线程id是以16进制来展示的，所以我们要先将这个线程id为3548转为16进制的，使用windows自带的计算器即可，在快捷命令行输入calc
计算器打开后将其设置为程序员使用的计算器
接着输入线程id3548，在按一下16进制，就会自动进行转换，结果为ddc，记住这个16进制；
使用jstack导出堆栈并分析
在命令行输入以下指令导出进程的堆栈快照信息
jstack 976 > jstackInfo.txt
几秒钟后，快照导出了，静静地躺在文件夹里，等待着我们打开
用Notepad++打开导出的文件，搜索刚刚计算出来的16进制ddc，就可以定位到线程出错的位置了
在java层面打印堆栈
有些童鞋可能会觉得用这个jstack命令麻烦了，那java在代码里面可不可以打印出堆栈呢？你别说，还真有，就是这个方法：Thread.getAllStackTraces()；光说不练假把式，来个demo测试一下吧
public static void main(String[] args) throws InterruptedException {
// 第一个线程，死循环
new Thread(new Runnable() {
@Override
public void run() {
while (true){
}
}
},"while").start();
// 延时一秒
Thread.sleep(1000);
// 第二个线程，用来打印堆栈
new Thread(new Runnable() {
@Override
public void run() {
Map<Thread, StackTraceElement[]> allStackTraces = Thread.getAllStackTraces();
for (Map.Entry<Thread, StackTraceElement[]> threadEntry : allStackTraces.entrySet()) {
Thread key = threadEntry.getKey();
System.out.println(key);
StackTraceElement[] value = threadEntry.getValue();
for (StackTraceElement stackTraceElement : value) {
System.out.println(" "+stackTraceElement.toString());
}
}
}
},"stack-info").start();
}
执行后打印结果如下，由此可以看到，将当前进程的所有线程都打印出来了，但是这边只打印了简单的堆栈信息，对于开发人员来说，已经起到了监控作用；
Thread[Reference Handler,10,system]
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:502)
java.lang.ref.Reference.tryHandlePending(Reference.java:191)
java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
Thread[while,5,main]
com.test.Test$1.run(Test.java:29)
java.lang.Thread.run(Thread.java:748)
Thread[Monitor Ctrl-Break,5,main]
java.net.SocketInputStream.socketRead0(Native Method)
java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
java.net.SocketInputStream.read(SocketInputStream.java:171)
java.net.SocketInputStream.read(SocketInputStream.java:141)
sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
java.io.InputStreamReader.read(InputStreamReader.java:184)
java.io.BufferedReader.fill(BufferedReader.java:161)
java.io.BufferedReader.readLine(BufferedReader.java:324)
java.io.BufferedReader.readLine(BufferedReader.java:389)
com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:61)
Thread[Finalizer,8,system]
java.lang.Object.wait(Native Method)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)
Thread[stack-info,5,main]
java.lang.Thread.dumpThreads(Native Method)
java.lang.Thread.getAllStackTraces(Thread.java:1610)
com.test.Test$2.run(Test.java:39)
java.lang.Thread.run(Thread.java:748)
Thread[Attach Listener,9,system]
Thread[Signal Dispatcher,9,system]
完
作为调优和找错的工具来说，可以说jstack是用的最多的一个工具了，但是由于局限性，现在已经慢慢被替换掉了；大家更倾向于使用阿里巴巴开发的工具arthas；感兴趣的童鞋可以了解下！
以上是关于原来jdk自带了这么好玩的工具 ＞ 使用 jstack定位死循环的主要内容，如果未能解决你的问题，请参考以下文章
原来jdk自带了这么好玩的工具 ＞ 使用 jstack定位死循环
原来jdk自带了这么好玩的工具 ＞ 使用 jstack定位死循环