三个实例演示 Java Thread Dump 日志分析

原文

线程状态

1. 死锁, DeadLock, 多个线程调用间, 进入相互资源占用, 导致一直等待无法释放的情况;
2. 执行中, Runnable, 指该线程正在执行状态中, 该线程占用了资源, 正在处理某个请求, 或者正在传递 SQL 到数据库执行, 或对某个文件操作, 或进行数据类型转换等;
3. 等待资源, Waiting on condition, 等待资源, 或等待某个条件的发生;(结合 stacktrace 分析)
   • 如果栈信息明确是应用代码, 则证明该线程正在等待资源, 一般是大量读取某资源, 且该资源采用了资源锁的情况下, 线程进入了等待状态, 等待资源的读取;
   • 或者正在等待其他线程的执行;
   • 如果发现大量的线程处于 Waiting on condition, 从线程 stack 上看, 正等待网络的读写, 这可能是网络瓶颈的征兆, 因为网络阻塞导致的线程无法执行;
     • 情况一, 是网络忙, 消耗了所有的带宽, 仍然有大量数据等待网络的读写;
     • 情况二, 网络空闲, 但由于路由等问题, 导致包丢失无法正常到达;
   • 大部分这种状态是因为线程处于 sleep, 等待 sleep 的时间到了时候被唤醒;
4. 等待获取监视器, Waiting on monitor entry
5. 暂停, Suspended
6. 对象等待中, Object.wait() or TIMED_WAITING
7. 阻塞, Blocked, 线程阻塞, 指当前线程执行过程中, 所需要的资源长时间等待却一直未能获取到, 被容器的线程管理器标识为阻塞状态, 可理解为等待资源超时的线程;
8. 停止, Parked

Monitor 是 Java 中用以实现线程之间的互斥与协作的主要手段, 可以看成是对象或者 Class 的锁; 每个对象都有, 也仅有一个 monitor;

每个 Monitor 在某个时刻, 只能被一个线程拥有, 该线程就是 Active Thread, 其他线程则处于 Waiting Thread, 分别在两个队列 Entry Set 和 Wait Set 里面等待;
在 Entry Set 中等待的线程状态是 Waiting for monitor entry;
在 Wait Set 中等待的线程是 in Object.wait();

示例一

"ForkJoinPool.commonPool-worker-37" #24464 daemon prio=5 os_prio=0 tid=0x00007f1bb418a800 nid=0x1fa12 waiting for monitor entry [0x00007f19a2054000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at java.util.concurrent.ConcurrentHashMap.computeIfPresent(ConcurrentHashMap.java:1760)
	- waiting to lock <0x00000005e20c0050> (a java.util.concurrent.ConcurrentHashMap$Node)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.evictEntry(BoundedLocalCache.java:756)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.expireAfterWriteEntries(BoundedLocalCache.java:717)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.expireEntries(BoundedLocalCache.java:674)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.maintenance(BoundedLocalCache.java:1136)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.performCleanUp(BoundedLocalCache.java:1108)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache$PerformCleanupTask.run(BoundedLocalCache.java:2979)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache$PerformCleanupTask.exec(BoundedLocalCache.java:2968)
	at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
	at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
	at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
	at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)

   Locked ownable synchronizers:
	- <0x00000005c4525180> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

1. 线程状态是 BLOCKED, 阻塞状态, 说明线程等待资源超时;
2. waiting to lock <0x00000005e20c0050> 表示线程正在等待给 0x00000005e20c0050 这个地址上锁(等待获取该地址的锁);
3. 查找日志中对应 0x00000005e20c0050 地址的 locked <0x00000005e20c0050> 位置, 就可以查出来当前谁获得了这个锁;

4. waiting for monitor entry 表示此线程通过 synchronized(obj){...} 方式申请进入里临界区, 从而进入了 Entry Set 队列, 但是该 obj 对应的 monitor 被其他线程拥有, 所以该线程在 Entry Set 队列中等待;
5. tid=thread id, nid=native 线程的 id, prio=线程优先级, 0x00007f19a2054000=线程栈起始地址;

示例二

"http-nio-58032-exec-479" #25175 daemon prio=5 os_prio=0 tid=0x00007f1c342d2800 nid=0x2d2fa waiting on condition [0x00007f1982a27000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x000000072740b888> (a java.util.concurrent.CompletableFuture$Signaller)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
	at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
	at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
	at io.lettuce.core.protocol.AsyncCommand.await(AsyncCommand.java:83)
	at io.lettuce.core.LettuceFutures.awaitOrCancel(LettuceFutures.java:112)
	at io.lettuce.core.cluster.ClusterFutureSyncInvocationHandler.handleInvocation(ClusterFutureSyncInvocationHandler.java:123)
	at io.lettuce.core.internal.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:80)

1. TIMED_WAITING (parking) 表示等待状态, 但是指定了等待时间, 到达指定的时间后自动退出等待状态; parking 表示线程处于挂起状态;
2. waiting on condition 与 parking to wait for <0x000000072740b888> 结合来看, 该线程肯定是在等待某个条件触发来唤醒自己;

示例三

"http-nio-58032-exec-307" #24690 daemon prio=5 os_prio=0 tid=0x00007f1c341b0800 nid=0x25e19 in Object.wait() [0x00007f199477a000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:502)
	at org.apache.http.concurrent.BasicFuture.get(BasicFuture.java:82)
	- locked <0x00000007162a9628> (a org.apache.http.concurrent.BasicFuture)
	at org.apache.http.impl.nio.client.FutureWrapper.get(FutureWrapper.java:70)

1. 在 Wait Set 队列中等待的线程状态就是 in Object.wait(); 当线程获得了 Monitor, 进入了临界区之后, 如果发现线程继续运行的条件没有满足, 则会调用对象(一般是被 synchronize 的对象) 的 wait() 方法, 放弃了 Monitor, 进入 Wait Set 队列; 只有当别的线程在该对象上调用 notify() 或者 notifyAll() 时, Wait Set 队列中的线程才得到机会去竞争; 但是也只有一个线程会获得对象的 Monitor, 恢复到运行态;
2. BasicFuture 的 get 方法, 表示异步请求时等待结果返回;

参考资料

1. 三个实例演示 Java Thread Dump 日志分析