mysql - JDBC连接超时无法重连

Question

我的 Spring Hibernate Web 应用程序在 MySQL 上运行，这给我带来了麻烦。

我四处搜索并尝试了不同的配置，阅读了该网站上的不少主题，但它仍然会露出微笑的脑袋。

错误信息是:Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: 从服务器成功接收到的最后一个数据包是 63,313,144 毫秒前。最后一个成功发送到服务器的数据包是在 63,313,144 毫秒之前。比服务器配置的“wait_timeout”值长。在您的应用程序中使用之前，您应该考虑过期和/或测试连接有效性，增加服务器配置的客户端超时值，或使用 Connector/J 连接属性“autoReconnect=true”来避免此问题。

Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 63,313,144 milliseconds ago.  The last packet sent successfully to the server was 63,313,144 milliseconds ago. 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.
    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:408)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1137)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3965)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2578)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2758)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2820)
    at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:5359)
    at net.sf.log4jdbc.ConnectionSpy.setAutoCommit(ConnectionSpy.java:764)
    at com.mchange.v2.c3p0.impl.NewProxyConnection.setAutoCommit(NewProxyConnection.java:912)
    at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:72)
    at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:162)
    at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1435)
    at org.hibernate.jpa.internal.TransactionImpl.begin(TransactionImpl.java:61)
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:159)
    at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:380)
    ... 46 more
Caused by: java.net.SocketException: Broken pipe
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
    at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3946)
    ... 58 more

MySQL wait_timeout 值为 28800。

我的数据源、c3p0 和 Hibernate 配置是:

@Bean
public DataSource dataSource() throws PropertyVetoException {
    ComboPooledDataSource dataSource = new ComboPooledDataSource();
    dataSource.setDriverClass(databaseProperties.getHibernateDriverClassName());
    dataSource.setJdbcUrl(databaseProperties.getDataSourceUrl());
    dataSource.setUser(databaseProperties.getDataSourceUsername());
    dataSource.setPassword(databaseProperties.getDataSourcePassword());
    dataSource.setAcquireIncrement(5);
    dataSource.setMaxStatementsPerConnection(20);
    dataSource.setMaxStatements(100);
    dataSource.setMinPoolSize(2);
    dataSource.setMaxPoolSize(5);
    return dataSource;
}

@Bean
public LocalContainerEntityManagerFactoryBean entityManagerFactory() throws PropertyVetoException {
    HibernateJpaVendorAdapter jpaVendorAdapter = new HibernateJpaVendorAdapter();
    jpaVendorAdapter.setDatabasePlatform(databaseProperties.getHibernateDialect());
    jpaVendorAdapter.setShowSql(true);
    jpaVendorAdapter.setGenerateDdl(false);

    Map<String, String> jpaPropertiesMap = new HashMap<String, String>();
    jpaPropertiesMap.put("hibernate.dialect", databaseProperties.getHibernateDialect());
    jpaPropertiesMap.put("hibernate.show_sql", "true");
    jpaPropertiesMap.put("hibernate.format_sql", "true");
    jpaPropertiesMap.put("hibernate.hbm2ddl.auto", databaseProperties.getHibernateHbm2ddlAuto());
    jpaPropertiesMap.put("hibernate.transaction.factory_class", "org.hibernate.transaction.JDBCTransactionFactory");
    jpaPropertiesMap.put("hibernate.ejb.naming_strategy", "org.hibernate.cfg.ImprovedNamingStrategy");
    jpaPropertiesMap.put("hibernate.c3p0.min_size", "5");
    jpaPropertiesMap.put("hibernate.c3p0.max_size", "20");
    jpaPropertiesMap.put("hibernate.c3p0.timeout", "1000");
    jpaPropertiesMap.put("c3p0.maxConnectionAge", "7200");
    jpaPropertiesMap.put("c3p0.maxIdleTime", "7200");
    jpaPropertiesMap.put("c3p0.unreturnedConnectionTimeout", "60");
    jpaPropertiesMap.put("c3p0.debugUnreturnedConnectionStackTraces", "true");
    jpaPropertiesMap.put("hibernate.c3p0.max_statements", "50");
    // Prevent JPA from converting the dates to the UTC time zone
    jpaPropertiesMap.put("jadira.usertype.autoRegisterUserTypes", "true");
    jpaPropertiesMap.put("jadira.usertype.databaseZone", "jvm");
    jpaPropertiesMap.put("jadira.usertype.javaZone", "jvm");

    LocalContainerEntityManagerFactoryBean factoryBean = new LocalContainerEntityManagerFactoryBean();
    factoryBean.setJpaVendorAdapter(jpaVendorAdapter);
    factoryBean.setPackagesToScan("com.nsn.nitro.project.data.jpa.domain");
    factoryBean.setJpaPropertyMap(jpaPropertiesMap);
    String[] mappingsResources = new String[] {"custom/typedef.hbm.xml"};        
    factoryBean.setMappingResources(mappingsResources);
    factoryBean.setDataSource(dataSource());
    return factoryBean;
}

当第二天早上我回到 web 应用程序并且整个晚上都没有访问它时，错误发生了。

我知道 MySQL wait_timeout 是 MySQL 在关闭连接之前等待再次使用连接的秒数。

这意味着我的 Web 应用程序正在尝试使用一个已过期并在 MySQL 端关闭的连接，而我的 Web 应用程序仍然认为它是一个有效连接。

我想我应该在 MySQL 之前让我的 Web 应用程序超时连接。这样，Web 应用程序就不会重用任何在 MySQL 端已经超时和关闭的连接，因为连接在 Web 应用程序端已经超时。

感觉我所有的 c3p0 配置都没有完成未使用的连接超时的效果。

我正在使用以下堆栈:

MySQL mysql-5.6.14
mysql-connector-java 5.1.32
Spring 4.1.0.RELEASE
spring-data-jpa 1.6.2.RELEASE
Hibernate 4.3.6.Final
hibernate-jpa-2.1-api 1.0.0.Final
C3P0 0.9.2.1

我的配置有什么问题？

或者我应该明确关闭连接吗？

以下是我设置存储库的方式:

public interface LanguageRepository extends GenericRepository<Language, Long> {
}

@Repository
@Transactional
public class GenericRepositoryImpl<T, ID extends Serializable> extends SimpleJpaRepository<T, ID> implements GenericRepository<T, ID> {

    private EntityManager entityManager;

    public GenericRepositoryImpl(JpaEntityInformation<T, ID> entityMetadata, EntityManager entityManager) {
        super(entityMetadata, entityManager);

        this.entityManager = entityManager;
    }

    public GenericRepositoryImpl(Class<T> domainClass, EntityManager entityManager) {
        super(domainClass, entityManager);

        this.entityManager = entityManager;
    }

    public EntityManager getEntityManager() {
        return entityManager;
    }

    @Override
    @Transactional
    public T deleteById(ID id) throws EntityNotFoundException {
        T entity = findOne(id);
        if (entity != null) {
            delete(entity);
        } else {
            throw new EntityNotFoundException("The entity could not be found and was not deleted");
        }
        return entity;
    }

}

public class GenericRepositoryFactoryBean<R extends JpaRepository<T, I>, T, I extends Serializable> extends JpaRepositoryFactoryBean<R, T, I> {

    protected RepositoryFactorySupport createRepositoryFactory(EntityManager entityManager) {
        return new BaseRepositoryFactory<T, I>(entityManager);
    }

    protected static class BaseRepositoryFactory<T, I extends Serializable> extends JpaRepositoryFactory {

        private EntityManager entityManager;

        public BaseRepositoryFactory(EntityManager entityManager) {
            super(entityManager);

            this.entityManager = entityManager;
        }

        @Override
        protected Object getTargetRepository(RepositoryMetadata metadata) {
            return new GenericRepositoryImpl<T, I>((JpaEntityInformation<T, I>) getEntityInformation(metadata.getDomainType()), entityManager);
        }

        @Override
        protected Class<?> getRepositoryBaseClass(RepositoryMetadata metadata) {
            return GenericRepositoryImpl.class;
        }
    }

}

@NoRepositoryBean
public interface GenericRepository<T, ID extends Serializable> extends JpaRepository<T, ID> {

    public EntityManager getEntityManager();

    public T deleteById(ID id) throws EntityNotFoundException;

}

我看不到任何正在实现或调用的 close() 方法。我的代码中缺少什么？

编辑:为 C3P0 添加了日志记录。这是输出:

2014-10-17 14:29:00,464 INFO   [AbstractPoolBackedDataSource] Initializing c3p0 pool... com.mchange.
v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 5, acquireRetryAttempts -> 30, acquireRetryDelay
 -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false,
 checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchan
ge.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> agvw3s958cggbnis1syx|1acb901, debugUnretu
rnedConnectionStackTraces -> false, description -> null, driverClass -> net.sf.log4jdbc.DriverSpy, f
actoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> agvw3s958c
ggbnis1syx|1acb901, idleConnectionTestPeriod -> 0, initialPoolSize -> 3, jdbcUrl -> jdbc:log4jdbc:my
sql://127.0.0.1:3306/nitroproject, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTim
e -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 5, maxStatements -> 100, maxStatementsPerC
onnection -> 20, minPoolSize -> 2, numHelperThreads -> 3, preferredTestQuery -> null, properties -> 
{user=******, password=******}, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, test
ConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, u
serOverrides -> {}, usesTraditionalReflectiveProxies -> false ] 
2014-10-17 14:29:00,479 DEBUG  [BasicResourcePool] incremented pending_acquires: 1 
2014-10-17 14:29:00,480 DEBUG  [BasicResourcePool] Starting acquisition series. Incremented pending_
acquires [1],  attempts_remaining: 30 
2014-10-17 14:29:00,480 DEBUG  [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchr
onousRunner@11dbedc: Adding task to queue -- com.mchange.v2.resourcepool.BasicResourcePool$Scattered
AcquireTask@1dd75ae 
2014-10-17 14:29:00,481 DEBUG  [BasicResourcePool] incremented pending_acquires: 2 
2014-10-17 14:29:00,481 DEBUG  [BasicResourcePool] Starting acquisition series. Incremented pending_
acquires [2],  attempts_remaining: 30 
2014-10-17 14:29:00,482 DEBUG  [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchr
onousRunner@11dbedc: Adding task to queue -- com.mchange.v2.resourcepool.BasicResourcePool$Scattered
AcquireTask@15083c7 
2014-10-17 14:29:00,482 DEBUG  [BasicResourcePool] incremented pending_acquires: 3 
2014-10-17 14:29:00,483 DEBUG  [BasicResourcePool] Starting acquisition series. Incremented pending_
acquires [3],  attempts_remaining: 30 
2014-10-17 14:29:00,483 DEBUG  [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchr
onousRunner@11dbedc: Adding task to queue -- com.mchange.v2.resourcepool.BasicResourcePool$Scattered
AcquireTask@fbbf1d 
2014-10-17 14:29:00,511 DEBUG  [GooGooStatementCache] checkinAll(): com.mchange.v2.c3p0.stmt.DoubleMaxStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0 
2014-10-17 14:29:00,523 DEBUG  [C3P0PooledConnectionPool] com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager@e38aca.acquireResource() returning.  
2014-10-17 14:29:00,523 DEBUG  [BasicResourcePool] trace com.mchange.v2.resourcepool.BasicResourcePool@ad2e72 [managed: 1, unused: 1, excluded: 0] 
2014-10-17 14:29:00,523 DEBUG  [BasicResourcePool] decremented pending_acquires: 2 
2014-10-17 14:29:00,523 DEBUG  [BasicResourcePool] Acquisition series terminated successfully. Decremented pending_acquires [2],  attempts_remaining: 30 
2014-10-17 14:29:00,521 DEBUG  [BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool@ad2e72 config: [start -> 3; min -> 2; max -> 5; inc -> 5; num_acq_attempts -> 30; acq_attempt_delay -> 1000; check_idle_resources_delay -> 0; mox_resource_age -> 0; max_idle_time -> 0; excess_max_idle_time -> 0; destroy_unreturned_resc_time -> 0; expiration_enforcement_delay -> 0; break_on_acquisition_failure -> false; debug_store_checkout_exceptions -> false] 
2014-10-17 14:29:00,523 DEBUG  [C3P0PooledConnectionPoolManager] Created new pool for auth, username (masked): 'ni******'. 
2014-10-17 14:29:00,523 DEBUG  [BasicResourcePool] trace com.mchange.v2.resourcepool.BasicResourcePool@ad2e72 [managed: 1, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@acde7c) 
2014-10-17 14:29:00,524 DEBUG  [GooGooStatementCache] checkinAll(): com.mchange.v2.c3p0.stmt.DoubleMaxStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0 
2014-10-17 14:29:00,525 DEBUG  [C3P0PooledConnectionPool] com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager@e38aca.acquireResource() returning.  
2014-10-17 14:29:00,525 DEBUG  [BasicResourcePool] trace com.mchange.v2.resourcepool.BasicResourcePool@ad2e72 [managed: 2, unused: 1, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@acde7c) 
2014-10-17 14:29:00,525 DEBUG  [BasicResourcePool] decremented pending_acquires: 1 
2014-10-17 14:29:00,529 DEBUG  [BasicResourcePool] Acquisition series terminated successfully. Decremented pending_acquires [1],  attempts_remaining: 30 
2014-10-17 14:29:00,525 DEBUG  [GooGooStatementCache] checkinAll(): com.mchange.v2.c3p0.stmt.DoubleMaxStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0 
2014-10-17 14:29:00,530 DEBUG  [C3P0PooledConnectionPool] com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager@e38aca.acquireResource() returning.  
2014-10-17 14:29:00,530 DEBUG  [BasicResourcePool] trace com.mchange.v2.resourcepool.BasicResourcePool@ad2e72 [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@acde7c) 
2014-10-17 14:29:00,530 DEBUG  [BasicResourcePool] decremented pending_acquires: 0 
2014-10-17 14:29:00,530 DEBUG  [BasicResourcePool] Acquisition series terminated successfully. Decremented pending_acquires [0],  attempts_remaining: 30 
2014-10-17 14:29:00,562 DEBUG  [GooGooStatementCache] checkinAll(): com.mchange.v2.c3p0.stmt.DoubleMaxStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0 
2014-10-17 14:29:00,574 DEBUG  [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner@11dbedc: Adding task to queue -- com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@1fec09e 
2014-10-17 14:29:00,574 DEBUG  [GooGooStatementCache] checkinAll(): com.mchange.v2.c3p0.stmt.DoubleMaxStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0 
2014-10-17 14:29:00,575 DEBUG  [BasicResourcePool] trace com.mchange.v2.resourcepool.BasicResourcePool@ad2e72 [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@acde7c) 
2014-10-17 14:29:00,575 DEBUG  [NewProxyConnection] com.mchange.v2.c3p0.impl.NewProxyConnection@39069f: close() called more than once. 
2014-10-17 14:29:02,260 DEBUG  [BasicResourcePool] trace com.mchange.v2.resourcepool.BasicResourcePool@ad2e72 [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@acde7c) 
2014-10-17 14:29:03,111 DEBUG  [GooGooStatementCache] checkinAll(): com.mchange.v2.c3p0.stmt.DoubleMaxStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0 
2014-10-17 14:29:03,112 DEBUG  [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner@11dbedc: Adding task to queue -- com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@146219b 
2014-10-17 14:29:03,112 DEBUG  [GooGooStatementCache] checkinAll(): com.mchange.v2.c3p0.stmt.DoubleM
axStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0 
2014-10-17 14:29:03,113 DEBUG  [BasicResourcePool] trace com.mchange.v2.resourcepool.BasicResourcePo
ol@ad2e72 [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@acde7c) 
2014-10-17 14:29:03,262 DEBUG  [DefaultListableBeanFactory] Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor' 
2014-10-17 14:29:03,285 DEBUG  [DefaultListableBeanFactory] Finished creating instance of bean 'entityManagerFactory' 

然后循环输出:

2014-10-17 14:34:10,399 DEBUG  [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@70b40a -- Running DeadlockDetector[Exiting. No pending tasks.] 
2014-10-17 14:34:10,825 DEBUG  [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@15e34e2 -- Running DeadlockDetector[Exiting. No pending tasks.] 
2014-10-17 14:34:10,825 DEBUG  [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@15e34e2 -- Running DeadlockDetector[Exiting. No pending tasks.]

Answer 1

我想问题的出现是因为数据库服务器终止了连接，而应用程序连接池仍然有它的句柄。通过使应用程序连接池的超时时间短于数据库服务器端的超时时间，应用程序连接池会在连接被数据库服务器终止之前更新连接，从而避免了该问题。我的 MySQL 数据库服务器有 28800 秒的超时等待，我的应用程序连接池 C3P0 有 14400 秒的超时等待。从服务器到客户端的超时等待链必须缩短是有道理的。