Hibernate / MySQL connection timeouts -- Trying to deal with thread-pooled executors not releasing Hibernate connections to C3P0 after exit
Asked Answered
S

1

6

I have a Tomcat application that uses MySQL, and Hibernate for ORM. The nature of our application demands that we have to pull and aggregate a lot of analytics data from a NoSQL store for each request , so we split the pulling and aggregating for each request into several tasks and delegate those to a thread-pooled executor service.

When each thread performs a task, it needs to query / update MySQL regarding certain things so it borrows Hibernate sessions from C3P0 ( which we use for connection pooling ).

Essential config :

    <property name="current_session_context_class">thread</property>
    <property name="connection.provider_class">org.hibernate.connection.C3P0ConnectionProvider</property>
    <property name="hibernate.connection.shutdown">true</property>
    <property name="hibernate.use_sql_comments">false</property>

<!-- C3p0 Performance Improvements -->
    <property name="hibernate.c3p0.acquire_increment">1</property>
    <property name="hibernate.c3p0.idle_test_period">300</property>
    <property name="hibernate.c3p0.maxConnectionAge">3600</property>
    <property name="hibernate.c3p0.timeout">120</property>
    <property name="hibernate.c3p0.max_size">300</property>
    <property name="hibernate.c3p0.min_size">1</property>
    <property name="hibernate.c3p0.max_statements">100</property>
    <property name="hibernate.c3p0.preferredTestQuery">select 1;</property>

The problem is Hibernate requests cause the MySQL / JDBC connection timeout error after 8 hours (our configured value of MySQL's wait_timeout parameter is the default i.e. 8 hours) . I replicated this by setting wait_timeout to 11 minutes but the result is the same for a 8-hour wait_timeout as well :

2013-01-27 20:08:00,088 ERROR [Thread-0] (JDBCExceptionReporter.java:234) - Communications link failure

The last packet successfully received from the server was 665,943 milliseconds ago.  The last packet sent successfully to the server was 6 milliseconds ago.
org.hibernate.exception.JDBCConnectionException: could not execute query
  at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:99)
  at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
  at org.hibernate.loader.Loader.doList(Loader.java:2536)
  at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2276)
  at org.hibernate.loader.Loader.list(Loader.java:2271)
  at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:119)
  at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1716)
  at org.hibernate.impl.CriteriaImpl.list(CriteriaImpl.java:347) 
  .....
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
The last packet successfully received from the server was 665,943 milliseconds ago.  The last packet sent successfully to the server was 6 milliseconds ago.
  at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
  at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
  at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
  at java.lang.reflect.Constructor.newInstance(Unknown Source)
  at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
  at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116)
  at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3102)
  at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2991)
  at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3532)
  at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002)
  at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163)
  at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2624)
  at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2127)
  at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2293)
  at  com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76)
  at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:208)
  at org.hibernate.loader.Loader.getResultSet(Loader.java:1953)
  at org.hibernate.loader.Loader.doQuery(Loader.java:802)
  at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:274)
  at org.hibernate.loader.Loader.doList(Loader.java:2533)
  ... 9 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:2552)
  at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3002)
  ... 22 more

2013-01-27 20:19:00,179  WARN [Thread-0] (NewPooledConnection.java:487) - [c3p0] Another error has occurred [ com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 1,326,037 milliseconds ago.  The last packet sent successfully to the server was 660,100 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. ] which will not be reported to listeners!
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 1,326,037 milliseconds ago.  The last packet sent successfully to the server was 660,100 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(Unknown Source)
  at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
  at java.lang.reflect.Constructor.newInstance(Unknown Source)
  at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
  at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116)
  at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3364)
  at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1983)
  at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163)
  at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2624)
  at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2127)
  at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2293)
  at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76)
  at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:208)
  at org.hibernate.loader.Loader.getResultSet(Loader.java:1953)
  at org.hibernate.loader.Loader.doQuery(Loader.java:802)
  at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:274)
  at org.hibernate.loader.Loader.doList(Loader.java:2533)
  at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2276)
  at org.hibernate.loader.Loader.list(Loader.java:2271)
  at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:119)
  at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1716)
  at org.hibernate.impl.CriteriaImpl.list(CriteriaImpl.java:347)
  ....
Caused by: java.net.SocketException: Broken pipe
  at java.net.SocketOutputStream.socketWrite0(Native Method)
  at java.net.SocketOutputStream.socketWrite(Unknown Source)
  at java.net.SocketOutputStream.write(Unknown Source)
  at java.io.BufferedOutputStream.flushBuffer(Unknown Source)
  at java.io.BufferedOutputStream.flush(Unknown Source)
  at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3345)
  ... 20 more

I thought C3P0 wasn't evicting stale connections frequently enough, so that during heavy load a connection would be returned to the pool, go stale and be borrowed again before eviction. So I created a c3p0.properties file and set "c3p0.testConnectionsOnCheckout" to true so that no stale connections would be borrowed from the pool. I got the same error again.

I figured that since my hibernate sessions are configured with session-context "thread" , sessions used by a thread aren't released until a transaction is committed or rolled back [ http://docs.jboss.org/hibernate/orm/3.6/javadocs/org/hibernate/context/ThreadLocalSessionContext.html ] . So the only explanation I have is that the executor threads make read-only DB calls where there's no committing going on , and once the task is done, the thread returns to the pool , holding the session with it.

What should I do here ? Our application has hibernate querying code inside Data-Access-Object classes, one for each kind of bean. I wish to avoid having to change each and every method in those classes that makes read-only DB calls so as to have them "commit" unnecessarily. I also wish to minimize the changes to the business logic of our app.

Is there a way I can check for the freshness of the session returned by sessionFactory.getCurrentSession() each time a Data-Access-Object is declared / used (all Data-Access-Object classes inherit a few things from a single base class, so I can change things in that base class constructor) , and maybe return stale sessions to the pool ? Or is there a better way to do it ?

Thanks.

Silviasilviculture answered 23/5, 2013 at 17:45 Comment(0)
I
0

NOTE: the below is based on an Oracle example, but can be modified for MySQL.

I have gotten around this problem of dropped connections by using Tomcat managed databased connections. This can be done by creating a context.xml file in your META-INF directory, something like this:

<Context crossContext="true" docBase="myBase" path="/myBase" reloadable="false" useHttpOnly="true">
    <ResourceLink global="jdbc/dbOne" name="jdbc/dbOne" type="javax.sql.DataSource" />
    <!-- Need another DB? -->   
    <!-- <ResourceLink global="jdbc/dbTwo" name="jdbc/dbTwo" type="javax.sql.DataSource" /> -->
</Context>

To create the connection your Tomcat server.xml file must also be updated. The below is based on Tomcat 6.0.26.:

<!-- Global JNDI resources
   Documentation at /docs/jndi-resources-howto.html
-->
<GlobalNamingResources>
<!-- Editable user database that can also be used by
     UserDatabaseRealm to authenticate users
-->
<Resource name="UserDatabase" auth="Container"
          type="org.apache.catalina.UserDatabase"
          description="User database that can be updated and saved"
          factory="org.apache.catalina.users.MemoryUserDatabaseFactory"
          pathname="conf/tomcat-users.xml" />

    <!-- START MY MODS -->
    <!-- Add the db connection(s)! The rest is standard in the server.xml file.-->        
    <Resource auth="Container" driverClassName="oracle.jdbc.driver.OracleDriver" initialSize="2" logAbandoned="true" maxActive="5" maxIdle="2" maxWait="120000" minEvictableIdleTimeMillis="1800000" minIdle="1" name="jdbc/dbOne" numTestsPerEvictionRun="3" password="openPlease" removeAbandoned="true" removeAbandonedTimeout="60" testOnBorrow="true" testOnReturn="true" testWhileIdle="true" timeBetweenEvictionRunsMillis="900000" type="javax.sql.DataSource" url="jdbc:oracle:thin:@servername:portnumber:schema" username="myUser" validationQuery="select sysdate from dual"/>  
    <!-- Need another connection? Copy and past the above making the required changes. -->
    <!-- END MY MODS -->

Then in my hibernate.cfg.xml file I have specified:

<!-- Connection handling -->
<property name="connection.datasource">java:/comp/env/jdbc/dbOne</property>
<property name="dialect">org.hibernate.dialect.Oracle10gDialect</property>
<property name="connection.autoReconnect">true</property>
<property name="connection.autoReconnectForPools">true</property>
<property name="connection.is-connection-validation-required">true</property>
<property name="current_session_context_class">thread</property>

Having said that, the following config using just C3P0 worked for me as well, but I now prefer Tomcat managed connections as they can be shared between the apps on my Tomcat server, which is desirable in my case.

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-configuration PUBLIC
        "-//Hibernate/Hibernate Configuration DTD 3.0//EN"
        "http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd">
<hibernate-configuration>
    <session-factory>
        <property name="hibernate.connection.driver_class">oracle.jdbc.driver.OracleDriver</property>
        <property name="hibernate.connection.password">@dbPassword@</property>
        <property name="hibernate.connection.url">@dbURL@</property>
        <property name="hibernate.connection.username">someUser</property>
        <property name="dialect">org.hibernate.dialect.Oracle10gDialect</property>

        <property name="show_sql">false</property>
        <property name="format_sql">false</property>
        <property name="current_session_context_class">thread</property>

        <!-- Connection handling -->
        <property name="connection.autoReconnect">true</property>
        <property name="connection.autoReconnectForPools">true</property>
        <property name="connection.is-connection-validation-required">true</property>
        <property name="current_session_context_class">thread</property>
        <property name="max_fetch_depth">1</property>

        <property name="hibernate.connection.provider_class">org.hibernate.connection.C3P0ConnectionProvider</property>  
        <property name="hibernate.c3p0.breakAfterAcquireFailure">false</property>
        <property name="hibernate.c3p0.acquireRetryAttempts">-1</property>
        <property name="hibernate.c3p0.acquireRetryDelay">3000</property>
        <property name="hibernate.c3p0.automaticTestTable">C3P0_TEST</property> <!-- c3p0 uses this table for testing connection. -->
        <property name="hibernate.c3p0.initialPoolSize">2</property> <!-- 3 is c3p0 default. -->
        <property name="hibernate.c3p0.minPoolSize">2</property> <!-- 1 is Hibernate default. -->
        <property name="hibernate.c3p0.maxPoolSize">6</property> <!-- 100 is Hibernate default. -->
        <property name="hibernate.c3p0.acquireIncrement">2</property> <!-- 3 is c3p0 default. -->
        <property name="hibernate.c3p0.maxIdleTimeExcessConnections">600</property> <!-- 0 seconds is c3p0 default and means do not check. This is the num of seconds a connections in excess of minPoolSize are permitted to remain idle in the pool before being culled. -->
        <property name="hibernate.c3p0.idleConnectionTestPeriod">30</property> <!-- 0 seconds is the c3p0 default and means do not check. (i.e. never test). Using only this provides the best performance even if individuals may occasionally receive an error message due to a connection being dropped. -->

        <!-- Cache setup -->
        <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">net.sf.ehcache.hibernate.EhCacheRegionFactory</property>
       <!-- <property name="hibernate.cache.provider_class">net.sf.ehcache.hibernate.SingletonEhCacheProvider</property> -->

        <property name="cache.use_minimal_puts">true</property>
        <property name="hibernate.generate_statistics">true</property>
        <property name="hibernate.cache.use_structured_entries">true</property>

        <!-- Mapping files -->
        ...

       </session-factory>

</hibernate-configuration>
Incus answered 12/6, 2013 at 17:59 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.