数据库连接池could not inspect JDBC autocommit mode 问题处理

Posted 2022-01-02 niaonao

异常信息

org.springframework.orm.hibernate3.HibernateJdbcException: JDBC exception on Hibernate data access: SQLException for SQL [n/a]; SQL state [null]; error code [0]; could not inspect JDBC autocommit mode; nested exception is org.hibernate.exception.GenericJDBCException: could not inspect JDBC autocommit mode
	at org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:651)
	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:106)
	at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:403)
	at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:59)
	at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:213)
	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:147)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
	at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodIntercceptor.invoke(CrudMethodMetadataPostProcessor.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
	at com.sun.proxy.$Proxy66.getMarketingActivityList(Unknown Source)
	at cn.nascent.smartcrm.executor.service.AddNodeTaskService.getCyclicActivityList(AddNodeTaskService.java:43)
	at cn.nascent.smartcrm.executor.service.AddNodeTaskService$$FastClassBySpringCGLIB$$bea08e31.invoke(<generated>)
	at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:649)
	at cn.nascent.smartcrm.executor.service.AddNodeTaskService$$EnhancerBySpringCGLIB$$e67dffe.getCyclicActivityList(<generated>)
	at cn.nascent.smartcrm.executor.jobhandler.AddNodeTaskHandler.getCyclicActivityList(AddNodeTaskHandler.java:113)
	at cn.nascent.smartcrm.executor.jobhandler.AddNodeTaskHandler$AuthRunTask.run(AddNodeTaskHandler.java:231)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: org.hibernate.exception.GenericJDBCException: could not inspect JDBC autocommit mode
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:126)
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:112)
	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.isAutoCommit(LogicalConnectionImpl.java:325)
	at org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl.afterNonTransactionalQuery(TransactionCoordinatorImpl.java:199)
	at org.hibernate.internal.SessionImpl.afterOperation(SessionImpl.java:503)
	at org.hibernate.internal.SessionImpl.listCustomQuery(SessionImpl.java:1880)
	at org.hibernate.internal.AbstractSessionImpl.list(AbstractSessionImpl.java:311)
	at org.hibernate.internal.SQLQueryImpl.list(SQLQueryImpl.java:141)
	at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:573)
	at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:449)
	at sun.reflect.GeneratedMethodAccessor100.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.orm.jpa.SharedEntityManagerCreator$DeferredQueryInvocationHandler.invoke(SharedEntityManagerCreator.java:311)
	at com.sun.proxy.$Proxy116.getResultList(Unknown Source)
	at org.springframework.data.jpa.repository.query.JpaQueryExecution$CollectionExecution.doExecute(JpaQueryExecution.java:81)
	at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:59)
	at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:97)
	at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:88)
	at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:384)
	at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:344)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136)
	... 17 more
Caused by: java.sql.SQLException: connection holder is null
	at com.alibaba.druid.pool.DruidPooledConnection.checkStateInternal(DruidPooledConnection.java:1120)
	at com.alibaba.druid.pool.DruidPooledConnection.checkState(DruidPooledConnection.java:1113)
	at com.alibaba.druid.pool.DruidPooledConnection.getAutoCommit(DruidPooledConnection.java:718)
	at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.isAutoCommit(LogicalConnectionImpl.java:322)
	... 41 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 28,353 milliseconds ago.  The last packet sent successfully to the server was 1 milliseconds ago.
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
	at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1129)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3720)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3609)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4160)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2617)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2778)
	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2834)
	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2156)
	at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2313)
	at com.alibaba.druid.pool.DruidPooledPreparedStatement.executeQuery(DruidPooledPreparedStatement.java:227)
	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:82)
	at org.hibernate.loader.Loader.getResultSet(Loader.java:2065)
	at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1862)
	at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1838)
	at org.hibernate.loader.Loader.doQuery(Loader.java:909)
	at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:354)
	at org.hibernate.loader.Loader.doList(Loader.java:2553)
	at org.hibernate.loader.Loader.doList(Loader.java:2539)
	at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2369)
	at org.hibernate.loader.Loader.list(Loader.java:2364)
	at org.hibernate.loader.custom.CustomLoader.list(CustomLoader.java:353)
	at org.hibernate.internal.SessionImpl.listCustomQuery(SessionImpl.java:1873)
	... 38 more
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3166)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3620)
	... 58 more

分析处理

问题描述
    定时任务在凌晨 2点报错一次，之后就恢复了。

问题分析
    在使用 connection 时，连接对象为 null, connection holder is null. 由于数据库链接池配置在使用链接对象时，使用耗时较长，导致连接池已经把 connection 提交了，再使用时 connection 已经提交或者断开导致无法连接。

问题解决
    修改连接池配置，根据产品情况调整连接池最大连接数 maxActive 及连接超时时间 removeAbandonedTimeout、等待时间 maxWait。

	<bean id="dataSource" class="com.alibaba.druid.pool.DruidDataSource"
		destroy-method="close">
		<property name="driverClassName" value="com.mysql.jdbc.Driver" />
		<property name="url" value="jdbc:mysql://127.0.0.1:3306/smartcrm" />
		<property name="username" value="root" />
		<property name="password" value="root" />
		<property name="initialSize" value="10" /><!-- 在连接池中初始化多少个连接,建议10-50个-->
		<property name="maxActive" value="100" /><!-- 连接池中最多支持多少个活动对话连接 -->
		<property name="maxWait" value="120000" /><!-- 程序向连接池中请求连接时,超过 maxWait 的值后，认为本次请求失败 -->
		<property name="defaultAutoCommit" value="true" /><!-- 事务自动提交 -->
		<property name="testWhileIdle" value="true" /><!-- 当程序请求连接池,在分配连接时,是否先检查该连接是否有效 -->
		<property name="timeBetweenEvictionRunsMillis" value="30000" /><!-- 检查空闲连接的频率/毫秒 -->
		<property name="testOnBorrow" value="false" /><!-- 获取连接时,进行连接有效性检查,效率较低 -->
		<property name="testOnReturn" value="false" /><!-- 返还连接时,进行连接有效性检查,效率较低 -->
		<property name="removeAbandoned" value="true" /><!-- 从连接池中获取连接后,多少秒后必须关闭连接,否则会强制回收,防止进程强占连接 -->
		<property name="removeAbandonedTimeout" value="300" /><!-- 强制回收连接超时时长上限/秒 -->
		<property name="logAbandoned" value="true" /><!-- 强制回收连接后,是否将 stack trace 记录到日志中 -->
		<property name="validationQuery" value="SELECT 1" /><!-- 检查连接池连接是否可用的 SQL -->
	</bean>

参考阅读

could not execute query 解决方法
druid 参数配置详解