问题描述
前段时间线上遇到个问题,nginx检测检查发现某个结点上tomcat部署的应用不可用就停止转发请求了,不过还有集群其它机器支撑,没对业务造成什么影响。
记得以前相同的问题也出现过一次,因为当时较忙临时重启就正常了,也没认真去查明原因。既然再次又出现了,那还是查查原因吧。
问题排查
查看进程,tomcat的进程是存活的。
查看应用日志,那些调用外部系统日志都正常,这就说明不是内存爆了或都cpu耗尽等外部原因。
进一步排查nginx检测的url:
curl http://xxx/status
没有发现任何异常信息,但tomcat对于客户端请求没有响应,一脸懵B了~
继续curl其它地址,也是相同的现象,初步判断是应用不处理请求了,百思不得其解~
继续查,这次是查看堆栈了,总算发现问题有异常现象了
jstack pid
满屏都是BLOCKED状态的线程,共1024个,刚好是tomcat配置的最大连接线程数,看来都阻塞在这里,把tomcat线程给耗尽了
"http-bio-8185-exec-1024" daemon prio=10 tid=0x00007f55bcd6d000 nid=0x66e1 waiting for monitor entry [0x00007f54faaab000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.xxx.yyy.zzz.ProductKeywordChecker.check(ProductKeywordChecker.java:82)
- waiting to lock (a java.lang.Object)
at com.xxx.yyy.zzz.ProductKeywordChecker.check(ProductKeywordChecker.java:171)
定位到ProductKeywordChecker这个类,发现里面有段同步代码,
synchronized(lock){// 这里加锁是不想被多次初始化
targetKeywordChecker = targetCheckers.get(targetId);
if(targetKeywordChecker == null){ // 如果不存在那么会不停的尝试初始化,直到存在为止
getData(xxx); //请求外部服务进行初始化
...
}
}
继续跟踪getData方法,里面有用到 InetAddress.getLocalHost()来获取本机地址信息,同时在堆栈信息看到如下信息:
"handler.scheduler" daemon prio=10 tid=0x000000004514b000 nid=0x7c2 runnable [0x00007f55b5e88000]
java.lang.Thread.State: RUNNABLE
at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
at java.net.InetAddress$1.lookupAllHostAddr(InetAddress.java:876)
at java.net.InetAddress.getAddressFromNameService(InetAddress.java:1229)
at java.net.InetAddress.getLocalHost(InetAddress.java:1399)
- locked (a java.lang.Object)
at xxx.yyy.zzz.config.DataUpdater.getHostInfo(DataUpdater.java:184)
这里这个线程只是两分钟一次的定时任务,连续查看了几次堆栈,这个线程一直都是locked,。由于仔细想想lookupAllHostAddr()也就获取下本地ip信息,理论应该不需要耗多少时间,怎么可能一直停在这里,应该是有问题的。
以前没遇到过这种问题,也只能报着猜测的心态去google,果然找到了答案。
具体原因
https://wiki.zimbra.com/wiki/Configuring_for_IPv4
There are some known problems with applications trying to use IPv6, when the environment is really only configured for IPv4.
- IPv6 changes the way that Round-Robin A-records are used, and instead forces an ordered priority weighting of A-records. This can cause high-availability techniques dependent on round-robin A-records to fail or work incorrectly. If using IPv4/IPv6 dual-stack, then the JVM will use getaddrinfo() instead of gethostbyname(). getaddrinfo() will sort the DNS results in an ordered way, due to RFC 3484 [1]. Some OSs provide /etc/gai.conf configuration options in an attempt to configure record handling.
- The JVM can be blocked by an infinite loop problem between the JVM and libc when using the IPv6 getaddrinfo() libraries with IPv4 addresses.
如果操作系统开启了IPv4/IPv6双栈,java会优先使用ipv6, 所以在上面日志里看到 Inet6AddressImpl.lookupAllHostAddr(Native Method) ,而不是,然而这里在一定条件下会触发Java与libc间的一个bug,导致进入死循环或死锁。
这就可以解释通今天线上遇到的问题:
getData(xxx) 里调用 Inet6AddressImpl.lookupAllHostAddr(Native Method) 进入死循环或死锁,一直没有返回,而getData(xxx)又在同步代码区,导致其它线程都阻塞在门外,慢慢耗尽了tomcat的线程池,就不再对新请求做出响应
解决文案
按网上的解决方案,在应用启动参数里加上:
-Djava.net.preferIPv4Stack=true
因为这个线上问题出现的比较偶然,也只在同一台机器上出现过,也没法复现,只能先这样处理。不过现在过去一个多月,没有再出现过。
https://sourceware.org/bugzilla/show_bug.cgi?id=12926#c4
从这里我们可以看到,其实这个问题在2011年的时候都有人报过bug,只是官方一直没有处理,直到2014年才修复,glibc 2.21 (2015-02-06) 才正式发布。
查看了下服务器的glibc版本,确实还是使用未修复前的版本。
ldd –version
ldd (Debian EGLIBC 2.11.3-4) 2.11.3
后记总结
1、在遇到实际问题后,有时找不出原因,就会开始猜疑了,甚至是对一些自己以前的知识理解表示怀疑;
2、对于一些公认的工具也要有适当的质疑,比如这次遇到的问题,就是运行环境里的glibc问题。按我们常规的思维,总觉得的都是经过长期实践检验,如果有什么坑,其它人早就遇到,早就有人修复了。可是却忽略了应该具体问题具体分析。就像这次线上的环境一样,高版本的glibc中这个问题早已修复,只是因为我们用的低版本,这个问题仍然存在。