c3p0数据库连接池死锁问题和mysql重连，连接丢失

最近项目中用的C3P0连接池出现各种bug，现在记录一下。1、经常报连接池死锁2016-08-31 15:24:00 [ WARN] - [com.mchange.v2.async.ThreadPoolAsynchronousRunner|run] - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@74

西楚小羽的窝窝

12221人浏览 · 2016-08-31 21:37:53

西楚小羽的窝窝 · 2016-08-31 21:37:53 发布

c3p0参数解释

#最常用配置
#initialPoolSize：连接池初始化时创建的连接数,default : 3，取值应在minPoolSize与maxPoolSize之间
c3p0.initialPoolSize=10
#minPoolSize：连接池保持的最小连接数,default : 3
c3p0.minPoolSize=10
#maxPoolSize：连接池中拥有的最大连接数，如果获得新连接时会使连接总数超过这个值则不会再获取新连接，而是等待其他连接释放，所以这个值有可能会设计地很大,default : 15
c3p0.maxPoolSize=50
#acquireIncrement：连接池在无空闲连接可用时一次性创建的新数据库连接数,default : 3
c3p0.acquireIncrement=5
#管理连接池的大小和连接的生存时间
#maxIdleTime：连接的最大空闲时间，如果超过这个时间，某个数据库连接还没有被使用，则会断开掉这个连接。如果为0，则永远不会断开连接,即回收此连接。default : 0 单位 s建议：不能设置太短，否则连接会被频繁的丢弃。
c3p0.maxIdleTime=600
#idleConnectionTestPeriod：每900秒检查所有连接池中的空闲连接
c3p0.idleConnectionTestPeriod=900
#重连相关配置
#acquireRetryAttempts：连接池在获得新连接失败时重试的次数，如果小于等于0则无限重试直至连接获得成功。default : 30（建议使用）
c3p0.acquireRetryAttempts=5
#acquireRetryDelay：两次连接中间隔时间，单位毫秒，连接池在获得新连接时的间隔时间。default : 1000 单位ms（建议使用）
c3p0.acquireRetryDelay=1000
#breakAfterAcquireFailure：如果为true，则当连接获取失败时自动关闭数据源，除非重新启动应用程序。所以一般不用。default : false（不建议使用）
c3p0.breakAfterAcquireFailure=false
#checkoutTimeout：配置当连接池所有连接用完时应用程序getConnection的等待时间。为0则无限等待直至有其他连接释放或者创建新的连接，单位毫秒。不为0则当时间到的时候如果仍没有获得连接，则会抛出SQLException。其实就是acquireRetryAttempts*acquireRetryDelay。default : 0（与上面两个，有重复，选择其中两个都行）
c3p0.checkoutTimeout=100
#其他
#autoCommitOnClose：连接池在回收数据库连接时是否自动提交事务。如果为false，则会回滚未提交的事务，如果为true，则会自动提交事务。default : false（不建议使用）
c3p0.autoCommitOnClose=false
#c3p0是异步操作的，缓慢的JDBC操作通过帮助进程完成。扩展这些操作可以有效的提升性能通过多线程实现多个操作同时被执行。Default: 3
c3p0.numHelperThreads=10

最近项目中用的C3P0连接池出现各种bug，现在记录一下。

1、经常报连接池死锁

2016-08-31 15:24:00 [ WARN] - [com.mchange.v2.async.ThreadPoolAsynchronousRunner|run] - com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@74a7d985 -- APPARENT DEADLOCK!!! Complete Status: 
    ⇒  	Managed Threads: 3
    ⇒  	Active Threads: 3
    ⇒  	Active Tasks: 
    ⇒  	com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@115721ba (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2)
    ⇒  	com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@6f67433a (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0)
    ⇒  	com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask@646ecdf9 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1)
    ⇒  	Pending Tasks: 
    ⇒  	com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@2694c9f2
    ⇒  	com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask@725642a7
    ⇒  	com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@7d321c95
    ⇒  	com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask@64f2ba69
    ⇒  Pool thread stack traces:
    ⇒  	Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,main]
    ⇒  	com.mysql.jdbc.ResultSetImpl.realClose(ResultSetImpl.java:7337)
    ⇒  	com.mysql.jdbc.ResultSetImpl.close(ResultSetImpl.java:922)
    ⇒  	com.mysql.jdbc.StatementImpl.realClose(StatementImpl.java:2528)
    ⇒  	com.mysql.jdbc.PreparedStatement.realClose(PreparedStatement.java:3036)
    ⇒  	com.mysql.jdbc.StatementImpl.close(StatementImpl.java:577)
    ⇒  	com.mchange.v1.db.sql.StatementUtils.attemptClose(StatementUtils.java:41)
    ⇒  	com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask.run(GooGooStatementCache.java:404)
    ⇒  	com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
    ⇒  	Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main]
    ⇒  	com.mysql.jdbc.PreparedStatement.initializeFromParseInfo(PreparedStatement.java:2944)
    ⇒  	com.mysql.jdbc.PreparedStatement.<init>(PreparedStatement.java:926)
    ⇒  	com.mysql.jdbc.JDBC4PreparedStatement.<init>(JDBC4PreparedStatement.java:47)
    ⇒  	sun.reflect.GeneratedConstructorAccessor63.newInstance(Unknown Source)
    ⇒  	sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    ⇒  	java.lang.reflect.Constructor.newInstance(Constructor.java:526)
    ⇒  	com.mysql.jdbc.Util.handleNewInstance(Util.java:409)
    ⇒  	com.mysql.jdbc.PreparedStatement.getInstance(PreparedStatement.java:842)
    ⇒  	com.mysql.jdbc.ConnectionImpl.clientPrepareStatement(ConnectionImpl.java:1588)
    ⇒  	com.mysql.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:4604)
    ⇒  	com.mysql.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:4502)
    ⇒  	com.mysql.jdbc.LoadBalancedMySQLConnection.prepareStatement(LoadBalancedMySQLConnection.java:2207)
    ⇒  	sun.reflect.GeneratedMethodAccessor45.invoke(Unknown Source)
    ⇒  	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    ⇒  	java.lang.reflect.Method.invoke(Method.java:606)
    ⇒  	com.mysql.jdbc.LoadBalancingConnectionProxy.invoke(LoadBalancingConnectionProxy.java:651)
    ⇒  	com.mysql.jdbc.LoadBalancingConnectionProxy.invoke(LoadBalancingConnectionProxy.java:556)
    ⇒  	com.sun.proxy.$Proxy52.prepareStatement(Unknown Source)
    ⇒  	com.mysql.jdbc.ReplicationConnection.prepareStatement(ReplicationConnection.java:637)
    ⇒  	com.mysql.fabric.jdbc.FabricMySQLConnectionProxy.prepareStatement(FabricMySQLConnectionProxy.java:766)
    ⇒  	sun.reflect.GeneratedMethodAccessor45.invoke(Unknown Source)
    ⇒  	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    ⇒  	java.lang.reflect.Method.invoke(Method.java:606)
    ⇒  	com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StmtAcquireTask.run(GooGooStatementCache.java:525)
    ⇒  	com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
    ⇒  	Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main]
    ⇒  	com.mysql.jdbc.PreparedStatement.realClose(PreparedStatement.java:3021)
    ⇒  	com.mysql.jdbc.StatementImpl.close(StatementImpl.java:577)
    ⇒  	com.mchange.v1.db.sql.StatementUtils.attemptClose(StatementUtils.java:41)
    ⇒  	com.mchange.v2.c3p0.stmt.GooGooStatementCache$1StatementCloseTask.run(GooGooStatementCache.java:404)
    ⇒  	com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)

使用第二种最新版本的包：

<dependency>
<groupId>com.mchange</groupId>
<artifactId>c3p0</artifactId>
<version>0.9.5.2</version>
</dependency>

这种数据库连接池线程死锁的问题发生的原因可能有很多，我将我的配置环境以及解决方法贴出来供大家参考一下：

使用环境，spring + c3p0

esp.c3p0.url=${esp.c3p0.url}
esp.c3p0.user=${esp.c3p0.user}
esp.c3p0.password=${esp.c3p0.password}

esp_question.c3p0.url=${esp_question.c3p0.url}
esp_question.c3p0.user=${esp_question.c3p0.user}
esp_question.c3p0.password=${esp_question.c3p0.password}

report.c3p0.url=${report.c3p0.url}
report.c3p0.user=${report.c3p0.user}
report.c3p0.password=${report.c3p0.password}

c3p0.driverClass=com.mysql.fabric.jdbc.FabricMySQLDriver
c3p0.initialPoolSize=5
c3p0.maxPoolSize=50
c3p0.minPoolSize=3

c3p0.maxStatements=0
c3p0.maxStatementsPerConnection=0
c3p0.checkoutTimeout=100

c3p0.acquireIncrement=5
c3p0.acquireRetryDelay=1000
c3p0.acquireRetryAttempts=50
##create connect
c3p0.autoCommitOnClose=false
c3p0.breakAfterAcquireFailure=false

修改后，我开启一个多线程任务，没有出现异常。

一般设置maxStatements=0和maxStatementsPerConnection=0解决该问题，但是c3p0在同时关闭statement和connection的时候，或者关闭他们之间的时间很短的时候，有时候connection并没有被关闭，因为有些preparedstatement还在被cached住。（作者说的http://forum.hibernate.org/viewtopic.php?t=947246&highlight=apparent+deadlock+c3p0）

我在这里设置checkoutTimeout。（后面还是没有解决问题）

maxStatements：JDBC的标准参数，用以控制数据源内加载的PreparedStatements数量。但由于预缓存的statements 属于单个connection而不是整个连接池。所以设置这个参数需要考虑到多方面的因素。Default: 0

maxStatementsPerConnection：连接池为数据源单个Connection缓存的PreparedStatement数，这个配置比maxStatements更有意义，因为它缓存的服务对象是单个数据连接，如果设置的好，肯定是可以提高性能的。为0的时候不缓存。Default: 0

如果maxStatements与maxStatementsPerConnection均为0，则缓存被关闭。只要有一个不为0，则语句的缓存就能生效。

c3p0.maxStatements=0
c3p0.maxStatementsPerConnection=0

c3p0.checkoutTimeout=100

打印正确日志：

2016-08-31 17:20:00 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 开始执行
2016-08-31 17:20:00 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - 任务开始执行
2016-08-31 17:20:00 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 开始执行，time_section: 2015-09-02T20:33:16+08:00 - 2015-10-24T15:42:36+08:00
2016-08-31 17:20:00 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 开始执行
2016-08-31 17:20:00 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - 任务开始执行
2016-08-31 17:20:00 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 开始执行，time_section: 2015-10-24T15:42:36+08:00 - 2015-12-15T10:51:57+08:00
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 开始执行
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - 任务开始执行
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 开始执行，time_section: 2015-12-15T10:51:57+08:00 - 2016-02-05T06:01:18+08:00
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 开始执行
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - 任务开始执行
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 开始执行，time_section: 2016-02-05T06:01:18+08:00 - 2016-03-28T01:10:38+08:00
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 开始执行
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - 任务开始执行
2016-08-31 17:20:01 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 开始执行，time_section: 2016-03-28T01:10:38+08:00 - 2016-05-18T20:19:59+08:00
2016-08-31 17:20:41 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 处理一次分页耗时：39 秒
2016-08-31 17:20:41 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复-(2016-02-05T06:01:18+08:00 - 2016-03-28T01:10:38+08:00) 执行完成，共耗时39秒
2016-08-31 17:20:41 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|sendNotification] - No message to send
2016-08-31 17:20:41 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|onJobSuccess] - lcNDResourceRepairJob 成功执行完成
2016-08-31 17:20:41 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 执行完成
2016-08-31 17:21:39 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 处理一次分页耗时：98 秒
2016-08-31 17:21:39 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复-(2015-12-15T10:51:57+08:00 - 2016-02-05T06:01:18+08:00) 执行完成，共耗时98秒
2016-08-31 17:21:39 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|sendNotification] - No message to send
2016-08-31 17:21:39 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|onJobSuccess] - lcNDResourceRepairJob 成功执行完成
2016-08-31 17:21:39 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 执行完成
2016-08-31 17:22:13 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 处理一次分页耗时：131 秒
2016-08-31 17:22:13 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复-(2016-03-28T01:10:38+08:00 - 2016-05-18T20:19:59+08:00) 执行完成，共耗时131秒
2016-08-31 17:22:13 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|sendNotification] - No message to send
2016-08-31 17:22:13 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|onJobSuccess] - lcNDResourceRepairJob 成功执行完成
2016-08-31 17:22:13 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 执行完成
2016-08-31 17:23:53 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 处理一次分页耗时：232 秒
2016-08-31 17:23:53 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复-(2015-09-02T20:33:16+08:00 - 2015-10-24T15:42:36+08:00) 执行完成，共耗时232秒
2016-08-31 17:23:53 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|sendNotification] - No message to send
2016-08-31 17:23:53 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|onJobSuccess] - lcNDResourceRepairJob 成功执行完成
2016-08-31 17:23:53 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 执行完成
2016-08-31 17:27:24 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复 处理一次分页耗时：443 秒
2016-08-31 17:27:24 [ INFO] - [nd.sdp.lcreporting.schedule.job.esp2middle.RPBaseRepairJob|doJob] - 中间库-资源修复-(2015-10-24T15:42:36+08:00 - 2015-12-15T10:51:57+08:00) 执行完成，共耗时443秒
2016-08-31 17:27:24 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|sendNotification] - No message to send
2016-08-31 17:27:24 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|onJobSuccess] - lcNDResourceRepairJob 成功执行完成
2016-08-31 17:27:24 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - esp_to_middle_repair 执行完成

补充：后面又出了问题，是因为quartz里面没有配置数据源信息，而且quartz用的数据源和我们自己应用中的数据源还不一致，所以做了一些配置上的修改:

1）查看quartz用的什么数据源

2）修改pom.xml文件，排除冲突

3）修改quartz.properties配置，增加以下配置

后面在开发环境、测试环境、预生产环境就再也没有出现死锁的情况了。

2、换了一组多线程任务进行

{
    "schedule_name" : "middle_to_mongodb_sync",
    "schedule_desc":"中间库同步到mongodb",
    "time_section_start_time":1463456657382,
    "time_section_end_time":1463732172026,
       "jobs" : [ 
        {
            "name" : "rpDimensionCodesTreeRefreshJob",
            "sort_order" : 1,
            "retry_times" : 3
        },
        {
            "name" : "rpNDResourceSyncJob",
            "sort_order" : 2,
            "retry_times" : 3
        },
        {
            "name" : "rpResourceCategorySyncJob",
            "sort_order" : 3,
            "retry_times" : 3
        },
        {
            "name" : "rpResourceUsageSyncJob",
            "sort_order" : 4,
            "retry_times" : 3
        },
        {
            "name" : "rpResourcesUsageJob",
            "sort_order" : 5,
            "retry_times" : 3
        },
        {
            "name" : "rpResourcesTrendJob",
            "sort_order" : 5,
            "retry_times" : 3
        },
        {
            "name" : "rpResourceRelationTransformJob",
            "sort_order" : 5,
            "retry_times" : 3
        },
        {
            "name" : "rpDimensionCodeStatJob",
            "sort_order" : 5,
            "retry_times" : 3
        },
        {
            "name" : "rpResourceUsagePercentJob",
            "sort_order" : 6,
            "retry_times" : 3
        }

    ]
}

这次又有异常出现，如下：

2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - 中间库同步到mongodb 开始执行
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|doInvoke] - 等待前置任务完成
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - 任务开始执行
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.job.middle2mongo.RPDimensionCodesTreeRefreshJob|doJob] - 刷新DimensionCodesTreeCache
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.job.middle2mongo.RPDimensionCodesTreeRefreshJob|doJob] - 刷新成功，共耗时 0:00:00.233 
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|sendNotification] - No message to send
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|onJobSuccess] - rpDimensionCodesTreeRefreshJob 成功执行完成
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|doInvoke] - 前置任务完成，继续执行
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|doInvoke] - 等待前置任务完成
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - 任务开始执行
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.job.middle2mongo.RPNDResourceSyncJob|fetchFromMiddleRepoAndPersist] - 开始同步rpNDResourceSyncJob_1463456657382_1463732172026数据,范围：1463456657382 - 1463732172026
2016-08-31 19:36:38 [ INFO] - [org.springframework.beans.factory.xml.XmlBeanDefinitionReader|loadBeanDefinitions] - Loading XML bean definitions from class path resource [org/springframework/jdbc/support/sql-error-codes.xml]
2016-08-31 19:36:38 [ INFO] - [org.springframework.jdbc.support.SQLErrorCodesFactory|<init>] - SQLErrorCodes loaded: [DB2, Derby, H2, HSQL, Informix, MS-SQL, MySQL, Oracle, PostgreSQL, Sybase]
2016-08-31 19:36:38 [ERROR] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - JobExecution run rpNDResourceSyncJob 发生错误
org.springframework.dao.RecoverableDataAccessException: PreparedStatementCallback; SQL [SELECT identifier, title, description, estatus, enable, primary_category, create_time, last_update  FROM ndresource WHERE last_update BETWEEN ? AND ?  ORDER BY last_update ASC  LIMIT ? OFFSET ?]; Communications link failure

The last packet successfully received from the server was 160,044 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 160,044 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
    at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:98)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:660)
    at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:695)
    at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:722)
    at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:772)
    at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.query(NamedParameterJdbcTemplate.java:192)
    at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.query(NamedParameterJdbcTemplate.java:199)
    at nd.sdp.lcreporting.sync.rp.repository.RPNDResourceRepository.findByLastUpdateBetweenOrderByLastUpdateAsc(RPNDResourceRepository.java:56)
    at nd.sdp.lcreporting.schedule.job.middle2mongo.RPNDResourceSyncJob.fetchFromMiddleRepoAndPersist(RPNDResourceSyncJob.java:55)
    at nd.sdp.lcreporting.schedule.job.middle2mongo.RPNDResourceSyncJob.doJob(RPNDResourceSyncJob.java:44)
    at nd.sdp.lcreporting.schedule.job.Job.run(Job.java:159)
    at nd.sdp.lcreporting.schedule.job.JobExecution.run(JobExecution.java:55)
    at nd.sdp.lcreporting.schedule.QuartzJobExecutor$Worker.run(QuartzJobExecutor.java:96)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 160,044 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:409)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1127)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3715)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3604)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4155)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2615)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2776)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2843)
    at com.mysql.jdbc.LoadBalancedMySQLConnection.execSQL(LoadBalancedMySQLConnection.java:166)
    at sun.reflect.GeneratedMethodAccessor50.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.mysql.jdbc.LoadBalancingConnectionProxy.invoke(LoadBalancingConnectionProxy.java:651)
    at com.mysql.jdbc.LoadBalancingConnectionProxy.invoke(LoadBalancingConnectionProxy.java:556)
    at com.sun.proxy.$Proxy65.execSQL(Unknown Source)
    at com.mysql.fabric.jdbc.FabricMySQLConnectionProxy.execSQL(FabricMySQLConnectionProxy.java:985)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2085)
    at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2215)
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:353)
    at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:703)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:644)
    ... 14 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:3161)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3615)
    ... 32 more
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|onJobFailed] - rpNDResourceSyncJob 成功执行失败
2016-08-31 19:36:38 [ERROR] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|run] - error occurs on worker for rpNDResourceSyncJob
org.springframework.dao.RecoverableDataAccessException: PreparedStatementCallback; SQL [SELECT identifier, title, description, estatus, enable, primary_category, create_time, last_update  FROM ndresource WHERE last_update BETWEEN ? AND ?  ORDER BY last_update ASC  LIMIT ? OFFSET ?]; Communications link failure

The last packet successfully received from the server was 160,044 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 160,044 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
    at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:98)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:660)
    at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:695)
    at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:722)
    at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:772)
    at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.query(NamedParameterJdbcTemplate.java:192)
    at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.query(NamedParameterJdbcTemplate.java:199)
    at nd.sdp.lcreporting.sync.rp.repository.RPNDResourceRepository.findByLastUpdateBetweenOrderByLastUpdateAsc(RPNDResourceRepository.java:56)
    at nd.sdp.lcreporting.schedule.job.middle2mongo.RPNDResourceSyncJob.fetchFromMiddleRepoAndPersist(RPNDResourceSyncJob.java:55)
    at nd.sdp.lcreporting.schedule.job.middle2mongo.RPNDResourceSyncJob.doJob(RPNDResourceSyncJob.java:44)
    at nd.sdp.lcreporting.schedule.job.Job.run(Job.java:159)
    at nd.sdp.lcreporting.schedule.job.JobExecution.run(JobExecution.java:55)
    at nd.sdp.lcreporting.schedule.QuartzJobExecutor$Worker.run(QuartzJobExecutor.java:96)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 160,044 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:409)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1127)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3715)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3604)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4155)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2615)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2776)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2843)
    at com.mysql.jdbc.LoadBalancedMySQLConnection.execSQL(LoadBalancedMySQLConnection.java:166)
    at sun.reflect.GeneratedMethodAccessor50.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.mysql.jdbc.LoadBalancingConnectionProxy.invoke(LoadBalancingConnectionProxy.java:651)
    at com.mysql.jdbc.LoadBalancingConnectionProxy.invoke(LoadBalancingConnectionProxy.java:556)
    at com.sun.proxy.$Proxy65.execSQL(Unknown Source)
    at com.mysql.fabric.jdbc.FabricMySQLConnectionProxy.execSQL(FabricMySQLConnectionProxy.java:985)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2085)
    at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2215)
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:353)
    at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:703)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:644)
    ... 14 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:3161)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3615)
    ... 32 more
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|doInvoke] - 前置任务完成，继续执行
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|run] - 任务开始执行
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.job.middle2mongo.RPResourceCategorySyncJob|fetchFromMiddleRepoAndPersist] - 开始同步rpResourceCategorySyncJob_1463456657382_1463732172026数据,范围：1463456657382 - 1463732172026
2016-08-31 19:36:38 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|execute] - 中间库同步到mongodb 执行完成
2016-08-31 19:36:39 [ INFO] - [nd.sdp.lcreporting.schedule.job.middle2mongo.RPResourceCategorySyncJob|persistToMongodb] - 处理一次分页所用时间：0:00:00.364, 记录数：92，资源数：20
2016-08-31 19:36:39 [ INFO] - [nd.sdp.lcreporting.schedule.job.middle2mongo.RPResourceCategorySyncJob|fetchFromMiddleRepoAndPersist] - 结束同步 ; jobId :rpResourceCategorySyncJob_1463456657382_1463732172026
2016-08-31 19:36:39 [ INFO] - [nd.sdp.lcreporting.schedule.job.JobExecution|sendNotification] - No message to send
2016-08-31 19:36:39 [ INFO] - [nd.sdp.lcreporting.schedule.QuartzJobExecutor|onJobSuccess] - rpResourceCategorySyncJob 成功执行完成

可以看到上面说的是距上次向服务器发送和接收数据已经过了好长时间，所以服务器自动断开了连接，这个服务器不是指web服务器断开了浏览器的连接，而是指我们的数据库服务器断开了和web容器的连接。这是由于web容器和数据库服务器的连接长时间没有数据（默认是8小时）发送，所以MySQL自动断开了连接。一般情况下使用的DBCP、C3P0、Proxool都提供了在分配一个连接时自动测试其是否有效的功能，所以在使用这些时不需要担心。不过如果是使用的jdbc默认的连接池就会出现这个问题了。URL加上：autoReconnect=true&failOverReadOnly=false。但是最好还是在使用数据库连接池的情况下，最好设置如下两个参数：
autoReconnect=true&failOverReadOnly=false

jdbc:mysql://:3306/?autoReconnect=true

解决办法：

c3p0提供了几个参数给用户用于测试连接是否可用。他们分别是automaticTestTable，connectionTesterClassName，idleConnectionTestPeriod，preferredTestQuery，testConnectionOnCheckin， testConnectionOnCheckout。组合使用这几个参数可以检测连接是否可用。idleConnectionTestPeriod，testConnectionOnCheckin，testConnectionOnCheckout，这三个参数设置什么时候检测连接是否可用，而automaticTestTable，connectionTesterClassName，preferredTestQuery用于设置使用什么方式检测连接。

idleConnectionTestPeriod：单位为秒。用来配置测试空闲连接的间隔时间。可以用来解决MySQL8小时断开连接的问题。因为它保证连接池会每隔一定时间对空闲连接进行一次测试，从而保证有效的空闲连接能每隔一定时间访问一次数据库，将于MySQL8小时无会话的状态打破。为0则不测试。default : 0
testConnectionOnCheckin：布尔值，默认为false。如果值为true，在连接放入连接池时会异步发送检测请求到服务器，检测连接是否可用。如果为true，则在close（这里不是真正的关闭）的时候测试连接的有效性。
testConnectionOnCheckout：布尔值，默认为false。如果为true，在连接从连接池取出是，会同步发一个检测请求，以保证连接可用。如果为true，在每次getConnection的时候都会测试，为了提高性能,尽量不要用。

由于testConnectionOnCheckout每个连接使用前都做检测，这样会降低性能。如果要满足高性能的应用中，不建议使用。所以建议组合使用idleConnectionTestPeriod和testConnectionOnCheckin，以保证连接的可用。

automaticTestTable：如果设置了此值，c3p0会自动在数据库创建一个设置的表，用来检测连接是否可用。
preferredTestQuery：这个值为用于检测连接是否可用的查询语句。在一些数据库，如MySQL中直接使用"SELECT　１"就可以，不用依赖一个数据库存在的表。
connectionTesterClassName: 用户可以自定义一个类来检测数据库连接是否可用。

如果是MySQL服务器，在兼顾性能的方案上，检测时间使用idleConnectionTestPeriod和testConnectionOnCheckin配置，检测方式上最简单的就是"SELECT　１"。参考配置如下：

c3p0.testConnectionOnCheckin=true
c3p0.preferredTestQuery=SELECT 1
c3p0.idleConnectionTestPeriod=10

貌似在这里已经解决了问题，在本地运行也没有报过错，但是最后发布到公司的开发环境和测试环境还是报这种错误，最后检查了一下发现还需要加一行配置代码：

c3p0.maxIdleTime=55（这个值的设定要根据公司MySQL服务端设置的空闲超时断开时间指定，比如wait_timeout=60s，mysql默认是8小时）maxIdleTime必须要小于wait_timeout（不管这个连接有没有被close掉，只要这个连接属于空闲状态，超过这个时间连接就废弃）

为什么要加这行配置代码呢？

因为有的数据库CRUD操作之后，没有close（不是真正意义上的关闭）掉，只有close后才能回归连接池。这里的close()只是将数据库连接池中占用的connection释放掉，使其在连接池中处于空闲状态，如果你不关闭，数据库连接池中的connection中用完以后，请求就会处于队列状态，超出规定时间连接池就会将队列的请求断开，导致其无法进行连接。只有close掉，这样我们才能去心跳校验，也就是上面那三行代码配置才有作用。

spring 中可以使用使用spring 的 DataSourceUtils 里面有 public static Connection getConnection(DataSource dataSource) throws CannotGetJdbcConnectionException
和 public static void doReleaseConnection(Connection con, DataSource dataSource) throws SQLException 这两个是获得和关闭连接。

我们用的是spring的jdbctemplate，因为spring对jdbc进行了封装，这个是不需要手工关闭的。

finally {
            if(psc instanceof ParameterDisposer) {
                ((ParameterDisposer)psc).cleanupParameters();
            }

            JdbcUtils.closeStatement(ps);
            DataSourceUtils.releaseConnection(con1, this.getDataSource());
        }

public static void releaseConnection(Connection con, DataSource dataSource) {
        try {
            doReleaseConnection(con, dataSource);
        } catch (SQLException var3) {
            logger.debug("Could not close JDBC Connection", var3);
        } catch (Throwable var4) {
            logger.debug("Unexpected exception on closing JDBC Connection", var4);
        }

    }

所以不是jdbctemplate的错，最后看了源码觉得应该是c3p0:

c3p0在从连接池中获取和返回连接的时候，采用了异步的处理方式，使用一个线程池来异步的把返回关闭了（没有真正关闭）的连接放入连接池中。这样就意味着，我们在调用了从c3p0获得的连接的close方法时，不是立即放回池中的，而是放入一个事件队列中等待c3p0内部的线程池顺序的处理。所以没有及时加入到线程池中，所以心跳时间监测不到。（也就是我们设置了maxIdleTime的原因）

报以下错误：The last packet successfully received from the server was 990,743 milliseconds ago.
连接超时问题，
a.需检查心跳时间是否小于30秒（这个时间要根据公司MySQL服务端设置的空闲超时断开时间指定，比如wait_timeout=60s）
b.是否添加 autoReconnect=true（最好加上，但是这个貌似只对mysql5之前的版本起作用）
c.是否在调用数据库connection后没有close（只有close后才能回归连接池，才会去心跳校验）

备注：1、像mysql重连，连接丢失这种情况，一般发生在一个应用中有多个数据源（多个不同的库），比如多个线程操作，一个线程操作了第一个库之后，第二个线程去操作第二个库同步数据花费了很长的时间，而且第一个库的连接在mysql中已经失效，这时候连接池中如果不设置maxIdleTime小于mysql的wait_timeout，就会报mysql连接丢失的异常。maxIdleTime还有一个好处就是：空闲连接回收（长时间不用的连接应该被销毁），否则会导致连接泄露（另一种内存泄露)。

2、在Tomcat中配置c3p0数据库连接池的时候，如果数据库重启，或者网络原因造成服务器和数据库断开连接，Tomcat便再也不能和数据库连接，除非Tomcat服务重启。

也就是说无效连接清除。如果客户端（连接池）保持了若干连接，而数据库服务器重启，那么客户端哪些仍被保持的连接实际已经失效。因此必须有检测机制定期清除无效连接。

也就是这个在前面介绍的配置：

c3p0.testConnectionOnCheckin=true
c3p0.preferredTestQuery=SELECT 1
c3p0.idleConnectionTestPeriod=10

这样配置之后，连接池每隔10秒自动检测数据库连接情况，如果断开则自动重连。

最后别忘了quartz.properties也要配置上

参考资料：http://www.cnblogs.com/zhishan/archive/2012/11/09/2761980.html

http://blog.csdn.net/frankcheng5143/article/details/50589264

一门面向 Data 和 AI 的低代码、云原生的开源编程语言

无需安装部署，在线快速体验 Byzer

更多推荐

编译时权限控制

前言权限控制，对于 MLSQL 而言的重要程度可以说是生命线。 MLSQL 需要面对各式各样的资源访问，比如 MySQL, Oracle,HDFS，Hive，Kafka，Sorl，ElasticSearch，Redis，API，Web等等，不同用户对这些数据源（以及表，列）的权限是不一样的。传统模式是，每个用户都需要有个 proxy user，然后到每个数据源里面给这个 proxy user

Byzer 白泽

Byzer 支持 JDBC 聚合下推

聚合下推PR链接聚合下推我们知道 Byzer 支持多数据源和联邦查询，可以方便分析师在一个平台上快速的分析来自多种数据源的数据，从而进行灵活的探索式分析。使用场景和优势当前 Byzer 中加载数据的方式会拉取明细数据到 spark 中进行聚合计算，对于小数据量或者在分布式文件系统上的数据源来说是常规操作。但是对于 JDBC 数据源或者有分析能力的 OLAP 系统来说拉取明细数据可能就不是最

Byzer 白泽

Byzer 术语表

Byzer-lang Byzer ，又称为 Byzer-lang，一门面向 Data 和 AI 的低代码、云原生的开源编程语言。 Byzer 是一门结合了声明式编程和命令式编程的混合编程语言，其低代码且类 SQL 的编程逻辑配合内置算法及插件的加持，能帮助数据工作者们高效打通数据链路，完成数据的清洗转换，并快速地进行机器学习相关的训练及预测。 Byzer 希望能够提供一套语言、一个引擎，就能覆盖整