一次中间件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文件溢出.

一次中间件BUG的诊断过程

分析工具:MemoryAnalyzer

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

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

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

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

一次中间件BUG的诊断过程

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

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

进一步分析:

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

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

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

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

一次中间件BUG的诊断过程

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

一次中间件BUG的诊断过程

相关推荐