一次线上tomcat无响应问题排查

问题描述

前段时间线上遇到个问题,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.

  1. 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.
  2. 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中这个问题早已修复,只是因为我们用的低版本,这个问题仍然存在。

# 技巧 

评论

test : test
Your browser is out-of-date!

Update your browser to view this website correctly. Update my browser now

×