java dump 线程_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

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)

Locked ownable synchronizers:

- 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

image.png

image.png

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

例如：27840==》6cc0

image.png

"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