一次类加载死锁问题排查
上半年遇到了一次类加载死锁的问题,花了挺长时间才定位到具体原因,因此做个记录,以便下次遇到类似问题时可以快速定位。
问题背景
上半年的一个周五的夜晚,像往常一样上线发布服务,当发到中间某一台的时候突然出现告警,大量接口请求出现超时,从监控上看告警全部来自最后发布的那台机器,说明只是一台机器存在问题,遂将其从 rpc 服务列表中拉出。
通常情况下一台机器出现问题,大概率是这台机器本身或依赖的资源存在问题,于是排查了机器网络流量、磁盘IO、CPU占用率等监控数据,没有发现异常。查看服务依赖的 redis、数据库等资源监控,也都正常。
既然外部影响因素都排除了,没有发现问题点,那就需要看下是否是内部因素导致的。关于这次发布的变更点,只是新增了一个 rpc 接口,因为调用方还没发布,也就没有流量进来,排除是代码变更因素。接下来就是排查 jvm 情况,在服务拉出后,已经使用 jstack 命令获取到线程堆栈,通过分析发现线程大多数是 runnable 状态,除了线程数偏多外并未发现其他异常。
关于 java 线程 dump 分析的工具,https://fastthread.io/
是一个不错的选择,各种线程的状态一目了然,最有意思的是,它提示从这次的堆栈中发现在一个问题,但是需要付费才能查看 🤣
后来机器重启后正常了,因为时间紧迫需要继续发布,当天并未定位到具体原因。
问题排查
问题排查还要从线程堆栈分析起来
线程堆栈
原始的线程堆栈不适合贴在这里,因此我写了个 demo,用来模拟当时的情况。下面是这个 demo 执行时的堆栈
1 | "B" #12 prio=5 os_prio=31 tid=0x00007fd4e289e800 nid=0x3b03 in Object.wait() [0x000070000497c000] |
从这里可以看到以下几点:
- java 线程的状态为
RUNNABLE
,说明它正在运行中 in Object.wait()
表示在 wait set 中等待 moitor 锁- 还有很重要的一点是,
ClassLoadDeadLock$B.<clinit>
表明它正在执行类的初始化代码,这是在 jvm 加载完类之后并初始化时调用的
如果不熟悉各种 java 线程状态的堆栈展示情况或者印象有些模糊,只看上面的堆栈很难发现问题点。因此我们来回顾下几种常见的线程状态堆栈
几种常见的线程状态堆栈
在 java 中,通过执行一些调用可以改变线程的状态
Thread.sleep(10)
执行 Thread.sleep
可使当前线程处于 TIMED_WAITING
状态并等待指定时间,在这期间线程并不会释放持有的 monitor 锁。它的堆栈如下:
1 | "main" #1 prio=5 os_prio=31 tid=0x00007f9f6b01b800 nid=0x2703 waiting on condition [0x000070000acca000] |
waiting on condition
表示线程在等待某种事件,这里是等待超时
TIMED_WAITING(sleeping)
表示是线程状态是 TIMED_WAITING
,并且是 sleep 调用引起的
LockSupport.park()
LockSupport.park()
用于挂起当前线程,它会检测是否有许可证(permit),如果有则直接消费掉许可并继续执行,否则进入 WAITING
状态,等待 LockSupport.unpark()
生成许可。它的堆栈如下:
1 | "main" #1 prio=5 os_prio=31 tid=0x00007ff98e800800 nid=0xd03 waiting on condition [0x0000700003078000] |
waiting on condition
表示线程在等待某种事件,这里是等待 unpark 操作生成许可证
WAITING(parking)
表示是线程状态是 WAITING
,并且是 park 调用引起的
synchronized
synchronized
是 java 内置的锁机制使用的关键字,通过它可以实现临界资源的互斥访问。在等待进入 synchronized
代码块时的线程栈如下:
1 | "Thread-0" #12 prio=5 os_prio=31 tid=0x00007fdc059c4800 nid=0x3e03 waiting for monitor entry [0x000070000aa36000] |
waiting for monitor entry
表示在 monitor 的 entry set 中等待
BLOCKED (on object monitor)
表示线程状态是 BLOCKED
阻塞状态,on object monitor
说明是在 monitor 锁上等待
Object.wait()
Object.wait()
和 Object.notify()
用于实现线程间的协作,调用 Object.wait()
时的堆栈如下
1 | "main" #1 prio=5 os_prio=31 tid=0x00007fe2cc013000 nid=0x2803 in Object.wait() [0x0000700000b98000] |
in Object.wait()
表示在 wait set 中等待
WAITING (on object monitor)
表示线程状态是 BLOCKED
阻塞状态,on object monitor
说明是在 monitor 锁上等待
Runnable
Runnable
并不是一个调用,它是线程的一个状态,对应堆栈栈如下:
1 | "Thread-0" #12 prio=5 os_prio=31 tid=0x00007fba05191800 nid=0x4003 runnable [0x000070001115c000] |
runnable
表明是运行状态
RUNNABLE
表明线程状态是 RUNNABLE
问题堆栈分析
了解了常见的线程状态对应的堆栈后,再回过头来看下前面的问题堆栈
1 | "B" #12 prio=5 os_prio=31 tid=0x00007fd4e289e800 nid=0x3b03 in Object.wait() [0x000070000497c000] |
第 2 行显示 java 线程状态为 RUNNABLE
从第 4 行显示当前正在执行类加载过程中的类初始化逻辑
结合这两点,我们可以猜想,当前线程正在执行类加载,我们刚好取到了这一时刻的线程快照,这也是当时排查问题时首先想到的。
再看第 1 行,这里就有些诡异了,它的显示是 in Object.wait()
,表明线程正在 wait set 中等待,这与执行 Object.wait()
时的堆栈比较类似。
一个疑问是:一个线程不应该既在运行,又在 monitor 对象的 wait set 上等待,这不合理。
说到类的加载,顺便说一下,java 虚拟机是通过执行类构造器的 <clinit>
方法完成初始化的,在这个过程中会自动加锁,以保证类只会被初始化一次。
一次尝试
我们尝试下在类加载代码中加入 Object.wait()
逻辑,查看下堆栈,如下是测试代码:
1 | public class ClassLoadDeadLock { |
对应堆栈如下:
1 | "main" #1 prio=5 os_prio=31 tid=0x00007fdfd0813800 nid=0x1703 in Object.wait() [0x000070000a549000] |
可以看到 java 线程状态是 WAITING
,与问题堆栈并不一样
Runnable 状态
假如说线程正在执行类加载过程中,那么 java 线程状态会是 RUNNABLE
,不过这并不好模拟。更重要的是,即使是模拟出来,第一行也应该显示为 runnable
。
这就用到了 https://fastthread.io/
的统计功能,因为不止一个线程处于类似的问题状态,这说明并不是我们运气好取到了类加载过程的快照,而是类在加载过程中卡在了这里。
查看相关代码,发现类的静态块里有比较多的逻辑,其中还涉及到从磁盘读取文件的操作,猜测可能是磁盘IO抖动导致类加载变慢,但并没有相关证据。后续的一次发布又出现了同样的问题,而且问题机器并不相同,因此可以排除磁盘抖动的可能性。
类加载死锁
事实上是类加载死锁导致的服务无响应,我们来看下 demo 代码
1 | public class ClassLoadDeadLock { |
这里有两个类:A 和 B。类 A 有一个静态块,它内部会触发类 B 的加载。类 B 内也有一个静态块,它内部则会触发类 A 的加载。
main 方法中先会通过启动线程的方式触发类 B 的 check 方法,然后再在主线程中调用类 A 的 check 方法。
main线程 | B线程 |
---|---|
B.check | |
sleep | |
A.check | |
加载B | |
B.check | |
加载A | |
A.check |
可以看到 main 线程卡在了加载 B 的过程中,B 线程卡在了加载 A 的过程中,两个线程相互等待,导致无法完成类的加载
关于线程堆栈显示不一致问题
前面提到类加载死锁的堆栈中,第 1 行的 in Object.wait()
与第 2 行的 RUNNABLE
不一致,这应该是 jdk 的一个 bug。不过,正因为这个特征,我们也可以用于快速发现类加载死锁问题。
解决方法
上述场景中的循环加载依赖是产生死锁的必要条件,去掉循环依赖即可解决此问题。
此外还可以调整程序执行顺序,让类加载有序进行,避免并发导致的竞争问题。
对于本次问题,我们是通过调整代码的顺序解决的,调整后如下:单线程执行完 A.check() 方法,从而完成类 A、B 的加载
1 | public static void main(String[] args) { |
上面还有一个点没有提到,就是死锁的问题不是必现,而是在某些情况下出现。这是因为在实际项目中,我们的线程 B 不是在主线程中直接启动的,它实际是 mq 的消费者在消费到消息的时候间接启动的。此外,代码执行的过程中也没有 demo 中的 sleep 逻辑。也就是说,当启动时消息消费的 qps 比较高,出现类加载死锁的概率就比较大。这也解释了为什么服务发布过程中偶尔会有一台无响应。
如何快速定位类加载死锁问题
这个才是我们的目的,就是当服务无响应的时候,如何确认是类加载死锁造成的?
如果容易重现,可以在 jvm 启动命令上添加参数 -verbose:class
,用于打印类加载日志,这样在启动后你会看到类似如下的日志
1 | [Loaded com.gorden5566.demos.clazz.ClassLoadDeadLock$B from file:/Users/gorden5566/github/demo/target/classes/] |
然后卡在此处不再打印日志
更进一步,启动后使用 jstack -l <pid>
命令打印 java 线程堆栈,搜索 <clinit>
关键字,查看对应的线程状态,看是否具有如下特征
1 | "B" #12 prio=5 os_prio=31 tid=0x00007fd4e289e800 nid=0x3b03 in Object.wait() [0x000070000497c000] |
到这里就可以确定是类加载死锁
- 2019-02-21
Java 线程共有 6 种状态,在任意时刻只能处于其中一种状态,随着代码的执行状态也会发生变化。