如何解决dbcp连接池连接失效问题

本篇内容主要讲解“如何解决dbcp连接池连接失效问题”,感兴趣的朋友不妨来看看。本文介绍的方法操作简单快捷,实用性强。下面就让小编来带大家学习“如何解决dbcp连接池连接失效问题”吧!

一、问题出现

a.log的错误日志报了mysql的连接问题,时间在16:35分左右

[2016-09-14 16:35:03.643]Last packet sent to the server was 8 ms ago.; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:

[2016-09-14 16:35:03.643]--- The error occurred in sqlmaps/friend/FriendsInviteSQL.xml.

[2016-09-14 16:35:03.643]--- The error occurred while applying a parameter map.

[2016-09-14 16:35:03.643]--- Check the FriendsInvite.getLastInvited-InlineParameterMap.

[2016-09-14 16:35:03.643]--- Check the statement (query failed).

[2016-09-14 16:35:03.643]--- Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

[2016-09-14 16:35:03.643]

[2016-09-14 16:35:03.643]Last packet sent to the server was 8 ms ago.

[2016-09-14 16:35:03.643]       at com.xx.core.dao.msroute.MasterSlaveDatasourceInteceptor.invoke(MasterSlaveDatasourceInteceptor.java:61) ~[MasterSlaveDatasourceInteceptor.class:na]

[2016-09-14 16:35:03.643]       at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[ReflectiveMethodInvocation.class:3.1.2.RELEASE]

[2016-09-14 16:35:03.643]       at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) ~[JdkDynamicAopProxy.class:3.1.2.RELEASE]

[2016-09-14 16:35:03.643]       at com.sun.proxy.$Proxy101.getLastInvited(Unknown Source) ~[na:na]

[2016-09-14 16:35:03.643]       at com.xx.user.friend.manager.FriendsManager.getLastInviter(FriendsManager.java:160) ~[classes:na]

[2016-09-14 16:35:03.643]       at com.xx.user.friend.manager.FriendsManager$$FastClassByCGLIB$$1076743a.invoke(<generated>) ~[classes:na]

[2016-09-14 16:35:03.643]       at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[MethodProxy.class:na]

[2016-09-14 16:35:03.643]       at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:618) ~[Cglib2AopProxy$DynamicAdvisedInterceptor.class:3.1.2.RELEASE]

[2016-09-14 16:35:03.643]       at com.xx.user.friend.manager.FriendsManager$$EnhancerByCGLIB$$8999470e.getLastInviter(<generated>) ~[classes:na]

[2016-09-14 16:35:03.643]       at com.xx.user.controller.newm.NewUserMobileAPIController.getNewTipMsg(NewUserMobileAPIController.java:1977) ~[classes:na]

[2016-09-14 16:35:03.643]       at sun.reflect.GeneratedMethodAccessor104.invoke(Unknown Source) ~[na:na]

[2016-09-14 16:35:03.643]       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_71]

[2016-09-14 16:35:03.643]       at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_71]

随后不断有同样的异常报出,且时间间隔在不断加大,到19:35的时候已经是12175秒了。

[2016-09-14 19:35:52.934]--- Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was12175 seconds ago.The last packet sent successfully to the server was 12175 seconds ago, which  is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:

二、分析排查

1、查看现有配置参数

起初是认为只有a数据库有问题,后来发现b数据库也报这个问题。判断应该是连接池中的连接已经失效的问题。

(1) dbcp连接池的配置:

<bean id="webgame_ds_master" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
    <property name="driverClassName" value="xxx"/>
    <property name="url" value="xxx"/>
    <property name="username" value="xxx"/>
    <property name="password" value="xxx"/>
    <property name="maxActive" value="800"/>
    <property name="maxIdle" value="800"/>
    <property name="maxWait" value="1000"/>
    <property name="defaultAutoCommit" value="true"/>
    <property name="removeAbandoned" value="true"/>
    <property name="removeAbandonedTimeout" value="60"/>
    <property name="logAbandoned" value="false"/>
    <property name="testOnBorrow" value="false"/>
    <property name="testWhileIdle" value="true"/>
    <property name="validationQuery" value="select 1"/>
    <property name="poolPreparedStatements" value="true"/>
    <property name="timeBetweenEvictionRunsMillis" value="100000"/>
    <property name="minEvictableIdleTimeMillis" value="600000"/>
</bean>

(2)mysql数据库配置

mysql数据库dba那边的超时时间设置为1800(30分钟)秒,如果一个连接1800秒没有使用,数据库那边就会断掉。

2、dbcp参数解读:

testOnBorrow=false 表示使用连接池中的连接时,不做检测,这个也是推荐配置,如果设置为true会影响数据库的性能。

testWhileIdle=true  指明连接是否被空闲连接回收器进行检验,如果检测失败,则连接将被从池中去除,和timeBetweenEvictionRunsMillis配合使用。

validationQuery=select 1 SQL查询,用来验证从连接池取出的连接,验证连接是否有效,查询必须是一个SQL SELECT并且必须返回至少一行记录。

timeBetweenEvictionRunsMillis=100000  在空闲连接回收器线程运行期间休眠的时间值,以毫秒为单位,即每100秒做一次idle连接的检测,检测语句为validationQuery。

minEvictableIdleTimeMillis=600000  连接在池中保持空闲而不被空闲连接回收器线程,即idle连接的保存时间为600秒(10分钟)

感觉没有问题,每100秒就会做idle线程的检测,应用的检测时间600秒也小于数据库设置的1800秒的时间,为什么还会有连接失效的异常?且报的连接失效时长越来越长。

3、分析

看dbcp源码看到还有一个参数numTestsPerEvictionRun ,在每次空闲连接回收器线程运行时检查的连接数量,这个参数配置了每100秒检测的idle线程的数量。这个参数我们没有配置,走的是默认值。

protected int numTestsPerEvictionRun = 3;

源码中配置的是3,就是默认每次只检测3个idle线程。

按照最坏的情况,最大的idle线程为800,每100秒执行3个idle线程的判断,判断完所有的idle线程的状态需要 (800/3) * 100秒=26666秒,而数据库的超时是1800秒,这意味着如果池子满了(或者池子中的连接数很多)的话,到所有的idle线程都检测完成,应用是很大概率会取到已经失效的连接的。最早的超时连接应该是在30分钟之后也就是数据库配置的1800秒

4、产生原因

看nginx的访问日志,当时没有这么一个大的量的突然访问会把连接池打满(或者池子中的连接增加很多),访问量正常。

(1)应用在16:00左右有个重启操作按理不会发生这种情况,以前经常以后重启,也不会突然连接池数量上来的。

(2)想到在16:05分左右,查过一次activeMq的运行状态的一个操作,打jstack的时候,导致activeMq挂了,重启了。这时候,应用的量起来了,把线程数拉高了。

(3)看异常的日志第一条在16:35分左右,基本符合这个现象,最短的失效的线程是数据库配置的1800秒,刚好在半个小时之后失效被使用了,报了上述异常。

5、解决

     网上大家的推荐配置是设置numTestsPerEvictionRun=maxIdle,这样一次检测就都可以把失效的idle都移出线程池,避免了一个高峰之后,连接池的连接已经失效的问题。

     鉴于失效的连接会被慢慢的剔除,当时没有做修改配置的操作,之后会把numTestsPerEvictionRun参数配置成和maxIdle一样的值,可以避免这个问题的发生。

到此,相信大家对“如何解决dbcp连接池连接失效问题”有了更深的了解,不妨来实际操作一番吧!这里是亿速云网站,更多相关内容可以进入相关频道进行查询,关注我们,继续学习!