Połączenie z bazą danych do MySQL przekracza czas nawet po ustawieniu c3p0.testConnectionOnCheckout = true

Question

Mam aplikację, która używa hibernacji (v3.6.4), z pulą połączeń dostarczoną przez C3P0 (v0.9.1.2).

Problem polega na tym, że uzyskuję błąd łącza komunikacyjnego JDBC, jeśli wykonuję zapytanie DB, jeśli proces aplikacji (a więc i pula C3P0) działa dłużej niż wartość wait_timeout MySQL. I ustawić wartość wait_timeout w /etc/mysql/my.cnf do 600 sekund do testowania ten problem:

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 

ten wyglądał jak typowy problem tak, aby rozwiązać ten problem, próbowałem dostroić te hibernacji/właściwości C3P0 po sprawdzeniu dokumentacji C3P0/hibernacji i odpowiedzi na już zadawane pytania na przepełnienie stosu:

istotnych właściwości Hibernacja:

<property name="hibernate.connection.driver_class">com.mysql.jdbc.Driver</property> 
<property name="hibernate.connection.url">jdbc:mysql://localhost:3306/gsui?useUnicode=true&amp;characterEncoding=UTF-8&amp;autoReconnect=true</property> 

<property name="hibernate.connection.autoReconnect">true</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> 

<property name="hibernate.connection.useUnicode"> 
    true 
</property> 
<property name="hibernate.connection.characterEncoding"> 
    UTF-8 
</property> 
<property name="hibernate.connection.charSet"> 
    UTF-8 
</property> 

ja również ustawić c3p0.testConnectionOnCheckout się prawdziwe w pliku właściwości C3P0 utrzymuję :

c3p0.testConnectionOnCheckout=true 

w dziennikach, basen C3P0 inicjuje porządku z następujących komunikatów:

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&characterEncoding=UTF-8&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 -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@71b9e1e9 [ acquireIncrement -> 1, 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 -> z8kfsx8sz4pted1s4b69w|51f726b9, idleConnectionTestPeriod -> 300, initialPoolSize -> 1, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 3600, maxIdleTime -> 120, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 300, maxStatements -> 100, maxStatementsPerConnection -> 0, minPoolSize -> 1, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@58f45048 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> z8kfsx8sz4pted1s4b69w|454b7177, jdbcUrl -> jdbc:mysql://localhost:3306/gsui?useUnicode=true&characterEncoding=UTF-8&autoReconnect=true, properties -> {useUnicode=true, autoReconnect=true, user=******, password=******, shutdown=true, characterEncoding=UTF-8, charSet=UTF-8} ], preferredTestQuery -> select 1;, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> true, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> z8kfsx8sz4pted1s4b69w|71ffd9f1, numHelperThreads -> 3 ] 

Z powyższych logów, jeden stwierdzi testConnectionOnCheckout = true i autoReconnect = true w C3P0. Czy ktoś może mi pomóc dowiedzieć się, dlaczego C3P0 mimo to sprawdza przekroczenie limitu czasu? Dzięki.

Answer 1

Dodaj poniższą właściwość w pliku konfiguracyjnym hibernacji. Mam nadzieję, że to zadziała.

<property name="connection.provider_class"> 
    org.hibernate.connection.C3P0ConnectionProvider 
</property> 

Answer 2

Zaczęliśmy o tym samym „Komunikacja Link” problem kiedy zmodernizowane hibernacji do 4.3.x użyciem JPA i C3P0 dla puli połączeń.

Wygląda na to, że jest to problem z pulą połączeń, ponieważ połączenia były przechowywane dłużej niż baza danych wait_timeout (która była domyślna przez 8 godzin) pomimo moich ustawień C3P0. Jednak Naprawiłem problem poprzez zmianę konfiguracji hibernacji w naszym persistence.xml z:

<property name="hibernate.connection.release_mode" value="after_transaction" /> 

Wydaje się, że domyślne zachowanie w hibernacji zmieniona na nie zwalnia połączenie po operacji, więc trzeba jawnie ustawić ten tryb, jeśli” ponownie używać łączenia.