JVM 线程dump 导出和分析

最新推荐文章于 2024-08-29 03:33:22 发布

程序员掉头发

最新推荐文章于 2024-08-29 03:33:22 发布

阅读量1.9k

点赞数

分类专栏： JVM

原文链接：https://www.jianshu.com/p/bb4ba6612392

版权

JVM 专栏收录该内容

1 篇文章 0 订阅

订阅专栏

JVM 线程dump 导出和分析

码农随想录关注

前言

线程dump是非常有用的诊断java应用问题的工具，每一个java虚拟机都有及时生成显示所有线程在某一点状态的线程dump的能力。虽然各个java虚拟机线程dump打印输出格式上略微有一些不同，但是线程dump出来的信息包含线程基本信息；线程的运行状态、标识和调用的堆栈；调用的堆栈包含完整的类名，所执行的方法，如果可能的话还有源代码的行数。
JVM中的许多问题都可以使用线程dump文件来进行诊断，其中比较典型的包括线程阻塞，CPU使用率过高，JVM Crash，堆内存不足和类装载等问题。

导出

1、查询java进程pid

使用jps [-l]命令查看本机所有java进程pid

jps [-l]

image.png

2、使用top查看目前正在运行的进程使用系统资源情况

top

image.png

当前占用cpu最高26.5%的进程为27796的java程序

3、导出指定进程pid所有线程信息

使用jstack将所有线程信息导出到指定文件中(jstack了解传送门)

1)将所有线程信息输入到指定文件中

jstack [-l] pid > xxx.log

image.png

2)-F （当'jstack [-l] pid'没有响应，强制导出堆栈dump）

jstack -F [-m] [-l] pid >xxx.log

4、分析

线程状态介绍

死锁，Deadlock（重点关注） :一般指多个线程调用间，进入相互资源占用，导致一直等待无法释放的情况。
执行中，Runnable :一般指该线程正在执行状态中，该线程占用了资源，正在处理某个请求，有可能正在传递SQL到数据库执行，有可能在对某个文件操作，有可能进行数据类型等转换。
等待资源，Waiting on condition（重点关注） :等待资源，或等待某个条件的发生。具体原因需结合 stacktrace来分析。
1、如果堆栈信息明确是应用代码，则证明该线程正在等待资源。一般是大量读取某资源，且该资源采用了资源锁的情况下，线程进入等待状态，等待资源的读取。
又或者，正在等待其他线程的执行等。
2、如果发现有大量的线程都在处在 Wait on condition，从线程 stack看，正等待网络读写，这可能是一个网络瓶颈的征兆。因为网络阻塞导致线程无法执行。
2.1、一种情况是网络非常忙，几乎消耗了所有的带宽，仍然有大量数据等待网络读写；
2.2、另一种情况也可能是网络空闲，但由于路由等问题，导致包无法正常的到达。
3、另外一种出现 Wait on condition的常见情况是该线程在 sleep，等待 sleep的时间到了时候，将被唤醒。
等待获取监视器，Waiting on monitor entry（重点关注）
对象等待中，Object.wait() 或 TIMED_WAITING
Waiting for monitor entry 和 in Object.wait()：
Monitor(Monitor的深入理解传送门)是 Java中用以实现线程之间的互斥与协作的主要手段，它可以看成是对象或者 Class的锁。每一个对象都有，也仅有一个 monitor。
从下图中可以看出，每个 Monitor在某个时刻，只能被一个线程拥有，该线程就是 “Active Thread”，而其它线程都是 “Waiting Thread”，分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。
在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”，而在 “Wait Set”中等待的线程状态是 “in Object.wait()”

Java Monitor

暂停，Suspended
阻塞，Blocked（重点关注）：是指当前线程执行过程中，所需要的资源长时间等待却一直未能获取到，被容器的线程管理器标识为阻塞状态，可以理解为等待资源超时的线程。
停止，Parked

jvm_27796.log展示

image.png

stack trace实例分析

"consumer_redirectUrl_topic_jmq206_1546013217302" daemon prio=10 tid=0x00007f1bf03f6800 nid=0x693e waiting on condition [0x00007f1b38388000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000f76e21a0> (a java.util.concurrent.CountDownLatch$Sync)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1033)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1326)
    at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:282)
    at com.jd.jmq.common.network.netty.ResponseFuture.await(ResponseFuture.java:133)
    at com.jd.jmq.common.network.netty.NettyTransport.sync(NettyTransport.java:241)
    at com.jd.jmq.common.network.netty.failover.FailoverNettyClient.sync(FailoverNettyClient.java:94)
    at com.jd.jmq.client.consumer.GroupConsumer.pull(GroupConsumer.java:246)
    at com.jd.jmq.client.consumer.GroupConsumer$QueueConsumer.run(GroupConsumer.java:445)
    at java.lang.Thread.run(Thread.java:745):
    - None

线程名：consumer_redirectUrl_topic_jmq206_1546013217302
线程优先级：prio=10
java线程的identifier：tid=0x00007f1bf03f6800
native线程的identifier：nid=0x693e
线程的状态：waiting on condition [0x00007f1b38388000]
java.lang.Thread.State: TIMED_WAITING (parking)
线程栈起始地址：[0x00007f1b38388000]

找出某进程中要分析的线程ID

top -H -p <pid>

将线程ID转换为16进制后，在线程dump文件中搜索相关信息

例如：27840==》6cc0

"System_Clock" daemon prio=10 tid=0x00007f1c2cbc6800 nid=0x6cc0 runnable [0x00007f1c24872000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c0c9d918> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
   Locked ownable synchronizers:
    - None