Connections checking in c3p0 pool

Radzikowski picture Radzikowski · Oct 27, 2014 · Viewed 16.7k times · Source

I'm developing with Java SE application using Hibernate 4 and c3p0 for communication with MariaDB database. It's long running application, waiting for signals from outside, so sometimes database closes my connections after 8 hours of inactivity. I tried to configure c3p0 connections validating but it's not working. Could you help me?

Error log (thrown during named query execution):

2014-10-27 08:10:19.062 ERROR [trans] com.example.runnable.T1 - Exception thrown during event processing, rollbacking transaction: org.hibernate.exception.JDBCConnectionException: could not extract ResultSet
        at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:132)
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49)
        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.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:91)
        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.hql.QueryLoader.list(QueryLoader.java:496)
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:387)
        at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:231)                                                                                                                                                    
        at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1264)                                                                                                                                                                    
        at org.hibernate.internal.QueryImpl.list(QueryImpl.java:103)                                                                                                                                                                         
        at com.example.runnable.T1.find(EventsTransmitter.java:140)                                                                                                                         
        at com.example.runnable.T1.run(EventsTransmitter.java:86)                                                                                                                                  
        at java.lang.Thread.run(Thread.java:745)                                                                                                                                                                                             
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 108,132,692 milliseconds ago.  The last packet sent successfully to the server was 108,132,692 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.GeneratedConstructorAccessor30.newInstance(Unknown Source)                                                                                                                                                            
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)                                                                                                                              
        at java.lang.reflect.Constructor.newInstance(Constructor.java:408)                                                                                                                                                                   
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:377)                                                                                                                                                                              
        at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1036)                                                                                                                                                         
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3661)                                                                                                                                                                                    
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2417)                                                                                                                                                                             
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)                                                                                                                                                                          
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2530)                                                                                                                                                                   
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1907)                                                                                                                                                     
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2030)                                                                                                                                                        
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:82)                                                                                                                                       
        ... 17 more                                                                                                                                                                                                                          
Caused by: java.net.SocketException: Broken pipe                                                                                                                                                                                             
        at java.net.SocketOutputStream.socketWrite0(Native Method)                                                                                                                                                                           
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3643)
        ... 23 more

pom.xml:

<dependency>
    <groupId>mysql</groupId>
    <artifactId>mysql-connector-java</artifactId>
    <version>5.1.33</version>
</dependency>
<dependency>
    <groupId>org.hibernate</groupId>
    <artifactId>hibernate-core</artifactId>
    <version>4.3.6.Final</version>
</dependency>
<dependency>
    <groupId>org.hibernate</groupId>
    <artifactId>hibernate-validator</artifactId>
    <version>5.1.2.Final</version>
</dependency>
<dependency>
    <groupId>org.hibernate</groupId>
    <artifactId>hibernate-entitymanager</artifactId>
    <version>4.3.1.Final</version>
</dependency>
<dependency>
    <groupId>org.hibernate</groupId>
    <artifactId>hibernate-ehcache</artifactId>
    <version>4.3.6.Final</version>
</dependency>
<dependency>
    <groupId>org.hibernate</groupId>
    <artifactId>hibernate-c3p0</artifactId>
    <version>4.3.6.Final</version>
</dependency>

src/main/resources/hibernate.cfg.xml:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-configuration PUBLIC "-//Hibernate/Hibernate Configuration DTD 3.0//EN" "http://www.hibernate.org/dtd/hibernate-configuration-3.0.dtd">
<hibernate-configuration>
    <session-factory>
    <property name="hibernate.dialect">org.hibernate.dialect.MySQLDialect</property>
    <property name="hibernate.connection.driver_class">com.mysql.jdbc.Driver</property>
    <property name="hibernate.connection.url">jdbc:mysql://localhost:3306/MyBase?zeroDateTimeBehavior=convertToNull&amp;autoReconnect=true</property>
    <property name="hibernate.connection.username">user</property>
    <property name="hibernate.connection.password">pass</property>

    <property name="hibernate.current_session_context_class">thread</property>

    <property name="show_sql">true</property>
    <property name="use_sql_comments">true</property>

    <property name="hibernate.cache.use_second_level_cache">true</property>
    <property name="hibernate.cache.use_query_cache">true</property>
    <property name="hibernate.cache.region.factory_class">org.hibernate.cache.ehcache.EhCacheRegionFactory</property>

    <property name="hibernate.c3p0.min_size">5</property>
    <property name="hibernate.c3p0.max_size">10</property>
    <property name="hibernate.c3p0.timeout">300</property>
    <property name="hibernate.c3p0.max_statements">30</property>

    <mapping class="com.example.domain.E" />
    </session-factory>
</hibernate-configuration>

src/main/resources/c3p0-config.xml:

<?xml version="1.0" encoding="UTF-8"?>
<c3p0-config>
    <default-config>
    <property name="preferredTestQuery">SELECT 1 FROM DUAL</property>
    <property name="testConnectionOnCheckin">true</property>
    <property name="idleConnectionTestPeriod">1800</property> <!-- 30 minutes -->
    </default-config>
</c3p0-config>

Edited

In logs on startup I'm getting c3p0 configuration (executing by Maven from Netbeans):

...
INFO: Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@81187ff9
[ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@e1820e10 [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000,
autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null,
connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null,
forceIgnoreUnresolvedTransactions -> false, identityToken -> z8kflt95n558v5xddgsj|2cf3d63b, idleConnectionTestPeriod -> 1800, initialPoolSize -> 5,
maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 10, maxStatements -> 30,
maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@2f0d7eae [ description -> null, driverClass -> null,
factoryClassLocation -> null, identityToken -> z8kflt95n558v5xddgsj|1e6a3214, jdbcUrl -> jdbc:mysql://localhost:3306/MyBase?zeroDateTimeBehavior=convertToNull&autoReconnect=true,
properties -> {user=******, password=******} ], preferredTestQuery -> SELECT 1 FROM DUAL, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0,
testConnectionOnCheckin -> true, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ],
dataSourceName -> null, factoryClassLocation -> null, identityToken -> z8kflt95n558v5xddgsj|7161d8d1, numHelperThreads -> 3 ]
...

Edit 2

When executing jar created by maven-shade-plugin I'm getting:

paź 27, 2014 10:56:22 PM org.hibernate.engine.jdbc.connections.internal.ConnectionProviderInitiator instantiateC3p0Provider WARN: HHH000022: c3p0 properties were encountered, but the c3p0 provider class was not found on the classpath; these properties are going to be ignored. paź 27, 2014 10:56:22 PM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl configure WARN: HHH000402: Using Hibernate built-in connection pool (not for production use!) paź 27, 2014 10:56:22 PM org.hibernate.engine.jdbc.connections.internal.DriverManagerConnectionProviderImpl buildCreator

or when I tried to indicate org.hibernate.connection.C3P0ConnectionProvider in properties:

INFO: HHH000130: Instantiating explicit connection provider: org.hibernate.connection.C3P0ConnectionProvider Initial SessionFactory creation failed.org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.jdbc.connections.spi.ConnectionProvider] Exception in thread "main" java.lang.ExceptionInInitializerError at com.example.util.HibernateUtil.(HibernateUtil.java:27) at com.example.App.run(App.java:31) at com.example.App.main(App.java:25)
Caused by: org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.jdbc.connections.spi.ConnectionProvider]

    at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:261)

    at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:225)

    at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:206)

    at org.hibernate.engine.jdbc.internal.JdbcServicesImpl.buildJdbcConnectionAccess(JdbcServicesImpl.java:260)

    at org.hibernate.engine.jdbc.internal.JdbcServicesImpl.configure(JdbcServicesImpl.java:94)

    at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.configureService(StandardServiceRegistryImpl.java:111)

    at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:234)

    at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:206)

    at org.hibernate.cfg.Configuration.buildTypeRegistrations(Configuration.java:1885)

    at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1843)

    at com.example.util.HibernateUtil.<clinit>(HibernateUtil.java:24)

    ... 2 more                                                                                                                                                                                                                Caused by: org.hibernate.HibernateException: Could not instantiate

connection provider [org.hibernate.connection.C3P0ConnectionProvider]

    at org.hibernate.engine.jdbc.connections.internal.ConnectionProviderInitiator.instantiateExplicitConnectionProvider(ConnectionProviderInitiator.java:197)

    at org.hibernate.engine.jdbc.connections.internal.ConnectionProviderInitiator.initiateService(ConnectionProviderInitiator.java:120)
    at org.hibernate.engine.jdbc.connections.internal.ConnectionProviderInitiator.initiateService(ConnectionProviderInitiator.java:55)
    at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.initiateService(StandardServiceRegistryImpl.java:105)
    at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:251)
    ... 12 more Caused by: org.hibernate.boot.registry.selector.spi.StrategySelectionException:

Unable to resolve name [org.hibernate.connection.C3P0ConnectionProvider] as strategy [org.hibernate.engine.jdbc.connections.spi.ConnectionProvider] at org.hibernate.boot.registry.selector.internal.StrategySelectorImpl.selectStrategyImplementor(StrategySelectorImpl.java:128) at org.hibernate.engine.jdbc.connections.internal.ConnectionProviderInitiator.instantiateExplicitConnectionProvider(ConnectionProviderInitiator.java:194) ... 16 more

But everything is good when starting by Maven. Unfortunately I need this to work from single jar. Any ideas why org.hibernate.connection.C3P0ConnectionProvider cannot be found in shaded jar?

Answer

Radzikowski picture Radzikowski · Nov 3, 2014

Ok, i managed to fix all problems. Here is soultion.

First of all, as Steve Waldman suggested, c3p0 wasn't actually initialized, but in Hibernate 4.3 hibernate.connection.provider_class parameter should be: org.hibernate.c3p0.internal.C3P0ConnectionProvider. In documentation you can read:

A connection provider that uses a C3P0 connection pool. Hibernate will use this by default if the hibernate.c3p0.* properties are set.

But in my opinion it's good to put this parameter by yourself, and it's needed if you are using c3p0 config file, not hibernate.c3p0.* properties.


Second problem was obtaining session by calling SessionFactory.openSession() at the begining of the thread and later using always the same session object. I suppose after database connection was broken and there was new one recreated in pool, using old session caused using old, broken connection. So possible solutions were obtaining new session by SessionFactory.openSession() after catching connection error or using SessionFactory.getCurrentSession() at the begining of every communication. I've decided to use the second option (in this case my application waits for external signal, sometimes for hours, so I'm obtaining current session after each signal).


My final configuration:

hibernate.cfg.xml:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-configuration PUBLIC "-//Hibernate/Hibernate Configuration DTD 3.0//EN" "http://www.hibernate.org/dtd/hibernate-configuration-3.0.dtd">
<hibernate-configuration>
    <session-factory>
    <property name="hibernate.dialect">org.hibernate.dialect.MySQLDialect</property>
    <property name="hibernate.connection.driver_class">com.mysql.jdbc.Driver</property>
    <property name="hibernate.connection.url">jdbc:mysql://localhost:3306/MyBase?zeroDateTimeBehavior=convertToNull&amp;autoReconnect=true</property>
    <property name="hibernate.connection.username">user</property>
    <property name="hibernate.connection.password">pass</property>
    <property name="hibernate.connection.provider_class">org.hibernate.c3p0.internal.C3P0ConnectionProvider</property>

    <property name="hibernate.current_session_context_class">thread</property>

    <property name="show_sql">true</property>
    <property name="use_sql_comments">true</property>

    <property name="hibernate.cache.use_second_level_cache">true</property>
    <property name="hibernate.cache.use_query_cache">true</property>
    <property name="hibernate.cache.region.factory_class">org.hibernate.cache.ehcache.EhCacheRegionFactory</property>
    </session-factory>
</hibernate-configuration>

c3p0-config.xml:

<?xml version="1.0" encoding="UTF-8"?>
<c3p0-config>
    <default-config>
    <property name="initialPoolSize">5</property>
    <property name="minPoolSize">5</property>
    <property name="maxPoolSize">10</property>
    <property name="checkoutTimeout">3000</property>
    <property name="maxStatementsPerConnection">30</property>

    <property name="preferredTestQuery">SELECT 1 FROM DUAL</property>
    <property name="testConnectionOnCheckin">true</property>
    <property name="testConnectionOnCheckout">false</property>
    <property name="idleConnectionTestPeriod">300</property> <!-- 5 minutes -->
    </default-config>
</c3p0-config>

With this c3p0 configuration:

  • Every 5 minutes of not performing any queries on connection it will be tested, so it will never be invalidated by DB (in standard configuration MySQL invalidates connection after 8 hours of inactivity),
  • If DB will be restarted or connection(s) will be manually killed we have two options: a) after max 5 minutes connections will be reestablished, b) if application tries to perform query before automatic connection reestablishing HibernateException will be thrown, then connection will be reestablished and next query will succeed.

Optionally testConnectionOnCheckout could be set to true to prevent exceptions, but it will cause performance troubles (see documentation).