苦恼
每当线上应用出现各种吞吐下降、RT增长、CPU飚高、内存溢出等问题的时候是不是脑阔疼。面对出现的问题,简直就是无从下口啊。
不要慌,其实对于线上出现的各种奇葩问题,我们使用ThreadDump就能解决90%了。
很多时候根本不需要对JVM参数进行各种复杂的调优,好好看看线程栈,优化优化你的代码,简直就是美滋滋的提升性能。
好了,言归正传,下面我们就来说下线程栈重点关注的点来协助我们进行问题的排查。
线程状态的种类
以前大家接触到的线程状态是:BLOCKED、WAITING、TIMED_WAITING、RUNABLE,今天我们换个说法来看,到底什么样的线程会出现这种状态。
为了减少篇幅,线程栈的基本概念就不在这里重复了,有兴趣的可以看以前的文章 ThreadDump分析实战 。
1、线程状态为“waiting for monitor entry”:
含义: 意味着它 在等待进入一个临界区 ,所以它在”Entry Set“队列中等待。
此时状态: BLOCKED
举例: java.lang.Thread.State: BLOCKED (on object monitor)
知识点:注意 "Entry Set" 就是咱们平时经常使用synchronized 的时候线程所等待的区域
2,如果大量线程在 “waiting for monitor entry”:
含义:可能是一个全局锁阻塞住了大量线程,如果短时间内多次打印的 thread dump 文件反映,随着时间流逝,waiting for monitor entry 的线程越来越多,没有减少的趋势,可能意味着某些线程在临界区里呆的时间太长了,以至于越来越多新线程迟迟无法进入临界区。
此时状态:BLOCKED
3、线程状态为“waiting on condition”:
含义: 它在等待另一个条件的发生,来把自己唤醒,或者是它是调用了 sleep(N)。
此时状态:WAITING || TIMED_WAITING
举例:
java.lang.Thread.State: WAITING (parking):一直等某个条件发生
java.lang.Thread.State: TIMED_WAITING (parking或sleeping):设有超时时间,那个条件不到来,也将定时唤醒自己。
4,如果大量线程在“waiting on condition”:
含义: 可能是它们又跑去获取第三方资源,尤其是第三方网络资源,迟迟获取不到Response,导致大量线程进入等待状态。
所以如果你发现有大量的线程都处在 Wait on condition,从线程堆栈看,正等待网络读写,这可能是一个网络瓶颈的征兆,因为网络阻塞导致线程无法执行。
此时状态:WAITING || TIMED_WAITING
5、线程状态为“in Object.wait()”:
含义:说明它获得了监视器之后(也就是开始执行synchronized的方法),又调用了 java.lang.Object.wait() 方法。
每个 Monitor在某个时刻,只能被一个线程拥有,该线程就是 “Active Thread”,而其它线程都是 “Waiting Thread”,分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”,而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。
当线程获得了 Monitor,如果发现线程继续运行的条件没有满足,它则调用对象(一般就是被 synchronized 的对象)的 wait() 方法,放弃了 Monitor,进入 “Wait Set”队列。
此时状态:TIMED_WAITING || WAITING
举例:
- java.lang.Thread.State: TIMED_WAITING (on object monitor);
- java.lang.Thread.State: WAITING (on object monitor);
知识点:一般都是RMI相关线程(RMI RenewClean、 GC Daemon、RMI Reaper),GC线程(Finalizer),引用对象垃圾回收线程(Reference Handler)等系统线程处于这种状态,如图。
上例子
光说肯定是干巴巴的,下面我们来看几个小样,帮助大家消化消化。
Round 1
状态:waiting for monitor entry BLOCKED
原因:这个线程在等待这个锁 0x00000000fe7exx61,等待进入临界区:
"RMI TCP Connection(12345)-xxx.52.xxx" daemon prio=10 tid=0x00000000405a6000 nid=0x68fe waiting for monitor entry [0x00007f2be65a3000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.xyz.goods.service.impl.GoodsServiceImpl.findChanellGoodsCountWithCache(GoodsServiceImpl.java:1734)
- waiting to lock <0x00000000fe7exx61> (a java.lang.String)
那么当前谁持有这个锁呢?
在线程栈中搜索0x00000000fe7exx61,我们会发现另一个线程调用了 - locked <0x00000000fe7exx61> 对现场进行了加锁
"RMI TCP Connection(64878)-172.16.52.117" daemon prio=10 tid=0x0000000040822000 nid=0x6841 runnable [0x00007f2be76b3000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
- locked <0x00000000af4ed638> (a java.io.BufferedInputStream)
at org.bson.io.Bits.readFully(Bits.java:35)
at org.bson.io.Bits.readFully(Bits.java:28)
at com.mongodb.Response.<init>(Response.java:35)
at com.mongodb.DBPort.go(DBPort.java:110)
- locked <0x00000000af442d48> (a com.mongodb.DBPort)
at com.mongodb.DBPort.go(DBPort.java:75)
- locked <0x00000000af442d48> (a com.mongodb.DBPort)
at com.mongodb.DBPort.call(DBPort.java:65)
at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:202)
at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:296)
at com.mongodb.DB.command(DB.java:152)
at com.mongodb.DBCollection.getCount(DBCollection.java:760)
at com.mongodb.DBCollection.getCount(DBCollection.java:731)
at com.mongodb.DBCollection.count(DBCollection.java:697)
at com.xyz.goods.manager.MongodbManager.count(MongodbManager.java:202)
at com.xyz.goods.service.impl.GoodsServiceImpl.findChanellGoodsCount(GoodsServiceImpl.java:1787)
at com.xyz.goods.service.impl.GoodsServiceImpl.findChanellGoodsCountWithCache(GoodsServiceImpl.java:1739)
- locked <0x00000000fe7exx61> (a java.lang.String)
Round 2
状态: waiting on condition [0x00007fd4f1a59000] TIMED_WAITING
原因:等待另一个条件发生来将自己唤醒:
"RMI TCP Connection(idle)" daemon prio=10 tid=0x00007fd50834e800 nid=0x56b2 waiting on condition [0x00007fd4f1a59000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:662)
1)“TIMED_WAITING (parking)”中的 timed_waiting 指等待状态,但这里指定了时间,到达指定的时间后自动退出等待状态;parking指线程处于挂起中。
2)状态“waiting on condition” 需要与堆栈中的“parking to wait for <0x00000000acd84de8>
(a java.util.concurrent.SynchronousQueue$TransferStack)” 这一行结合来看。此时线程肯定是在等待某个条件的发生,来把自己唤醒。其次,SynchronousQueue 并不是一个队列,只是线程之间移交信息的机制,当我们把一个元素放入到 SynchronousQueue 中时必须有另一个线程正在等待接受移交的任务,因此这就是本线程在等待的条件,一般是在等待任务的出现。
Round 3
状态: TIMED_WAITING in Object.wait()
原因:就是线程主动挂起,在等待某一条件唤醒
"RMI RenewClean-[172.16.50.182:4888]" daemon prio=10 tid=0x0000000040d2c800 nid=0x97e in Object.wait() [0x00007f9ccafd0000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000799b032d8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0x0000000799b032d8> (a java.lang.ref.ReferenceQueue$Lock)
at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:516)
at java.lang.Thread.run(Thread.java:662)
总结
综上所述,就是线程栈给我们带来的信息。当然不仅仅只有这些,但线程的状态变化是我们分析应用问题的必要基础。其实分析这玩意真没什么技巧,大概的概念搞懂之后就是唯手熟尔咯。