title: Database Connection to MySQL times out even after setting c3p0.testConnectionOnCheckout=true
body: <p>I have an app that uses hibernate (v3.6.4) , with connection pooling provided by C3P0 (v0.9.1.2) . </p>
  
  <p>The problem is I get a JDBC communications link failure if I make a DB query , if the app process ( and hence the C3P0 pool ) has been running for more time than the MySQL wait_timeout value. I set the value of wait_timeout in /etc/mysql/my.cnf to 600 seconds for testing this issue : </p>
  
  <pre><code>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
  </code></pre>
  
  <p>This looked like a common issue so in order to resolve this , I have tried to tune these hibernate / c3p0 properties after checking the hibernate / c3p0 documentation and answers to already asked questions on Stack Overflow :</p>
  
  <p>Relevant hibernate properties : </p>
  
  <pre><code>&lt;property name="hibernate.connection.driver_class"&gt;com.mysql.jdbc.Driver&lt;/property&gt;
  &lt;property name="hibernate.connection.url"&gt;jdbc:mysql://localhost:3306/gsui?useUnicode=true&amp;amp;characterEncoding=UTF-8&amp;amp;autoReconnect=true&lt;/property&gt;
  
  &lt;property name="hibernate.connection.autoReconnect"&gt;true&lt;/property&gt;
  
  &lt;!-- C3p0 Performance Improvements --&gt;
  &lt;property name="hibernate.c3p0.acquire_increment"&gt;1&lt;/property&gt;
  &lt;property name="hibernate.c3p0.idle_test_period"&gt;300&lt;/property&gt;
  &lt;property name="hibernate.c3p0.maxConnectionAge"&gt;3600&lt;/property&gt;
  &lt;property name="hibernate.c3p0.timeout"&gt;120&lt;/property&gt;
  &lt;property name="hibernate.c3p0.max_size"&gt;300&lt;/property&gt;
  &lt;property name="hibernate.c3p0.min_size"&gt;1&lt;/property&gt;
  &lt;property name="hibernate.c3p0.max_statements"&gt;100&lt;/property&gt;
  &lt;property name="hibernate.c3p0.preferredTestQuery"&gt;select 1;&lt;/property&gt;
  
  &lt;property name="hibernate.connection.useUnicode"&gt;
      true
  &lt;/property&gt;
  &lt;property name="hibernate.connection.characterEncoding"&gt;
      UTF-8
  &lt;/property&gt;
  &lt;property name="hibernate.connection.charSet"&gt;
      UTF-8
  &lt;/property&gt;
  </code></pre>
  
  <p>I also set c3p0.testConnectionOnCheckout to true in a c3p0 properties file I maintain : </p>
  
  <pre><code>c3p0.testConnectionOnCheckout=true
  </code></pre>
  
  <p>In the logs , the C3P0 pool initializes fine with the following messages : </p>
  
  <pre><code>2013-01-27 19:45:04,607  INFO [main] (ConnectionProviderFactory.java:173) - Initializing connection provider: org.hibernate.connection.C3P0ConnectionProvider
  2013-01-27 19:45:04,609  INFO [main] (C3P0ConnectionProvider.java:103) - C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/gsui?useUnicode=true&amp;characterEncoding=UTF-8&amp;autoReconnect=true
  2013-01-27 19:45:04,610  INFO [main] (C3P0ConnectionProvider.java:104) - Connection properties: {useUnicode=true, autoReconnect=true, user=root, password=****, shutdown=true, characterEncoding=UTF-8, charSet=UTF-8}
  2013-01-27 19:45:04,610  INFO [main] (C3P0ConnectionProvider.java:107) - autocommit mode: false
  2013-01-27 19:45:04,629  INFO [main] (MLog.java:80) - MLog clients using log4j logging.
  2013-01-27 19:45:04,757  INFO [main] (C3P0Registry.java:204) - Initializing c3p0-0.9.1.2 [built 21-May-2007 15:04:56; debug? true; trace: 10]
  2013-01-27 19:45:04,842  INFO [main] (C3P0ConnectionProvider.java:194) - JDBC isolation level: READ_COMMITTED
  2013-01-27 19:45:04,871  INFO [main] (AbstractPoolBackedDataSource.java:462) - Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@9f4a7137 [ connectionPoolDataSource -&gt; com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@71b9e1e9 [ acquireIncrement -&gt; 1, acquireRetryAttempts -&gt; 30, acquireRetryDelay -&gt; 1000, autoCommitOnClose -&gt; false, automaticTestTable -&gt; null, breakAfterAcquireFailure -&gt; false, checkoutTimeout -&gt; 0, connectionCustomizerClassName -&gt; null, connectionTesterClassName -&gt; com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -&gt; false, factoryClassLocation -&gt; null, forceIgnoreUnresolvedTransactions -&gt; false, identityToken -&gt; z8kfsx8sz4pted1s4b69w|51f726b9, idleConnectionTestPeriod -&gt; 300, initialPoolSize -&gt; 1, maxAdministrativeTaskTime -&gt; 0, maxConnectionAge -&gt; 3600, maxIdleTime -&gt; 120, maxIdleTimeExcessConnections -&gt; 0, maxPoolSize -&gt; 300, maxStatements -&gt; 100, maxStatementsPerConnection -&gt; 0, minPoolSize -&gt; 1, nestedDataSource -&gt; com.mchange.v2.c3p0.DriverManagerDataSource@58f45048 [ description -&gt; null, driverClass -&gt; null, factoryClassLocation -&gt; null, identityToken -&gt; z8kfsx8sz4pted1s4b69w|454b7177, jdbcUrl -&gt; jdbc:mysql://localhost:3306/gsui?useUnicode=true&amp;characterEncoding=UTF-8&amp;autoReconnect=true, properties -&gt; {useUnicode=true, autoReconnect=true, user=******, password=******, shutdown=true, characterEncoding=UTF-8, charSet=UTF-8} ], preferredTestQuery -&gt; select 1;, propertyCycle -&gt; 0, testConnectionOnCheckin -&gt; false, testConnectionOnCheckout -&gt; true, unreturnedConnectionTimeout -&gt; 0, usesTraditionalReflectiveProxies -&gt; false; userOverrides: {} ], dataSourceName -&gt; null, factoryClassLocation -&gt; null, identityToken -&gt; z8kfsx8sz4pted1s4b69w|71ffd9f1, numHelperThreads -&gt; 3 ]
  </code></pre>
  
  <p>From the above logs , one finds that testConnectionOnCheckout=true and autoReconnect=true in C3P0. Can someone help me figure out why C3P0 checks out a timed-out connection anyway ? Thanks.</p>