服务器宕机排查记录

 

问题症状：服务器内存占用持续增长，性能低下，并发上不去，隔几天宕机

排查思路：分析出内存泄露模块，分析出性能瓶颈，调优JVM

使用工具：jconsole、jprofiler

 

使用jconsole连接，经过测试得到如下图表，可能为JVM配置不当或内存泄露

通过thread dump发现线程大都阻在HTTPCLIENT获取连接方法上，经分析可能为HTTPCLIENT连接未及时释放

问题一：HTTPCLIENT连接没有真正释放

THREAD DUMP日志

  "[ACTIVE] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)'" id=50 idx=0xbc tid=1596 prio=5 alive, in native, waiting, daemon
         
                -- Waiting for notification on: org/apache/commons/httpclient/MultiThreadedHttpConnectionManager$ConnectionPool@0x03801D20[fat lock]
         
                at jrockit/vm/Threads.waitForNotifySignal(JLjava/lang/Object;)Z(Native Method)
         
                at java/lang/Object.wait(J)V(Native Method)[optimized]
         
                at org/apache/commons/httpclient/MultiThreadedHttpConnectionManager.doGetConnection(MultiThreadedHttpConnectionManager.java:518)[optimized]
         
                ^-- Lock released while waiting: org/apache/commons/httpclient/MultiThreadedHttpConnectionManager$ConnectionPool@0x03801D20[fat lock]
         
                at org/apache/commons/httpclient/MultiThreadedHttpConnectionManager.getConnectionWithTimeout(MultiThreadedHttpConnectionManager.java:416)[optimized]
         
                at org/apache/commons/httpclient/HttpMethodDirector.executeMethod(HttpMethodDirector.java:153)[optimized]
         
                at org/apache/commons/httpclient/HttpClient.executeMethod(HttpClient.java:397)[optimized]
         
                at org/apache/commons/httpclient/HttpClient.executeMethod(HttpClient.java:346)[inlined]

解决办法：释放连接，为了避免产生大量CLOSE_WAIT，定期关闭空闲连接：

httpMethod.releaseConnection();

connectionManager.closeIdleConnections(3000);

问题二：JVM调优，开启JMX服务，使用JCONSOLE连接

SUN JDK

-Xms1024m -Xmx1024m -Xss192k -XX:PermSize=192M -XX:+UseParallelGC -XX:ParallelGCThread=8 -Djava.rmi.server.hostname=172.30.0.232 -Dcom.sun.management.jmxremote.port=7001 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false

【调优后】

服务器经过72小时的压力测试，线程数增加了100个，服务器内存增加了50M，总访问次数291万次，我们判断服务器目前运行正常，今天主要分析了线程数和内存增加的原因。

       从内存占用情况来看，内存最低能释放到170M左右，之前是120M左右，增长了50M左右
        

   从线程图表上看，有过两次线程增长，且堆栈内存占用都有增加，但是这次的线程数增长和上次不一样，我们的依据是Thread Dump抓包分析、日志分析、console后台分析，上次是由于tmp下文件过多，导致读取本地文件出现IO超时，而导致线程数急剧增长（400个）；而这次应该是由于网络问题（ERR日志中有一些Read Time Out异常）而导致某时段内网络出现阻塞，weblogic的线程管理器进行了自动优化，增加一些线程，另外单个HOST最大只能创建100个连接，也与这次线程增长数吻合，线程增长，栈内存增长（20M左右），线程中用到对象实例，堆内存自然增长（50M左右），似乎也合理，依据此我们判断目前服务器运行正常。

     

   从LoadRunner图表来看，周末网络情况似乎不错，TPS能到16，响应时间也在2S内，比上次图表好看，依然是凌晨的网络比白天的好
    
       

问题三：内存泄露

通过JMAP命令分析发现jtidy存在内存泄露，经过分析发现时在在异常时没有释放资源

1371376      164565120  org.w3c.tidy.Node3

1413005      169560600  org.w3c.tidy.Node

1437838      172540560  org.w3c.tidy.Node

问题四：连接数暴涨，分析发现磁盘已满

问题五：性能瓶颈，通过JPROFILER分析，找出消耗时间最多的方法，进行优化

分析发现，字符串操作耗时大，XSLT解析XML耗时大，优化，合理使用缓存

问题六：数据库连接达到上限

####<2011-8-25 上午08时21分07秒 CST> <Info> <Console> <RD-DCM-03> <AdminServer> <[ACTIVE] ExecuteThread: '32' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <> <1314231667171> <BEA-240002> <Struts module /core is configured to use com.bea.console.internal.ConsolePageFlowRequestProcessor as the request processor, but the <controller> element does not contain a <set-property> for "controllerClass".  Page Flow actions in this module may not be handled correctly.>
####<2011-8-25 上午08时21分07秒 CST> <Info> <Console> <RD-DCM-03> <AdminServer> <[ACTIVE] ExecuteThread: '32' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <> <1314231667171> <BEA-240001> <Attempting to instantiate SharedFlowControllers for request /console/core/CoreServerThreadStackDump.do>
####<2011-8-25 上午08时21分07秒 CST> <Info> <Console> <RD-DCM-03> <AdminServer> <[ACTIVE] ExecuteThread: '32' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <> <1314231667171> <BEA-240001> <<ConsoleInteraction: User is viewing <com.bea.console.actions.core.server.ThreadStackDumpAction> for <Server> <com.bea.console.handles.JMXHandle%28%22com.bea%3AName%3DAdminServer%2CType%3DServer%22%29>>>
####<2011-8-25 上午08时21分17秒 CST> <Info> <Common> <RD-DCM-03> <AdminServer> <[ACTIVE] ExecuteThread: '26' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1314231677484> <BEA-000627> <Reached maximum capacity of pool "dcm", making "0" new resource instances instead of "1".>
####<2011-8-25 上午08时21分17秒 CST> <Info> <Common> <RD-DCM-03> <AdminServer> <[ACTIVE] ExecuteThread: '27' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1314231677500> <BEA-000627> <Reached maximum capacity of pool "dcm", making "0" new resource instances instead of "1".>

JDBC连接池到达极限，设置JDBC Connection Max Capacity

问题七：其他问题

使用jps查看java进程id时，显示process informatin unavailable，且jstat无法连接，即无法图形化查看JVM运行情况，对排查问题造成不便，排查发现是管理员帐号中存在"_"，最后更换管理员帐号启动脚本，正常