原来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的死循环,并且给这个线程起个名字为: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是30365,但这个id是十进制的,在这里需要先转为16进制,输入命令

printf "%x\n" 30365

计算出对应的16进制为:769d

当然也可以用其他的计算工具,比如mac系统自带计算器就支持进制之间的转换

使用jstack分析堆栈快照

1、快速查找 (推荐使用)

在命令行输入以下命令,这种方法更加快速,推荐使用

jstack 12771 | grep -A 20 '769d'

其中,grep 命令是查找结果为769d的内容,-A 20 表示打印匹配所在行的后20行内容。直接帮我们定位到所在线程的堆栈,结果如下

"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)

2、常规方法

当然也可以用下面的死办法,先打印出所有的堆栈快照;

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;感兴趣的童鞋可以了解下!

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 220,458评论 6 513
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 94,030评论 3 396
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 166,879评论 0 358
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 59,278评论 1 295
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 68,296评论 6 397
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 52,019评论 1 308
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,633评论 3 420
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,541评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 46,068评论 1 319
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 38,181评论 3 340
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 40,318评论 1 352
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,991评论 5 347
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,670评论 3 331
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 32,183评论 0 23
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,302评论 1 272
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,655评论 3 375
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 45,327评论 2 358

推荐阅读更多精彩内容