25 FastThread 相关的工具介绍:欲穷千里目,更上一层楼

FastThread 简介

在前面的章节里,我们知道了可以打印出来 JVM 的所有线程信息,然后进行分析。然而所有的线程信息都很长,看起来又差不多,每次去看都让人头大。

所以,每当我去分析线程都在想,要是有工具能帮我把一般情况汇总,并自动帮我分析分析 JVM 线程情况就好了。这里要介绍的 FastThread 就是这么一款工具。

FastThread 是一款线程转储(Thread Dump)分析工具,官网地址为:http://fastthread.io/

这款工具由 tier1app 公司 开发和支持,这家公司现在主要提供 3 款 JVM 分析工具,除了 FastThread 还有:

  • GCEasy,访问地址:https://gceasy.io/,详情请参考前面的文章 [《GC 日志解读与分析(番外篇可视化工具)》]。
  • HeapHero,官网地址:https://heaphero.io/,顾名思义,这是一款 Heap Dump 分析工具。

FastThread 工具可用来分析和定位问题,功能特征包括:

顺便说一句,JVM 的线程转储不只是 Java 语言有,其他语言也是支持的,例如 Scala、Jython、JRuby 等等。

通过 FastThread 官方网站在线进行线程堆栈分析是“免费”的,下面我们通过示例程序来演示这款工具的使用。

示例程序与线程 Dump

基于前面《JVM 的线程堆栈数据分析》章节中的示例代码,我们简单修改一下,用来模拟死锁和线程等待的状态。

示例程序如下:

package demo.jvm0207;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
public class DeadLockSample2 {
    public static void main(String[] args) throws Exception {
        DeadLockTask deadLockTask = new DeadLockTask();
        // 多线程模拟死锁
        new Thread(deadLockTask).start();
        new Thread(deadLockTask).start();
        // 等待状态
        Thread wt = new WaitedThread();
        wt.start();
        // 当前线程等待另一个线程来汇合
        wt.join();
    }

    private static class WaitedThread extends Thread {
        @Override
        public void run() {
            synchronized (DeadLockSample2.class) {
                try {
                    DeadLockSample2.class.wait();
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        }
    }

    // 简单的死锁; 分别锁2个对象
    private static class DeadLockTask implements Runnable {
        private Object lockA = new Object();
        private Object lockB = new Object();
        private AtomicBoolean flag = new AtomicBoolean(false);
        public void run() {
            try {
                if (flag.compareAndSet(false, true)) {
                    synchronized (lockA) {
                        TimeUnit.SECONDS.sleep(2);
                        synchronized (lockB) {
                            System.out.println("死锁内部代码");
                        }
                    }
                } else {
                    synchronized (lockB) {
                        TimeUnit.SECONDS.sleep(2);
                        synchronized (lockA) {
                            System.out.println("死锁内部代码");
                        }
                    }
                }
            } catch (Exception e) {
            }
        }
    }
}

我们启动程序,会发现系统卡住不动。

然后我们可以用各种工具来探测和检查线程状态,如果有不了解的同学,可以参考前面的 《[JVM 的线程堆栈数据分析]》章节。

线程转储快照(Thread Dump)可用来辅助诊断 CPU 高负载、死锁、内存异常、系统响应时间长等问题。

所以我们需要先获取对应的 Thread Dump 文件:

# 查看本地 JVM 进程信息
jps -v
#  直接打印线程快照
jstack -l 51399
#  将线程快照信息保存到文件
jstack -l 51399 > 51399.thread.dump.txt

jstack 工具得到的线程转储信息大致如下所示:

Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.162-b12 mixed mode):

"Thread-2" #15 prio=5 os_prio=31 tid=0x00007fb3ee805000 nid=0x5a03 in Object.wait() [0x000070000475d000]
   java.lang.Thread.State: WAITING (on object monitor)
 at java.lang.Object.wait(Native Method)
 - waiting on <0x000000076abee388> (a java.lang.Class for demo.jvm0207.DeadLockSample2)
 at java.lang.Object.wait(Object.java:502)
 at demo.jvm0207.DeadLockSample2$WaitedThread.run(DeadLockSample2.java:25)
 - locked <0x000000076abee388> (a java.lang.Class for demo.jvm0207.DeadLockSample2)

   Locked ownable synchronizers:
 - None

"Thread-1" #14 prio=5 os_prio=31 tid=0x00007fb3ed05d800 nid=0x5903 waiting for monitor entry [0x000070000465a000]
   java.lang.Thread.State: BLOCKED (on object monitor)
 at demo.jvm0207.DeadLockSample2$DeadLockTask.run(DeadLockSample2.java:52)
 - waiting to lock <0x000000076abf7338> (a java.lang.Object)
 - locked <0x000000076abf7348> (a java.lang.Object)
 at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
 - None

"Thread-0" #13 prio=5 os_prio=31 tid=0x00007fb3ef8c1000 nid=0xa703 waiting for monitor entry [0x0000700004557000]
   java.lang.Thread.State: BLOCKED (on object monitor)
 at demo.jvm0207.DeadLockSample2$DeadLockTask.run(DeadLockSample2.java:45)
 - waiting to lock <0x000000076abf7348> (a java.lang.Object)
 - locked <0x000000076abf7338> (a java.lang.Object)
 at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
 - None

"main" #1 prio=5 os_prio=31 tid=0x00007fb3ee006000 nid=0x2603 in Object.wait() [0x0000700002f15000]
   java.lang.Thread.State: WAITING (on object monitor)
 at java.lang.Object.wait(Native Method)
 - waiting on <0x000000076abf7cf8> (a demo.jvm0207.DeadLockSample2$WaitedThread)
 at java.lang.Thread.join(Thread.java:1252)
 - locked <0x000000076abf7cf8> (a demo.jvm0207.DeadLockSample2$WaitedThread)
 at java.lang.Thread.join(Thread.java:1326)
 at demo.jvm0207.DeadLockSample2.main(DeadLockSample2.java:17)

   Locked ownable synchronizers:
 - None

JNI global references: 1358

Found one Java-level deadlock:
=============================
"Thread-1":
  waiting to lock monitor 0x00007fb3ee01f698 (object 0x000000076abf7338,a java.lang.Object),
  which is held by "Thread-0"
"Thread-0":
  waiting to lock monitor 0x00007fb3ee01f7f8 (object 0x000000076abf7348,a java.lang.Object),
  which is held by "Thread-1"

Java stack information for the threads listed above:
===================================================
"Thread-1":
 at demo.jvm0207.DeadLockSample2$DeadLockTask.run(DeadLockSample2.java:52)
 - waiting to lock <0x000000076abf7338> (a java.lang.Object)
 - locked <0x000000076abf7348> (a java.lang.Object)
 at java.lang.Thread.run(Thread.java:748)
"Thread-0":
 at demo.jvm0207.DeadLockSample2$DeadLockTask.run(DeadLockSample2.java:45)
 - waiting to lock <0x000000076abf7348> (a java.lang.Object)
 - locked <0x000000076abf7338> (a java.lang.Object)
 at java.lang.Thread.run(Thread.java:748)

Found 1 deadlock.

工具自动找到了死锁,另外几个处于等待状态的线程也标识了出来。当然,上面省略了其他线程的信息,例如:

Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.162-b12 mixed mode):
"Thread-2" #15 ... in Object.wait()
   java.lang.Thread.State: WAITING (on object monitor)
"Thread-1" #14 ... waiting for monitor entry
   java.lang.Thread.State: BLOCKED (on object monitor)
"Thread-0" #13 ... waiting for monitor entry
   java.lang.Thread.State: BLOCKED (on object monitor)
"Service Thread" #12 ... daemon prio=9 ... runnable
   java.lang.Thread.State: RUNNABLE
"C2 CompilerThread2" #10 daemon ... waiting on condition
   java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" #4 daemon ... runnable
   java.lang.Thread.State: RUNNABLE
"Finalizer" #3 daemon ... in Object.wait()
   java.lang.Thread.State: WAITING (on object monitor)
"Reference Handler" #2 daemon ... in Object.wait()
   java.lang.Thread.State: WAITING (on object monitor)
"main" #1 ... in Object.wait()
   java.lang.Thread.State: WAITING (on object monitor)

"VM Thread" ... runnable
"GC task thread#0 (ParallelGC)" ... runnable
"GC task thread#1 (ParallelGC)" ... runnable
"GC task thread#2 (ParallelGC)" ... runnable
"GC task thread#3 (ParallelGC)" ... runnable
"GC task thread#4 (ParallelGC)" ... runnable
"GC task thread#5 (ParallelGC)" ... runnable
"GC task thread#6 (ParallelGC)" ... runnable
"GC task thread#7 (ParallelGC)" ... runnable
"VM Periodic Task Thread" ... waiting on condition

获取到了线程快照信息之后,下面我们来看看怎么使用 FastThread 分析工具。

FastThread 使用示例

打开官网首页:http://fastthread.io/

文件上传方式

img

选择文件并上传,然后鼠标点击“分析”(Analyze)按钮即可。

上传文本方式

img

两种方式步骤都差不多,选择 RAW 方式上传文本字符串,然后点击分析按钮。

分析结果页面

等待片刻,自动跳转到分析结果页面。

6843295.png

这里可以看到基本信息,以及右边的一些链接:

线程数汇总

把页面往下拉,可以看到线程数量汇总报告。

6864312.png

从这个报告中可以很直观地看到,线程总数为 26,其中 19 个运行状态线程,5 个等待状态的线程,2 个阻塞状态线程。

右边还给了一个饼图,展示各种状态所占的比例。

线程组分析

接着是将线程按照名称自动分组。

6898070.png

这里就看到线程命名的好处了吧!如果我们的线程池统一命名,那么相关资源池的使用情况就很直观。

所以在代码里使用线程池的时候,统一添加线程名称就是一个好的习惯!

守护线程分析

接下来是守护线程分析:

6923926.png

这里可以看到守护线程与前台线程的统计信息。

死锁情况检测

当然,也少不了死锁分析:

6948610.png

可以看到,各个工具得出的死锁检测结果都差不多。并不难分析,其中给出了线程名称,以及方法调用栈信息,等待的是哪个锁。

线程调用栈情况

以及线程调用情况:

7008839.png

后面是这些线程的详情:

7058206.png

这块信息只是将相关的方法调用栈展示出来。

热点方法统计

热点方法是一个需要注意的重点,调用的越多,说明这一块可能是系统的性能瓶颈。

7104053.png

这里展示了此次快照中正在执行的方法。如果只看热点方法抽样的话,更精确的工具是 JDK 内置的 hprof。

但如果有很多方法阻塞或等待,则线程快照中展示的热点方法位置可以快速确定问题出现的代码行。

CPU 消耗信息

img

这里的提示信息不太明显,但给出了一些学习资源,这些资源请参考本文末尾给出的博客链接地址。

GC 线程信息

img

这里看到 GC 线程数是 8 个,这个值跟具体的 CPU 内核数量相差不大就算是正常的。

GC 线程数如果太多或者太少,会造成很多问题,我们在后面的章节中通过案例进行讲解。

线程栈深度

7277060.png

这里都小于10,说明堆栈都不深。

复杂死锁检测

接下来是复杂死锁检测和 Finalizer 线程的信息。

7295147.png

简单死锁是指两个线程之间互相死等资源锁。那么什么复杂死锁呢? 这个问题留给同学们自己搜索。

火焰图

7336167.png

火焰图挺有趣,将所有线程调用栈汇总到一张图片中。

调用栈树

如果我们把所有的调用栈合并到一起,整体来看呢?

7358293.png

树形结构在有些时候也很有用,比如大量线程都在执行类似的调用栈路径时。

以上这些信息,都有助于我们去分析和排查 JVM 问题,而图形工具相对于命令行工具的好处是直观、方便、快速,帮我们省去过滤一些不必要的干扰信息的时间。

参考链接