一次中间件BUG的诊断过程

       俺们ESB生产环境出现系统故障,个别Jboss应用服务器部署的应用出现404错误,检查JBOSS系统日志

发现WAR应用被JBOSS卸载,卸载原因为操作系统打开文件数过多.

日志如下:

2015-01-10 10:08:40,936 ERROR [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 2) JBAS015004: Caught exception writing deployment marker file /opt/jboss/standalone/deployments/OpenESBHttp_full_prd.war.isundeploying: java.io.FileNotFoundException: /opt/jboss/standalone/deployments/OpenESBHttp_full_prd.war.isundeploying (Too many open files) 

at java.io.FileOutputStream.open(Native Method) [rt.jar:1.7.0_25] 

at java.io.FileOutputStream.<init>(FileOutputStream.java:212) [rt.jar:1.7.0_25] 

at java.io.FileOutputStream.<init>(FileOutputStream.java:165) [rt.jar:1.7.0_25] 

通过查看操作系统的Java进程打开文件数据lsof -p [javapid] | wc -l 数量达到4W以上,大部分为以下的

文件句柄:

java    1378 jbossuser  306w  FIFO                0,8      0t0 1367483479 pipe

java    1378 jbossuser  308r  FIFO                0,8      0t0 1367483480 pipe

java    1378 jbossuser  309w  FIFO                0,8      0t0 1367483480 pipe

pipe句柄文件源自于Java NIO :

sun.nio.ch.PollSelectorImpl

sun.nio.ch.EPollSelectorImpl

每个SelectorImpl会生产两个pipe缓冲文件,一个用于读一个用于写.

通过heapdump查看内存中的PollSelectorImpl有创建一对pipe文件,但过一段时间后对象消失但

pipe文件仍然存在,因些诊断为PollSelectorImpl生成的pipe文件溢出.

分析工具:MemoryAnalyzer

如果所示,通过pipe文件的文件号可以在MemoryAnalyzer的OQL中查询到某个具体对象实例,系统运行一段

时间后再生产heapdump文件,观察对象是否消失.

诊断到由于PollSelectorImpl对象补GC但pipe文件没有关闭,我们就要定位PollSelectorImpl在何时会创建.

我们采用了一个比较笨但却很快的方法,直接修改JDK,在PollSelectorImpl的构造函数中运行了当前系统的dumpStack方法

源头找着了,在我们的异步Servlet返回客户端响应报文的时候有创建PollSelectorImpl,但是为什么PollSelectorImpl会

被GC呢,应该是创建它的线程被回收了,果然通过javacore发现HttpServiceHandler-921线程被创建后过一段时间就被销毁.

进一步分析:

我们的业务代码是通过Jetty的异步HttpClient调用其它系统,然后给客户端以返回.

HttpClient有一个线程池负载处理http的请求与回调.(org.eclipse.jetty.util.thread.QueuedThreadPool)

这个线程池是个可伸缩的,当并发请求高的时候可以创建更多的线程直至达到线程池最大值,

当系统空闲时,某个线程空闲后达到一个Idle超时时间时,该系统会被从线程池中remove掉,也就会随之被GC

至些我们检查了我们异步Servlet3.0的用法,查阅了众多资料,异步Servlet3.0中用新的线程去回写response也是个普遍的用法,

相关的demo也没有特别的处理.

问题还是集中到了Jboss中件间来了.

定位到PollSelectorImpl创建者org.xnio.nio.NioXnio

NioXnio创建了PollSelectorImpl,这个Selector保存在了ThreadLocal中,所以前面提到的线和回收了PollSelectorImpl自然也

会被回收,但回收是回收了,可没有关闭pipe文件啊.

问题原因基本清晰了.咋解决呢?去修改JBOSS原码?算了吧.

提交一个BUG到JBOSS社区吧.

https://issues.jboss.org/browse/WFLY-5731

 

 

 

红帽的工程师果然敬业,程序员小哥,在我提了两分钟之后就给了回复.

不过说了些套话,让咱更新到最新的JBOSS试试.

好吧.试试就试试.

问题依旧,呵呵.

继续

出来个工头说这个问题参考XXX问题解决bla bla ...,他哪晓得那个问题也是咱提的,现在是新的问题.

好吧.我原问题的分析过程和原因一五一十地摊开了讲了.

然后

那个工头果然是工头当天就写了fix,更新了代码,我们拿到代码重新编译,更新到我们系统,问题就这样解决了.最终这个FIX也被更新到了它的 XNIO 3.3.3版本中.