User Tools

Site Tools


java:thelastpacketsuccessfullyreceivedfromserver

The last packet successfully received from the server was X milliseconds ago

Intro

This crap will be useful for you if...

This problem is soooooo common that the solutions described above should work in most of the cases, however, it wasn't my case:

  • My application worked perfectly
  • Mysql worked perfectly
  • There wasn't a network error
  • So… were the problem is???

My architecture

Before going on, I think it's important to describe what's my architecture. If it doesn't match yours, probably the solutions described here won't work in your case.

  • Mysql as database
  • C3P0 as connection pooling mechanism
  • Hibernate as data access layer
  • Spring to tie all together
  • A batch application that runs for hours and then stops. It only have one thread: starts, do thounsands of queries and then stops.

If you have the same problem, but in a web application, this please read on; some of the things described here are still useful or at least you should check them out.

First approach: retention of Session objects

Yes, I am new in hibernate and I miss out this:

http://stackoverflow.com/questions/14554353/database-connection-to-mysql-times-out-even-after-setting-c3p0-testconnectiononc

Apparently, the retention of Hibernate Sessions can more time than the value of wait_timeout can produce this problem.

This could be my case, because it happens that I found one Session object stored as a private property inside of a singleton: this property could be held for many time after the first query is made. And the first query was made in the creation of the database.

Steps to reproduce the problem

  1. Configure your wait_timeout value to a low value, like five minutes or less:
wait_timeout = 60 
# just in case 
interactive_timeout = 60
- **Make a test.** I've built the following test, which is pretty straightforward: 
    @Test
    public void test()
    {
        Period p = entityProvider.randomExistingPeriod();
 
        // issue a query
        StringBuilder hql = new StringBuilder();
 
        hql.append( "from Table where period = :period" );
 
        Query q = session.createQuery( hql.toString() );
        q.setEntity( "period", p );
 
        @SuppressWarnings("unchecked")
        List<Period> result = q.list();
 
        log.info( "Sleeping...." );
        try
        {
            Thread.sleep( 10 * 60 * 1000 ); // ten minutes
        }catch( InterruptedException ex )
        {
            log.info( "Awakening..." );
        }
 
        // issue a second query
        // issue a query
        StringBuilder hql2 = new StringBuilder();
 
        hql2.append( "from Table where period = :period" );
 
        Query q2 = session.createQuery( hql.toString() );
        q2.setEntity( "period", p );
 
        @SuppressWarnings("unchecked")
        List<Period> result2 = q2.list();
 
        assertNotNull( result );
        assertNotNull( result2 );
        assertTrue( result.size() > 0 );
        assertTrue( result2.size() > 0 );
 
    } // test

In other words;

  1. issue a valid query to the database
  2. wait an amount of time greater than the wait_timeout you have configured
  3. issue a valid query to the database. This second query will show up the problem
2013-09-03 15:52:53,634 DEBUG c3p0.impl.NewPooledConnection            - com.mchange.v2.c3p0.impl.NewPooledConnection@c22a3b invalidated by Exception.
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 600.214 milliseconds ago.  The last packet sent successfully to the server was 15 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:3090)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2979)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3520)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1990)
[....]

Solution

The solution is as easy as not keeping the hibernate Session object too much in memory. Saying this is easy, but achiving this….

For myself, it worked the following countermeasures:

  • Bear always in mind that the Session object can't be kept in memory too much time, and close as quick as you can
  • Avoid saving Session beans as members of classes; use it only in local variables will reduce the exposure to this problem
  • Lower the wait_timeout value for your application in development. I've discovered that lower values of wait_timeout in the config file are rejected, so it is best to have a small bean that issues this command upon execution for development: this will ensure you that only your application is enforced to work with this values instead of changing the values for all the database

To change the wait_timeout value for a particular session:

SET SESSION wait_timeout = 300;

A quick and dirty solution

In my case I have a batch application that longs for 24 hours. So putting a big value in wait_timeout will solve the problem. Here is how to do this programmatically:

mysql> SET global interactive_timeout = 172800;
Query OK, 0 ROWS affected (0.00 sec)
 
mysql> SET global wait_timeout = 172800;
Query OK, 0 ROWS affected (0.01 sec)

You have to change interactive_timeout also because, depeding on the type of session is starting, the value wait_timeout can be set to the value of ineractive_timeout.

A way to set lower values of wait_timeout only for our tests

I've developed a bean who issues mysql commands to the database. With this, I've configured it to set low wait_timeout values for the testing sessions. With this, all the tests made will use low values, hence allowing all the possible errors arise before they reach to production.

import java.util.ArrayList;
import java.util.List;
import java.util.Map;
 
import org.springframework.jdbc.core.simple.SimpleJdbcTemplate;
 
/**
 * Allows to set commands to the sql database, like set commands.
 *
 * @author RLUNARO
 *
 */
public class MysqlConfigurator
{
    private SimpleJdbcTemplate jdbc;
    private List<String> initialListOfCommands;
 
    public SimpleJdbcTemplate getJdbc()
    {
        return jdbc;
    }
 
    public void setJdbc(SimpleJdbcTemplate jdbc)
    {
        this.jdbc = jdbc;
    }
    public List<String> getInitialListOfCommands()
    {
        return initialListOfCommands;
    }
 
    public void setInitialListOfCommands(List<String> initialListOfCommands)
    {
        this.initialListOfCommands = initialListOfCommands;
    }
 
    /**
     * This method must be called upon set of the initial properties.
     */
    public void init()
    {
        // traverse list of commands and run them
        for( String command : initialListOfCommands )
        {
            issueStatement( command );
        } // command : initialListOfCommands
    }
 
    public void issueStatement( String command )
    {
        jdbc.update( command );
    }
 
    public String queryVariable( String variable )
    {
        String sql = "show variables like ? ";
        List<Object> args = new ArrayList<Object>();
        args.add( variable );
        List<Map<String,Object>> result = jdbc.queryForList( sql, args.toArray() );
        return (String) result.get(0).get( "Value" );
    }
 
}

And here is the spring configuration I am using (see below). I am using a singleton to load the bean at the beginning of the program and make sure that the values are set.

  <bean id="mysqlConfigurator"
        class="com.mapfre.dga.mercurio.mock.MysqlConfigurator"
        init-method="init"
        scope="singleton">
      <property name="jdbc" ref="simpleJdbcTemplate"/>
      <property name="getInitialListOfCommands">
        <list>
          <value>set session wait_timeout = 30</value>
        </list>
      </property>
   </bean>

Second Approach: be careful with your open sessions

After this, sometimes I have the same problem, others I get this error.

com.mchange.v2.resourcepool.TimeoutException: A client timed out while waiting to acquire a resource from com.mchange.v2.resourcepool.BasicResourcePool@1665147 -- timeout at awaitAvailable()
at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1317)
at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)

HibernateTemplate must be a singleton

Catch it!!! I had this:

    <bean id="hibernateTemplate"
          class="org.springframework.orm.hibernate3.HibernateTemplate"
          scope="prototype">
        <property name="sessionFactory" ref="sessionFactory"/>
    </bean>

An this is wrong. The HibernateTemplate object must be declared singleton (maybe “session” in a web application to avoid multithreading issues). This saves lots of session objects and keep them alive because they are always been called across the application.

However, I am starting to think that HibernateTemplate doesn't close properly it's Session objects. If this were the case, it will explain why when I release my HibernateTemplate objects the corresponding session objects weren't released and closed.

You can configure also when Hibernate release its session objects

I've discovered these things that I think they could help in solving the problem:

You can se the parameter “releaseMode” to the value “AFTER_STATEMENT” and let C3P0 get this open sessions to mysql back. With this, the open sessions that hibernate gets, are released in the quickest way. This is discouraged in the documentation, but bear in mind that if you have put a pooling mechanism, this could act as a safety net catching this connections and reusing them.

<!-- 
Possible values for this are:
     ON_CLOSE : legacy behavior. The session gets the connection when 
                the first time it requires it and release it when it's
                destroyed
     AFTER_TRANSACTION : 
                session is released after Transaction issues a commit or 
                rollback
     AFTER_STATEMENT : 
                connection is released after execution of every statement,
                BUT it will keep the connection open if the object 
 -->
<prop key="hibernate.connection.release_mode"></prop>

You can configure C3P0 to reopen used connections

For me, this have been the silver bullet that can fix a broken application whihout the need to go back to development to fix the issue.

The configuration parameter unreturnedConnectionTimeout does the following:

  1. When C3P0 gives a connection to the application, it starts a counter
  2. When this counter reaches this limit, C3P0 silently replaces this connection and gives another fresh open connection
  3. This parameter can avoid the problem that I had that C3P0 gave a connection and it went closed because it was retained open for days

However, it is discouraged because it hides problems in the application. But if it can save your day, take it into account.

You have also this parameter: debugUnreturnedConnectionStackTraces that can help to debug those connection that the application stores and doesn't return back until it's too late.

My final configuration of Spring

First, define C3P0 datasource:

	  <!--
	  A better datasource: it gives a new connection each time
	  is requested.
	  -->
	  <bean id="dataSource"
	        class="com.mchange.v2.c3p0.ComboPooledDataSource"
	        destroy-method="close"
	        scope="singleton">
      <!--
      To test a connection:
      mysql -h HOSTNAME -u USERNAME -p
      and aftwerwards introduce the password when requested

       -->
      <property name="driverClass" value="com.mysql.jdbc.Driver"/>
      <property name="jdbcUrl"     value="jdbc:mysql://${mysql-server}:${mysql-port}/${mysql-database}"/>
      <property name="user"        value="${mysql-user}"/>
      <property name="password"    value="${mysql-password}"/>
      <!--
      Recommended values for maxPoolSize and minPoolSize:
          1. get value of max available connections of your
             database issuing command 'show variables like "max_connections";'
          2. this will be the upper limit for maxPoolSize: you shouldn't
             reach never this limit
          3. check out with show processlist the active connections
             to the database: this will help to determine the available
             connections for your application:
             (show processlist) - (show variables like max_connections)
          4. it is advisable to identify how many DAO objects will be
             issuing sentences to the database at the same time. Ok,
             make a rough stimation. Say that this value will be
             10. A good and steady value for maxPoolSize can
             be 40 (four times).

       -->
			<property name="maxPoolSize"         value="10"/>
			<property name="minPoolSize"         value="5"/>
			<!--
			checkoutTimeout mits how long a client will wait for a
			Connection, if all Connections are checked out and one
			cannot be supplied immediately. In milliseconds.
			http://www.mchange.com/projects/c3p0/#checkoutTimeout
			-->
			<property name="checkoutTimeout"     value="10000"/>
			<property name="acquireIncrement"    value="1"/>
			<property name="idleConnectionTestPeriod" value="100"/>
			<!-- property name="preferredTestQuery"  value="select 1"/ -->
			<!--
			testConnectionOnCheckout is not recommended because it
			checks the connection before give it to hibernate. In a
			paranoid environment could fix some problems
			-->
			<!-- property name="testConnectionOnCheckout" value="true"/-->
			<!--
			debugUnreturnedConnectionStackTraces prints a stack trace when
			a connection that is given to hibernate reachs its timeout value.
			This could help to debug cases when a connection is taken and
			not released in a certain amount of time
			http://www.mchange.com/projects/c3p0/#debugUnreturnedConnectionStackTraces
			-->
			<!-- property name="debugUnreturnedConnectionStackTraces" value="true"/-->
			<!--
			unreturnedConnectionTimeout is the silver bullet for a problem in
			a greedy application (in terms of sessions). It will count how long
			hibernate has taken a connection, and if reachs a timeout, c3p0 will
			replace this connection with a fresh session, avoiding the problem
			of the database may close opened for much time
			http://www.mchange.com/projects/c3p0/#unreturnedConnectionTimeout
			-->
			<!--property name="unreturnedConnectionTimeout" value="100"/-->
	  </bean>

Second, the hibernateTemplate and jdbctemplate objects of spring will be available accross the application. Beware!!! If you are developing a web application, these should be session instead of singleton!!!

	  <bean id="simpleJdbcTemplate"
	        class="org.springframework.jdbc.core.simple.SimpleJdbcTemplate"
	        scope="singleton">
	    <constructor-arg ref="dataSource"/>
	  </bean>
 
    <bean id="hibernateTemplate"
          class="org.springframework.orm.hibernate3.HibernateTemplate"
          scope="singleton">
        <property name="sessionFactory" ref="sessionFactory"/>
    </bean>

Finally, the sessionFactory:

    <bean id="sessionFactory"
          class="org.springframework.orm.hibernate3.annotation.AnnotationSessionFactoryBean"
          scope="singleton">
        <property name="dataSource" ref="dataSource"/>
        <property name="annotatedClasses">
            <list>
                <value>com.mapfre.dga.mercurio.entity.Detail</value>
                <value>com.mapfre.dga.mercurio.entity.Indicator</value>
                <value>com.mapfre.dga.mercurio.entity.Period</value>
                <value>com.mapfre.dga.mercurio.entity.Struct</value>
                <value>com.mapfre.dga.mercurio.entity.Valoration</value>
                <value>com.mapfre.dga.mercurio.entity.Version</value>
            </list>
        </property>
        <property name="hibernateProperties">
            <props>
                <prop key="hibernate.dialect">org.hibernate.dialect.MySQL5Dialect</prop>
                <!-- for debug, put these values to "true" -->
                <prop key="hibernate.show_sql">${show-sql-in-hibernate}</prop>
                <prop key="hibernate.format_sql">${format-sql-in-hibernate}</prop>
 
                <!--
                Possible values for this are:
                     on_close : legacy behavior. The session gets the connection when
                                the first time it requires it and release it when it's
                                destroyed
                     after_transaction :
                                session is released after Transaction issues a commit or
                                rollback
                     after_statement :
                                connection is released after execution of every statement,
                                BUT it will keep the connection open if the object
                 -->
                <!-- prop key="hibernate.connection.release_mode">after_statement</prop -->
            </props>
        </property>
    </bean>

I've put plenty of comments of useful configuration parameters and lots of information, just in case.

Resources

java/thelastpacketsuccessfullyreceivedfromserver.txt · Last modified: 2014/12/24 10:42 (external edit)