最近,Telsa-Gateway直销网关在生产部署时发现一个很奇怪的问题。
问题描述如下:部署时,部分节点启动不起来,但日志中无任何报错,程序也始终处于启动状态,而CPU和内存资源都占用特别少。通过工具查看线程堆栈发现,主线程是BLOCKED状态在等待锁资源,但该锁的持有线程状态却是RUNNABLE,线程Dump中也没有检测到明显的死锁信息,紧张的上线夜,老板的注视,消失的死锁……
当然,最终还是顺利解决了此问题,那么,这个问题的罪魁祸首到底是谁?谁害得我们如此慌张?最后分析结果为netty epoll自身的缺陷。Telsa-Gateway最新版本使用了netty epoll方式进行IO多路复用,相对select轮询方式,在IO效率上有较大的提升。
但由于netty (版本号4.1.9-Final) 在epoll的Native代码中 (C语言操作系统相关实现) 反向调用了java.io.NetworkInterface类,因此在并行进行类加载时导致了对应的classloader死锁。且由于classloader比较特殊,死锁发生时线程状态不会显示为BLOCKED,且线程dump里也看不到这把锁的存在。
Netty官方对此bug进行了修复,通过升级netty版本到4.0.54.Final版本,或者改进程序提前进行NetworkInterface类的加载即可解决上述问题。目前我行只有直销网关使用了此问题版本,因此生产上其他网关不存在这个问题。
本 文,我们将分析、验证、解决问题的过程做详细描述,分享给大家。
Part 1: 问题分析
当网关有两个节点不能正常启动,而其他几个节点能够正常启动时,我们首先怀疑以下几种可能性:
环境问题:JDK或操作系统版本不一致;
并发问题:Netty是典型的异步框架,主线程和netty线程在启动时不排除会存在资源竞争情况,导致死锁;
此现象是确定性发生、还是偶发现象?在其他正常节点是否也可复现?为什么在测试环境频繁的启动中没有发现此问题?
由于网关生产环境各个节点是同一批次创建的,因此我们在比对了JDK和操作系统版本没有差异后,觉得环境问题的可能性不大。 为了保留第一现场,我们先通过VisualVM工具抓取线程堆栈进行分析。 有疑点的两个线程堆栈如下所示:
"gateway" - Thread t@1
java.lang.Thread.State: BLOCKED
at java.lang.Runtime.loadLibrary0(Runtime.java:841)
- waiting to lock <74f6ce4> (a java.lang.Runtime) owned by "pool-11-thread-5" t@28
at java.lang.System.loadLibrary(System.java:1088)
at sun.security.action.LoadLibraryAction.run(LoadLibraryAction.java:67)
at sun.security.action.LoadLibraryAction.run(LoadLibraryAction.java:47)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.NetworkInterface.<clinit>(NetworkInterface.java:56)
at com.tesla.monitor.client.utils.NetworkInterfaceManager.load(NetworkInterfaceManager.java:102)
"pool-11-thread-5" - Thread t@28
java.lang.Thread.State: RUNNABLE
at io.netty.util.NetUtil.<clinit>(NetUtil.java:166)
at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary1(ClassLoader.java:1965)
- locked <29a773bd> (a java.util.Vector)
- locked <309f92a8> (a java.util.Vector)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1890)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1851)
at java.lang.Runtime.load0(Runtime.java:795)
- locked <74f6ce4> (a java.lang.Runtime)
at java.lang.System.load(System.java:1062)
at io.netty.util.internal.NativeLibraryUtil.loadLibrary(NativeLibraryUtil.java:36)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at io.netty.util.internal.NativeLibraryLoader$1.run(NativeLibraryLoader.java:272)
at java.security.AccessController.doPrivileged(Native Method)
at io.netty.util.internal.NativeLibraryLoader.loadLibraryByHelper(NativeLibraryLoader.java:264)
at io.netty.util.internal.NativeLibraryLoader.loadLibrary(NativeLibraryLoader.java:252)
at io.netty.util.internal.NativeLibraryLoader.load(NativeLibraryLoader.java:226)
at io.netty.channel.epoll.Native.loadNativeLibrary(Native.java:269)
at io.netty.channel.epoll.Native.<clinit>(Native.java:64)
从线程堆栈来看,主线程BLOCKED的原因是因为在调用java.lang.Runtime.loadLibrary0()方法时,一直在等待pool-11-thread-5持有的锁,loadLibrary0()是被synchronized关键字修饰的,也就是说主线程在等待Runtime对象锁。我们回头来看pool-11-thread-5的线程堆栈,其中有几个需要特别关注的点:
线程状态是RUNNABLE;
线程当前正要执行io.netty.util.NetUtil类的class init工作;
线程曾经通过java.lang.Runtime.load0()方法,获取到了Runtime对象的锁,而主线程正在等待此锁被释放;
如果两个线程相互在等待对方持有的资源,这个时候死锁就会发生,此时使用jstack命令也会打印出死锁的统计信息和详情,例如”Found one Java-level deadlock”。 但是在我们的线程堆栈里,pool-11-thread-5是可运行状态,并没有被block,那到底发生了什么会导致线程一直被卡在NetUtil的类初始化上呢?
分析线程堆栈里的相关源码可以发现,NetUtil类的static代码块里调用了java.net.NetworkInterface,而我们主线程也是在调用java.net.NetworkInterface的类初始化中发生了死锁,同一个类只会被classloader加载一次,为什么这个类被同时加载了呢?至此我们可以得出以下结论:
很可能是多线程导致的死锁问题,如果这个猜测成立,那么启动成功或者失败是偶发的,重试几次一般也能够复现此问题;
此问题一定与java.net.NetworkInterface类有关,因为主线程被block在了此类的初始化中,而netty线程调用的NetUtil类的静态代码块,也调用了NetworkInterface;
此问题跟classloader的类加载相关,因为主线程和netty线程都是在类的初始化class init里;
是时候展示搜索技术哪家强了,我们使用关键字”netty classloader deadlock”进行搜索,结果如下:
上述Issue (https://github.com/netty/netty/issues/7458) 同我们的现象虽然不完全一致,但非常相似。通过详细分析,我们意识到在分析堆栈时忽略了classloader在进行类初始化时也会加锁,只是这个锁在线程堆栈里没有显示。按照上述资料,我们结合线程堆栈还原了死锁发生的情况。其中红色标注的位置,Epoll的C语言实现里,通过 (*env)->FindClass(env, netty_unix_util_prepend(packagePrefix, "io/netty/util/NetUtil")) 反向调用了NetUtil类,是导致死锁的根源。
问题的根源基本查明,但是还有两个疑问
其实JAVA在类加载时是会持有当前类加载对象的锁后,才会调用ClassLoader.loadClass来加载类,不过遗憾的是因为这把锁不是java层面来显示加载的,因此我们在jstack线程dump里看不到这把锁的存在。 当使用NetWorkInterface类时,正常的加载顺序是先获取classloader锁进行类初始化,再获取Runtime对象锁调用本地JNI代码。 但由于netty epoll JNI代码里又反向调用了JAVA的NetWorkInterface类,导致这种常规的加锁方式被打破,死锁发生。 而且由于classloader的特殊性,从线程堆栈并不能明显检测到死锁现象。
我们猜测是测试环境和生产环境资源环境,尤其是CPU计算资源的不同导致。 系统启动时同一个类只会被加载一次,计算能力较差的情况下可能会导致两个线程恰好同时进行类加载的概率很低。 由于epoll方式只能在linux环境下进行验证,所以为了复现此问题,我们可以通过远程Debug的方式,按照上述堆栈分析步骤,人为在测试环境复现此问题。 具体步骤如下:
1. 远程linux服务器的jmv参数里增加如下启动命令:
-Xdebug -Xrunjdwp:transport=dt_socket,address=6666,server=y,suspend=y
当程序出现”Listening for transport dt_socket at address: 6666”时,表示服务器已就绪。
2. 打开STS “Debug Configuration”,增加”Remote Java Application”,输入远程服务器的 地址和端口,进行调试;
3. 根据断点和线程堆栈,人为控制线程的执行顺序,复现上述问题。
Part 2: 解决方法
查明原因后,此问题的修复就非常简单了。第一种方式是直接升级netty的版本。第二种方式是提前进行NetworkInterface类的加载,避免同epoll的类加载并行进行。
本次使用NetworkInterface类的,是我们新增的一个Tesla监控模块,考虑到生产环境进行netty版本的升级需要进行充分测试,因此我们将这个模块的加载顺序提前,即可避免classloader并行加载NetworkInterface导致的死锁问题,风险最小。因此我们暂时采用这种方式回避死锁问题。
接下来我们看下netty官方对于此问题修复的备注和代码, native代码里已经不再反向调用NetUtil类,而是使用一个环境变量替代原来的功能。同时,Socket的初始化也放在了调用native之后进行。从而避免在native中反向调用java类。
Part 3: 修复计划
本次出现的死锁问题,发生在netty epoll和主线程调用监控模块之间。Tesla-Gateway在1.1.0-RELEASE版本引入了epoll的IO方式,因此目前只1.1.0-RELEASE版本、1.1.1-SNAPSHOT版本可能存在启动时死锁现象。但由于这两个版本发布时间短,除服务治理网关平台外没有其他用户使用,因此网联网关、openAPI网关等生产用户不受影响。
Tesla-Gateway 1.1.0-RELEASE版本没用用户使用,因此我们会废弃此版本,并将netty升级到4.0.54.Final后发布1.1.1-RELEASE版本。
Part 4: 名词解释
Epoll在Linux2.6内核正式提出,是基于事件驱动的I/O方式。 由于传统select方式需要大量拷贝fd_set,并且需要不断遍历监听列表,因此epoll这种基于事件响应的方式在效率方面会更具优势。 Netty的EventLoop最常用的实现就包括NIOEventLoopGroup和EpollEventLoopGroup。
JNI是Java Native Interface的缩写,它提供了若干的API实现了Java和其他语言的通信 (主要是C&C++) ,其最终生成的动态链接库可以通过JAVA提供的System.loadLibrary()方法进行加载。在JNI代码中反向调用JAVA类,可能打破JAVA正常的获取锁的顺序,导致死锁。
<clinit>方法负责类变量初始化及静态初始化,且只能被jvm在类初始化阶段(Class Init)调用。通常创建实例(包括new、反射、反序列化等方式)、调用静态代码、初始化子类时,都会触发classloader进行类加载。类加载会对classloader加锁,以保证类只会被初始化一次。JDK1.7引入parallel capable class loader,锁的粒度从classloader变成了(classloader+className),缩小了锁的粒度。按照经验,虽然在线程堆栈里能够看到<clinit>方法,但是并不能看到加锁动作,而且在获取不到锁时线程状态依然是RUNABLLE。
Thanks!
作者简介:
于艳锋,民生银行基础技术板块,服务治理网关负责人。