【日志】今天的一个性能案例

环境：Solaris+WAS6.1+oracle9i

事发前，昨晚做了系统升级。

现象：

系统变得很慢，后台报了线程挂起。

分析：

1、WAS中的SystemOut.log日志信息如下

[12-4-10 9:17:33:581 CST] 0000003f ThreadMonitor W   WSVR0605W: 线程“Default : 7”（000000ef）已保持活动状态 763744 毫秒，可能被挂起了。服务器中可能总共挂起了 17 个线程。 [12-4-10 9:17:36:736 CST] 00000038 ServletWrappe I   SRVE0242I: [CMP7_7_0] [/] [/admin/ThreadList.jsp]: 初始化成功。 [12-4-10 9:17:45:281 CST] 00000035 ServletWrappe I   SRVE0242I: [CMP7_7_0] [/] [/portal/PerformanceMonitor.jsp]: 初始化成功。 [12-4-10 9:18:11:290 CST] 00000041 UserCallbacks I   HMGR3101I: 队列 1 的工作队列转储阈值已更改为 20000。阈值 void 的数据为 void。 [12-4-10 9:18:14:894 CST] 00000041 UserCallbacks I   HMGR3101I: 队列 1 的工作队列转储阈值已更改为 10000。阈值 void 的数据为 void。 [12-4-10 9:28:40:014 CST] 00000041 UserCallbacks I   HMGR3101I: 队列 1 的工作队列转储阈值已更改为 20000。阈值 10000 的数据为 {com.ibm.ws.recoverylog.spi.RLSHAGroupCallback=2, com.ibm.ws.hamanager.agent.AgentClassImpl=2, com.ibm.ws.drs.ha.DRSAgentClassEvents=9988, com.ibm.ws.hamanager.agent.AgentImpl=8} Last called back: com.ibm.ws.drs.ha.DRSAgentClassEvents#61939 Max depth: 23575。

2、WAS中的SystemErr.log日志信息如下

[12-4-10 9:16:14:621 CST] 00000168 SystemErr     R  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) [12-4-10 9:16:14:622 CST] 00000168 SystemErr     R  at java.lang.Thread.run(Thread.java:595) [12-4-10 9:22:16:536 CST] 00000036 SystemErr     R java.util.ConcurrentModificationException  at java.util.LinkedList$ListItr.checkForComodification(LinkedList.java:617)  at java.util.LinkedList$ListItr.next(LinkedList.java:552)  at com.ibm._jsp._POP3Chart._jspService(_POP3Chart.java:113)  at com.ibm.ws.jsp.runtime.HttpJspBase.service(HttpJspBase.java:87)  at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)  at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1096)  at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1037)  at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:118)  at com.ibm.ws.webcontainer.filter.WebAppFilterChain._doFilter(WebAppFilterChain.java:87)  at com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:832)  at com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:679)  at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:566)  at com.ibm.ws.wswebcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:478)  at com.ibm.wsspi.webcontainer.servlet.GenericServletWrapper.handleRequest(GenericServletWrapper.java:122)  at com.ibm.ws.jsp.webcontainerext.AbstractJSPExtensionServletWrapper.handleRequest(AbstractJSPExtensionServletWrapper.java:226)  at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:90)  at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:748)  at com.ibm.ws.wswebcontainer.WebContainer.handleRequest(WebContainer.java:1466)  at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:119)  at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:458)  at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewInformation(HttpInboundLink.java:387)  at com.ibm.ws.http.channel.inbound.impl.HttpICLReadCallback.complete(HttpICLReadCallback.java:102)  at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)  at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)  at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)  at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:136)  at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:195)  at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:743)  at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:873)  at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1473)

3、分析JavaCore

有大量的等待现场，有死锁，但是都是WAS的相关线程

思考：

怎么会这么多的会话得不到请求呢？

打了电话给IBM800，解释是，我们系统是建立在集群上，集群中使用了策略【内存复制到内存】，现在复制过程出了问题

这个让我更郁闷了，这个策略一直应用着，不至于现在出问题呀。

不过，从javacore中，初步判断是会话出了问题，因为大量的等待的会话线程，头天晚上做了升级，怀疑升级代码出问题了，但是升级的代码中，没有涉及到会话的修改啊。

检查与结论：

既然怀疑会话出问题，就先排除会话吧，把WAS有关会话的设置检查了一遍，没有看到异常。

最后检查到，我们代码的会话设置，果然是会话设置出问题了，在web.xml中

 <session-config>
  <session-timeout>30</session-timeout>
 </session-config>

把原来的30分钟会话过期，被改为了3，导致非常频繁的会话过期，从而导致WAS分布式会话管理服务的超负荷运转，线程挂起。

至于为什么会被改成这样，就不在此讨论了。