花钱的年华

江南白衣,公众号:春天的旁边

记一次ClassLoader死锁,及近距离感受R大

| Filed under 技术

死锁,通常都是别人的故事,从未想过会发生在自己身上。

今天不光遇见了死锁,还第一次享受了JVM界顶级大佬R大(RednaxelaFX,知乎问题:R大是谁 ) 的手把手指导,特别有意义,所以给各位看官一记。

感受之一: R大乐于助人的程度,中美互联网加起来也没有几个能比得上。
感受之二: R大的脑容量和打字速度都是别人的七八倍,有人直接认为R大其实是代码成精变的。
感受之三: 在基础架构部这种地方,瞎蒙的运气,强大的观察力,专业的技能,都那么重要。

 

第一回合

今天把JMeter里的Netty也换成Netty Native模式,然后压测就停在那不动了。。。。。。

第一时间jstack,得到如下输出,看到Netty在加载Native库时, Object.wait() [0x00007fb274057000]被锁住了。 同时有一个在JMX里注册Metrics的线程成为了受害者,Netty的线程锁住了它所需要的”java.lang.Runtime<0x00000000ecee76e0>"

马上想看看这个Object.wait() [0x00007fb274057000]是啥。

同事建议用jstack -m pid再看看,结果那条线程的输出如下,还是没看出来所以然。

 

第二回合

此时就只好群里找R大求救。。。。R大在大洋彼岸晚饭中,让我用Sun的JDK自带的CLHSDB看看。

于是一边学习R大的文章借HSDB来探索HotSpot VM的运行时数据 ,一边生成CoreDump (先ulimit -c unlimited,再运行jmeter,再kill -7 pid, 就会在程序目录里有一个core.xxx文件)。

可惜真的不会用CLHSDB,whatis 0x00007fb274057000 说无效地址。

第三回合

于是决定蒙一下,虽然JMX那条线程在jstack看起来只是受害者,但还是尝试把它禁止掉。翻代码翻到一个启动参数,感谢那个留了后门的同事,加上去一试,不锁了。。。。

赶紧把这个结论告诉负责Metrics模块的同事,然后,他很快就找到了原因,注册JMX那线程的栈里有一句:

at sun.nio.ch.FileChannelImpl.(FileChannelImpl.java:1171)

然后,Netty的epoll代码里也有一句:

jclass fileChannelCls = (*env)->FindClass(env, "sun/nio/ch/FileChannelImpl")

应该就是这两句之间锁了。问同事怎么这么快定位到FileChannelImpl头上的,同事说先看Netty的对应代码,再人肉一句句对jstack的输出。

 

第四回合

把结论告诉R大,此时R大已经有空了,就开始手把手教学--如何用gdb来找到这个问题,避免下次还要靠瞎蒙与肉眼观察来解决。

1.用gdb打开coredump

gdb [path of Java] core.xxx

因为要用一模一样的executable(java),所以core.xxx拿回家玩没用,必须就地打开。

2.找到对应的线程

jstack里的线程号是16进制的,先转回10进制,再对应回gdb里的线程号,这里Netty的线程号是17, jmx是56。

3. 进入Netty线程

(gdb) thread 17
[Switching to thread 17 (Thread 0x7fac9ce2c700 (LWP 35366))]#0 0x00007fad2932b5bc in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0

4.打印栈帧

jstack -m 里看到的在这里展开了。

5.进入第7层 Netty Epoll的JNI_OnLoad()函数

(gdb) frame 7
#7 0x00007fac9c404b23 in JNI_OnLoad () from /apps/svr/jmeter/native/libnetty-transport-native-epoll3448157366930317836.so

6. 列出20条指令

厉害的R大这里继续让我输入
(gdb) p (char*) 0x7fac9c4057ac
$2 = 0x7fac9c4057ac "sun/nio/ch/FileChannelImpl"

证明的确是加载"sun/nio/ch/FileChannelImpl”这个类锁了。

一头雾水的问,怎么知道要打印0x7fac9c4057ac??
R大解析,有个箭头的地方表明指令执行到这里,是调用方法的指令,再之前就是传递参数的语句,rsi是传递第二个参数的寄存器,所以# 0x7fac9c4057ac的注释就是char*的地址,遂打印之。

如果有debug info,可以采用更简单的方法查看,但明显发行版的JDK里不会有,No symbol table is loaded。

收获满满,下次遇到Natvie里的ClassLoader死锁问题也能GDB之了。

 

结论

原来因为程序里的两句代码:1. Netty异步建立连接,2.同步注册一个连接池Metrics的MBean。此时Netty因为要加载Native Lib,hold住了java.runtime,然后在JNI代码里尝试去加载FileChannelImpl类。同一时刻,JMX注册的进程先加载了FileChannelImp类,然后在某一步又尝试去获得java.runtime,传说中的死锁就这样发生了。

改进的方法很简单,尽早把JMX的MBean Server简单加载一下就好。

再次感谢R大和我的同事国忠。

转载请保留链接: http://calvin1978.blogcn.com/articles/classloader-deadlock.html

这么枯草的文章,配个图吧。

发表评论

您的电子邮箱不会被公开。

您可以使用这些 HTML 标签和属性: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>