作者:jaymarco
出自:ITPUB博客
原文:blog.itpub.net/28833846/viewspace-2723431/
一、问题描述
15/09/21 与15/09/24, 某移动客户有一套系统客户反馈,在下午15:00~18:00这个时间范围内业务系统访问缓慢,系统始终处于断断续续提供服务的状态;直接影响用户正常使用。平时出现问题通过重启服务来恢复业务,便隔一段时间问题反复发生。介于问题的严重性客户召集了三大厂商(主机,网络,开发商)在一起来定位分析此问题,各大厂商定位了3天还没有查明原因,最后客户请求新炬中间件工程师出面从tomcat中间件找突破口,新炬中间件工程师对中间件进行了一次深度巡检后排除中间件参数问题,最终定位出是网络连接丢弃导致。后来让思科工程师调整防火墙会话连接大小后问题彻底解决。
二、系统环境
操作系统: Red Hat Enterprise Linux Server release 5.8(x86_64)
JDK版本: Java HotSpot(TM) 64-Bit Server jdk1.6.0_43
DB 版本: Oracle 11.2.0.4 RAC
中间件版本: Apache Tomcat/7.0.63
集群:是
三、故障处理过程
1、故障处理过程
1.tomcat 中间件排查
(1)检查tomcat性能参数
(192.168.210.147~192.168.210.153)7台主机的tomcat中间件配置JVM内存、线程池和连接数等参数都满足业务需求。
(2)检查tomcat实时指标监控数据
从以上tomcat中间件指标监控数据来看tomcat内存占用率都在60%以下,线程使用率也不是很高。Tomcat的系统资源还是比较充足的。
(3)tomcat日志分析
从tomcat日志中分析来当时系统并没有产生内存泄露、线程阻塞和连接池过载等现象。但却在故障时间点(下午15点到18:00)之间,均发现主机 192.168.210.147~192.168.210.153这7台主机的tomcat日志文件catalina.out报出大量jdbc driver驱动去连接数据库网络超时异常。错误信息“ IO 错误: The Network Adapter could not establish the connection ”报错日志如下:
java.sql.SQLRecoverableException: IO 错误 : The Network Adapter could not establish the connection
at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:489)
at oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:553)
at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:254)
at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:528)
at java.sql.DriverManager.getConnection(DriverManager.java:582)
at java.sql.DriverManager.getConnection(DriverManager.java:185)
at qt.utils.DBCP.ConnectionPool.CreatePooledConnection(ConnectionPool.java:467)
at qt.utils.DBCP.ConnectionPool.getActiveConnection(ConnectionPool.java:776)
at qt.utils.DBCP.ConnectionPool.prepareStatement(ConnectionPool.java:566)
at cn.qtone.xxt.base.db.DBControl.getValue(DBControl.java:856)
at cn.qtone.xxt.base.utiltity.CheckPurview.getFunctionIdNoCheck(CheckPurview.java:169)
Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:439)
at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:454)
at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:693)
at oracle.net.ns.NSProtocol.connect(NSProtocol.java:251)
at oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1140)
at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:340)
... 37 more
Caused by: java.net.SocketTimeoutException: connect timed out
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
at java.net.Socket.connect(Socket.java:529)
at oracle.net.nt.TcpNTAdapter.connect(TcpNTAdapter.java:149)
at oracle.net.nt.ConnOption.connect(ConnOption.java:133)
at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:405)
... 42 more
分析结论
通过tomcat中间件分析,暂时可以排除tomcat资源不足(内存泄露、线程 阻塞和连接池过载)等问题。
引发出几点思路:
数据库是否有异常,导致中间件跟数据库无法正常交互。
应用服务器到数据库端之间经过的网络是否有问题。
2、数据库排查
1.监听状态正常,会话正常连接,会话数正常,没有超过最大连接数,监听日志没有任何报错。监控数据如下所示:
2.持续观察数据库后台日志,没有出现任何报错信息。
3.抓取故障时间段的AWR,分析数据库的性能,从AWR分析得出数据库运行良好,故障高峰期负载很低。
3、网络监控方法
1.脚本监控
Ping 包没有出现丢包问题。奇怪了。测试端口看一下。
单独拿一台应用服务器到数据库主机来监控,从应用端telnet数据库主机IP加监听端口情况来看,采集到的标红部分数据可以看到应用主机(192.168.210.153)到DB端的网络出现超时3分钟 最后网络不通。监控情况见下图:
监控脚本
#!/bin/sh
while true
do
for target in 57 58
do
ip_add="192.168.205."$target
echo " `date` script starting=====================================" >>/tmp/$ip_add.log
echo -e "n"|telnet $ip_add 1521|grep Connected >>/tmp/$ip_add.log
sleep 1
done;
done;
2.手工监控
从应用端telnet数据库主机IP加监听端口情况来看,发现从应用端telnet检测数据库主机之间的网络,检测6次,总有2次会出现超时问题。也尝试telnet数据库主机的22端口也是出现同样情况。
3.故障原因
经过我们的排查发现tomcat中间件和数据库都正常。只因应用服务器通过tomcat中间件的jdbc驱动去连接数据库时存在连接超时异常。从我们部署网络监脚本采集到的数据来看网络确实存在超时。初步怀疑是应用发起连接请求经过网络层,再到达数据库端,其实在网络层就可能出现延时,并没有到达数据库端,最终导致连接超时无法建立连接。
于是将分析的数据和思路给了网络工程师,网络工程最后才将问题切入点定向网络,网络工程师监控应用端到数据库端之间的防火墙会话连接数不够,出现大量的会话连接丢弃现象。于是网络工程师将应用端到数据库端之间的那台防火墙的会话连接数从原来的30000个调大到60000个。观察防火墙会话一段时间在也没有出现会话丢弃。同时中间件日志再也没有报关于网络连接超时问题了,业务也恢复正常。