前言
生产环境中,我们的应用有时会挂掉或运行缓慢,而去确定根本原因是比较麻烦的一件事情。线程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