jstack命令分析

    xiaoxiao2021-03-25  115

    在线程中,有一些JVM内部的后台线程,来执行譬如垃圾回收,或则低内存的检测等等任务,这些线程往往在JVM初始化的时候就存在,比如如下例子:

    "Low Memory Detector" daemon prio=10 tid=0x081465f8 nid=0x7 runnable [0x00000000..0x00000000] "CompilerThread0" daemon prio=10 tid=0x08143c58 nid=0x6 waiting on condition [0x00000000..0xfb5fd798] "Signal Dispatcher" daemon prio=10 tid=0x08142f08 nid=0x5 waiting on condition [0x00000000..0x00000000] "Finalizer" daemon prio=10 tid=0x08137ca0 nid=0x4 in Object.wait() [0xfbeed000..0xfbeeddb8] at java.lang.Object.wait(Native Method) - waiting on <0xef600848> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116) - locked <0xef600848> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159) "Reference Handler" daemon prio=10 tid=0x081370f0 nid=0x3 in Object.wait() [0xfbf4a000..0xfbf4aa38] at java.lang.Object.wait(Native Method) - waiting on <0xef600758> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:474) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116) - locked <0xef600758> (a java.lang.ref.Reference$Lock) "VM Thread" prio=10 tid=0x08134878 nid=0x2 runnable "VM Periodic Task Thread" prio=10 tid=0x08147768 nid=0x8 waiting on condition</span>

    但是我们更多关注的是用户级别的线程

    首先说下jstack命令执行结果的一个例子

    # jstack -l 26874

    结果如下:

    "RMI Scheduler(0)" daemon prio=10 tid=0x0000000000840000 nid=0x6939 waiting on condition [0x0000000043c3a000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0000000778b2f8a0> (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:744) Locked ownable synchronizers: - None

    下面对上述结果的各个字段大概解释下:

    "RMI Scheduler(0)" 是线程名称

    prio=10 是线程优先级

    tid=0x0000000000840000是线程Id

    nid=0x6939是native线程Id

    waiting on condition 是该线程的状态

    [0x0000000043c3a000] 是线程栈的起始地址

    线程主要有如下几种状态:

    死锁,Deadlock(重点关注) 执行中,Runnable 等待资源,Waiting on condition(重点关注) 等待获取监视器,Waiting on monitor entry(重点关注) 暂停,Suspended 对象等待中,Object.wait() 或 TIMED_WAITING 阻塞,Blocked(重点关注) 停止,Parked 分别解释下:

    1. Deadlock

    很显然是已经发生了死锁,一般指多个线程调用间,进入互相资源占用,导致一直等待无法释放的情况

    2. Runnable

    说明线程正在执行,或者线程满足执行的所有条件,只是等待被操作系统调度。该线程占用了资源,正在处理某个请求,有可能正在传递SQL到数据库执行,也有可能在对某个文件操作,有可能进行数据类型等转换

    3. Waitinig on condition

    等待资源,或者等待某个条件的发生,具体原因需要结合stackstrace来分析

    主要有以下几种可能

    (1)  网络非常忙,几乎消耗了所有的带宽,仍然有大量数据等待网络读写

    (2) 也可能网络空闲,但由于路由等问题,导致包无法正常的到达

    (3) 如果堆栈信息明确是应用代码,则证明该线程正在等待资源,一般是大量读取某资源,切该资源采用了资源锁的情况下,线程进入等待状态,等待资源的读取

    (4) 也可能在等待其他线程的执行

    (5) 如果发现有大量的线程都处在wait on condition, 从线程stack来看,如果正在等待网络读写,这可能是一个网络瓶颈的征兆,因为网络阻塞导致线程无法执行

    (5) 另外一种可能是该线程在sleep,等待sleep的时间到达的时候就会被唤醒

    4. Blocked

    线程阻塞,是指当前线程执行过程中,所需要的资源长时间等待却一直未能获取到,被容器的线程管理器标识为阻塞状态,可以理解为等待资源超时的线程

    5. waiting for monitor entry 和 in Object.wait()

    在多线程的Java程序中,实现线程之间的同步,就需要用到Monitor,Monitor是java中线程之间互斥和写作的主要手段,可以看成是对象或者class锁,每个对象都有一个Monitor,并且只有一个。每个Monitor在某个时刻只会被一个线程拥有,这里会有两个队列,分别为Entry Set和 Wait Set。进入Entry Set队列中的线程状态为waiting for monitor entry, 进入Wait Set队列中的线程状态为in Object.wait()。

    现在假设有一段临界区代码

    synchronized(obj) { }

    当线程申请进入临界区的时候,注意是申请进入,即代码执行到这里的时候:

    如果这个obj对象的Monitor不被其他线程持有,并且Entry Set队列中没有其他等待线程,那么这个线程就成为obj对象的Monitor的拥有者,并执行临界区的代码,线程将处于Runnable状态。

    如果这个obj对象的Monitor已经被其他线程持有,那么该线程就要进入Entry Set对象中等待。

    所以可以看出,进入Entry Set队列的线程的状态都会是waiting for monitor entry。

    那么当线程获得了obj对象的Monitor并进入临界区直接代码后,如果发现线程继续运行的条件没有满足,它就会调用对象obj的wait方法,放弃Monitor,代码如下:

    synchronize(obj) { ..... obj.wait(); .... } 此时线程就会进入Wait Set队列,并且线程的状态都是in Object.wait()。

    这种情况下,jstack的结果有点类似于如下情况:

    "Thread-1" prio=10 tid=0x08223250 nid=0xa in Object.wait() [0xef47a000..0xef47aa38] at java.lang.Object.wait(Native Method) - waiting on <0xef63beb8> (a java.util.ArrayList) at java.lang.Object.wait(Object.java:474) at testthread.MyWaitThread.run(MyWaitThread.java:40) - locked <0xef63beb8> (a java.util.ArrayList) at java.lang.Thread.run(Thread.java:595) 其中locked<0xef63beb8> 就表示线程获得了对象obj的Monitor,进入临界区执行代码,因为发现线程继续执行的条件没有满足,所以就调用obj.wait(),所以就表现为上述waiting on <0xef63beb8>,可以看到两个都是0xef63beb8,所以线程是先得到了obj对象的Monitor,然后又在obj对象上等待。

    只有当别的线程在该对象上调用了notify()或者notifyAll()方法, Wait Set队列中的线程才能得到机会去竞争继续执行

    下面分析几个例子:

    案例一: Waiting to lock 和 Blocked

    "RMI TCP Connection(267865)-172.16.5.25" daemon prio=10 tid=0x00007fd508371000 nid=0x55aewaiting for monitor entry[0x00007fd4f8684000] java.lang.Thread.State:BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:201) -waiting to lock <0x00000000acf4d0c0>(a org.apache.log4j.Logger) at org.apache.log4j.Category.forcedLog(Category.java:388) at org.apache.log4j.Category.log(Category.java:853) at org.apache.commons.logging.impl.Log4JLogger.warn(Log4JLogger.java:234) at com.tuan.core.common.lang.cache.remote.SpyMemcachedClient.get(SpyMemcachedClient.java:110) …… 分析

    1)线程状态是Blocked,阻塞状态。说明线程等待资源超时! 2)“waiting to lock <0x00000000acf4d0c0>”指,线程在等待给这个 0x00000000acf4d0c0 地址上锁(英文可描述为:trying to obtain 0x00000000acf4d0c0 lock)。 3)在 dump 日志里查找字符串 0x00000000acf4d0c0,发现有大量线程都在等待给这个地址上锁。如果能在日志里找到谁获得了这个锁(如locked < 0x00000000acf4d0c0 >),就可以顺藤摸瓜了。 4)“waiting for monitor entry”说明此线程通过 synchronized(obj) {……} 申请进入了临界区,从而进入了下图1中的“Entry Set”队列,但该 obj 对应的 monitor 被其他线程拥有,所以本线程在 Entry Set 队列中等待。

    案例二: Waiting on condition 和 TIMED_WAITING

    "RMI TCP Connection(idle)" daemon prio=10 tid=0x00007fd50834e800 nid=0x56b2waiting 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 中时必须有另一个线程正在等待接受移交的任务,因此这就是本线程在等待的条件。 案例三:in Object.wait() 和 TIMED_WAITING

    "RMI RenewClean-[172.16.5.19:28475]" daemon prio=10 tid=0x0000000041428800 nid=0xb09in Object.wait()[0x00007f34f4bd0000] java.lang.Thread.State:TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) -waiting on <0x00000000aa672478> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118) -locked <0x00000000aa672478> (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) 分析

    1)“TIMED_WAITING (on object monitor)”,对于本例而言,是因为本线程调用了 java.lang.Object.wait(long timeout) 而进入等待状态。 2)“Wait Set”中等待的线程状态就是“in Object.wait() ”。 当线程获得了 Monitor,进入了临界区之后,如果发现线程继续运行的条件没有满足,它则调用对象(一般就是被 synchronized 的对象)的 wait() 方法,放弃了 Monitor,进入 “Wait Set”队列。只有当别的线程在该对象上调用了 notify() 或者 notifyAll() ,“ Wait Set”队列中线程才得到机会去竞争,但是只有一个线程获得对象的 Monitor,恢复到运行态。 3)RMI RenewClean 是 DGCClient 的一部分。DGC 指的是 Distributed GC,即分布式垃圾回收。 4)请注意,是先 locked <0x00000000aa672478>,后 waiting on <0x00000000aa672478>,之所以先锁再等同一个对象,请看下面它的代码实现: static private class Lock { }; private Lock lock = new Lock(); public Reference<? extends T>remove(long timeout) { synchronized (lock) { Reference<? extends T> r = reallyPoll(); if (r != null) returnr; for (;;) { .wait(timeout); r = reallyPoll(); …… } } 即,线程的执行中,先用 synchronized 获得了这个对象的 Monitor(对应于 locked <0x00000000aa672478> );当执行到 lock.wait(timeout);,线程就放弃了 Monitor 的所有权,进入“Wait Set”队列(对应于 waiting on <0x00000000aa672478> )。 5)从堆栈信息看,是正在清理 remote references to remote objects ,引用的租约到了,分布式垃圾回收在逐一清理呢。

    转载请注明原文地址: https://ju.6miu.com/read-14088.html

    最新回复(0)