前言
线程dump是非常有用的诊断java应用问题的工具,每一个java虚拟机都有及时生成显示所有线程在某一点状态的线程dump的能力。虽然各个java虚拟机线程dump打印输出格式上略微有一些不同,但是线程dump出来的信息包含线程基本信息;线程的运行状态、标识和调用的堆栈;调用的堆栈包含完整的类名,所执行的方法,如果可能的话还有源代码的行数。
JVM中的许多问题都可以使用线程dump文件来进行诊断,其中比较典型的包括线程阻塞,CPU使用率过高,JVM Crash,堆内存不足和类装载等问题。
导出
1、查询java进程pid
- 使用jps [-l]命令查看本机所有java进程pid
jps [-l]
2、使用top查看目前正在运行的进程使用系统资源情况
top
当前占用cpu最高26.5%的进程为27796的java程序
3、导出指定进程pid所有线程信息
- 使用jstack将所有线程信息导出到指定文件中(jstack了解传送门)
1)将所有线程信息输入到指定文件中
jstack [-l] pid > xxx.log
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()”
- 暂停,Suspended
- 阻塞,Blocked(重点关注) :是指当前线程执行过程中,所需要的资源长时间等待却一直未能获取到,被容器的线程管理器标识为阻塞状态,可以理解为等待资源超时的线程。
- 停止,Parked
jvm_27796.log展示
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 <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