前言
生产环境中，我们的应用有时会挂掉或运行缓慢，而去确定根本原因是比较麻烦的一件事情。线程Dump展示了正在运行的Java进程的当前状态的快照。但是，生成的数据包含多个长文件。因此，我们需要分析Java线程Dump，并从大量不相关的信息中挖掘问题。
今天，我们就来了解下如何过滤掉无用数据以有效地诊断性能问题。此外，我们还将学习检测瓶颈甚至简单的bug。
虚拟机JVM中的线程
JVM使用线程来执行每个内部和外部操作。正如大家所知道的，GC过程有自己的线程，每一个Java应用程序中的任务也有自己的线程。
在其生命周期内，线程会经历各种状态。每个线程都有一个跟踪当前操作的执行堆栈。此外，JVM还存储了以前成功调用的所有方法。因此，可以分析整个堆栈来研究出错时应用程序发生了什么。
获取Java 线程 Dump
应用程序运行后，有多种方法可以生成用于诊断的Java线程Dump。今天，我们将使用JDK7+安装包中的两个实用程序。首先，我们将执行JVM Process Status（jps）命令来发现我们应用程序的PID进程：
[root@centos1 service]# jps 3507 jar 3525 Jps
其次，我们得到应用程序的PID。然后，我们将使用jstack捕获线程Dump。最后，我们将结果存储在文本文件中：
[root@centos1 service]# jstack -l 3507 > bam-thread-dump.txt
Java线程 Dump结构
2021-02-05 15:23:03 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.191-b12 mixed mode): "Attach Listener" #33 daemon prio=9 os_prio=0 tid=0x00007fd6c4001000 nid=0xe5d waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "DestroyJavaVM" #32 prio=5 os_prio=0 tid=0x00007fd708009800 nid=0xdb4 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "http-nio-8000-AsyncTimeout" #30 daemon prio=5 os_prio=0 tid=0x00007fd709895000 nid=0xdf1 waiting on condition [0x00007fd6dde79000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.coyote.AbstractProtocol$AsyncTimeout.run(AbstractProtocol.java:1133) at java.lang.Thread.run(Thread.java:748) Locked ownable synchronizers: - None "http-nio-8000-Acceptor-0" #29 daemon prio=5 os_prio=0 tid=0x00007fd70b7a0800 nid=0xdf0 runnable [0x00007fd6ddf7a000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422) at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250) - locked <0x000000078ed72eb8> (a java.lang.Object) at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:455) at java.lang.Thread.run(Thread.java:748) Locked ownable synchronizers: - None "http-nio-8000-ClientPoller-1" #28 daemon prio=5 os_prio=0 tid=0x00007fd70b79f000 nid=0xdef runnable [0x00007fd6de07b000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x000000078f1c7a00> (a sun.nio.ch.Util$3) - locked <0x000000078f1c79f0> (a java.util.Collections$UnmodifiableSet) - locked <0x000000078f1c78d8> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:796) at java.lang.Thread.run(Thread.java:748) Locked ownable synchronizers: - None "http-nio-8000-ClientPoller-0" #27 daemon prio=5 os_prio=0 tid=0x00007fd7085b0000 nid=0xdee runnable [0x00007fd6de17c000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x000000078f1c6048> (a sun.nio.ch.Util$3) - locked <0x000000078f1c6038> (a java.util.Collections$UnmodifiableSet) - locked <0x000000078f1c5f20> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:796) at java.lang.Thread.run(Thread.java:748) Locked ownable synchronizers: - None
让我们看看生成的Java线程Dump。第一行显示时间戳，第二行展示JVM信息：
2021-02-05 15:23:03 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.191-b12 mixed mode):
然后，Dump将显示线程列表。每个线程包含以下信息：
- Name: 如果开发人员包含有意义的线程名称，它可以提供有用的信息
- Priority (prior): 线程优先级
- Java ID (tid): 虚拟机JVM给的唯一ID
- Native ID (nid): 操作系统给出的唯一ID，用于提取与CPU或内存处理的相关性
- State: 线程实际状态
- Stack trace: 最重要的信息来源，用来观察我们的应用程序正在发生什么
我们可以从上到下看到线程快照，观察不同线程正在做什么。
从整个文件中，截取一部分内容，分析其：
"http-nio-8000-exec-1" #17 daemon prio=5 os_prio=0 tid=0x00007fd70bc75800 nid=0xde4 waiting on condition [0x00007fd6f089d000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000078edd19b8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:103) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:31) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) Locked ownable synchronizers: - None
展示了线程执行的过程，以及最终停在了JNI 上。
"VM Thread" os_prio=0 tid=0x00007fd70813e800 nid=0xdb9 runnable "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007fd70801e800 nid=0xdb5 runnable "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007fd708020800 nid=0xdb6 runnable "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007fd708022000 nid=0xdb7 runnable "GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007fd708024000 nid=0xdb8 runnable "VM Periodic Task Thread" os_prio=0 tid=0x00007fd708194800 nid=0xdc3 waiting on condition JNI global references: 909
结束时，我们会注意到有几个额外的线程执行后台操作，如垃圾收集（GC）或对象终止：
分析线程Dump使用场景
为了了解我们的应用程序如何工作，我们需要有效地分析生成的快照。在Dump文件中，我们将获得大量关于所有线程的精确数据的信息。但是，我们需要整理日志文件，进行一些过滤和分组，以便从堆栈跟踪中提取有用的提示。一旦我们准备好Dump文件，我们就可以使用不同的工具来分析问题。
同步问题
通过观察线程状态，进行分析。我们需要重点关注线程状态 RUNNABLE 或者 BLOCKED的线程，最终是TIMED_WAITING。这些线程状态能够指导我们分析出，多个线程间的问题
- 在死锁情况下，运行的多个线程在共享对象上持有一个同步块
- 在线程争用中，当一个线程被阻塞等待其他线程完成时
运行问题
根据经验，对于异常高的CPU使用率，我们只需要查看RUNNABLE 线程。我们将使用线程Dump文件和其他命令来获取额外的信息。其中一个命令是top-H-ppid，它显示在特定进程中哪些线程正在消耗操作系统资源。我们还需要查看内部JVM线程，例如GC，以防万一。另一方面，当处理性能异常低时，我们将研究BLOCKED 线程。
在这些情况下，一次Dump肯定不足以理解正在发生的事情。为了比较同一线程在不同时间的堆栈，我们需要以相近的间隔进行大量Dump。一方面，一个快照并不总是足以找出问题的根源。另一方面，我们需要避免快照之间的冗余（太多的信息）。
要了解线程随时间的变化，建议的最佳实践是至少进行3次Dump，每10秒一次。另一个有用的技巧是将Dump文件分成小块，以避免加载文件时发生崩溃。
建议
为了有效地寻找问题的根源，我们需要组织堆栈跟踪中的大量信息。因此，我们将考虑以下建议：
- 在执行问题中，以10秒的间隔捕获多个快照将有助于关注实际问题。如果需要，还建议拆分文件以避免加载崩溃
- 在创建新线程时使用命名来更好地标识源代码
- 根据问题的不同，忽略内部JVM处理（例如GC）
- 当CPU或内存使用异常时，关注长时间运行或阻塞的线程
- 使用top-H-ppid将线程堆栈与CPU处理关联起来
- 最重要的是，使用Analyzer工具
手动分析Java线程Dump可能是一项比较困难的事情。对于简单的应用程序，可以识别产生问题的线程。对于复杂的情况，我们需要工具来简化这项任务。
在线工具
推荐几种在线可用的工具。在使用这种软件时，我们需要考虑到安全问题。请记住，我们使用线程工具，不可避免的与第三方共享线程日志。
FastThread
FastThread可能是分析生产环境中线程Dump文件的最佳在线工具。它提供了一个非常好的图形用户界面。它还包括多种功能，如线程的CPU使用率、堆栈长度以及最常用和最复杂的方法：
FastThread集成了RESTAPI，能来自动分析线程转储。通过一个简单的cURL命令，可以立即发送结果。主要缺点是安全性，因为它将堆栈跟踪存储在云中。
