我有问题从数据库连接中断恢复。我的测试用例使用以下库。
guice-persist 4.0
Hibernate内核4.3.1
HikariCP-java6-2.3.9 (connection pool).
我的测试在一个循环中运行一个简单的读取，每次读取之间有一个小的睡眠。
@com.google.inject.persist.Transactional
protected void simpleRead() {
dao = new MyDao(....)
dao.findBy(...)
}
Dao像这样获得它的entityManager
@Inject
protected com.google.inject.Provider<EntityManager> entityManager;
向导模块是这样绑定的
@Override
public void configure() {
install(new JpaPersistModule("test"));
bind(JPAInitializer.class).asEagerSingleton();
}
My persistence.xml将事务类型定义为"RESOURCE-LOCAL"。
我有一些光的设置，但我不确定这些是否相关
<property name="hibernate.connection.provider_class" value="com.zaxxer.hikari.hibernate.HikariConnectionProvider" />
<property name="hibernate.hikari.maxLifetime" value="1800000" />
<property name="hibernate.hikari.connectionTestQuery" value="SELECT 1" />
<property name="hibernate.hikari.leakDetectionThreshold" value="300000" />
当测试循环读取时，我通过从任务管理器停止服务来中断SQLServer连接。如果循环不在simplRead()方法中，那么它会优雅地处理下一次尝试读取时的错误，并在服务再次启动时重新连接。但是，如果在服务停止时它在simpleRead()方法中，那么它将失败并且永远不会恢复。第一个失败报告如下
org.hibernate.TransactionException: JDBC begin transaction failed:
javax.persistence.PersistenceException: org.hibernate.TransactionException: JDBC begin transaction failed:
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1677)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1771)
at org.hibernate.jpa.internal.TransactionImpl.begin(TransactionImpl.java:64)
at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:66)
at net.impro.portal.server.model.dao.TestConnectionStuff.testConnectionBroken(TestConnectionStuff.java:40)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:80)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
at org.testng.TestRunner.privateRun(TestRunner.java:767)
at org.testng.TestRunner.run(TestRunner.java:617)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:334)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:329)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:291)
at org.testng.SuiteRunner.run(SuiteRunner.java:240)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1197)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1122)
at org.testng.TestNG.run(TestNG.java:1030)
at org.testng.remote.RemoteTestNG.run(RemoteTestNG.java:111)
at org.testng.remote.RemoteTestNG.initAndRun(RemoteTestNG.java:204)
at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:175)
Caused by: org.hibernate.TransactionException: JDBC begin transaction failed:
at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:76)
at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:162)
at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1431)
at org.hibernate.jpa.internal.TransactionImpl.begin(TransactionImpl.java:61)
... 26 more
Caused by: java.sql.SQLException: I/O Error: Connection reset by peer: socket write error
at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1059)
at net.sourceforge.jtds.jdbc.TdsCore.submitSQL(TdsCore.java:905)
at net.sourceforge.jtds.jdbc.JtdsConnection.setAutoCommit(JtdsConnection.java:2291)
at com.zaxxer.hikari.proxy.ConnectionProxy.setAutoCommit(ConnectionProxy.java:334)
at com.zaxxer.hikari.proxy.ConnectionJavassistProxy.setAutoCommit(ConnectionJavassistProxy.java)
at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:72)
... 29 more
Caused by: java.net.SocketException: Connection reset by peer: socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(Unknown Source)
at java.net.SocketOutputStream.write(Unknown Source)
at java.io.DataOutputStream.write(Unknown Source)
at net.sourceforge.jtds.jdbc.SharedSocket.sendNetPacket(SharedSocket.java:717)
at net.sourceforge.jtds.jdbc.RequestStream.putPacket(RequestStream.java:570)
at net.sourceforge.jtds.jdbc.RequestStream.flush(RequestStream.java:518)
at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1046)
... 34 more
...
由于现在不能正确地清理，随后的请求给出如下失败
org.hibernate.TransactionException: Already have an associated managed connection
我发现确定哪一层对这个问题负责并不容易。从我所读到的，连接池应该测试断开的连接并清理东西，但我怀疑它的引导-持久化永远有断开的EntityManager引用与其线程本地对象相关联。当然，这也可能是我使用它们的方式。
编辑在进一步调查之后，我注意到如果在每次测试读取之间等待> 1000ms，那么代码的行为与预期一致。我得到下面的StackTrace，然后在我恢复SQLServer服务后，它愉快地重新连接。任何少于1000毫秒，我得到上面在原始帖子中列出的错误。hibernate似乎不以同样的方式处理IO/Error，连接永远处于断开状态。
javax.persistence.QueryTimeoutException: Could not open connection
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1725)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1677)
at org.hibernate.jpa.spi.AbstractEntityManagerImpl.throwPersistenceException(AbstractEntityManagerImpl.java:1771)
at org.hibernate.jpa.internal.TransactionImpl.begin(TransactionImpl.java:64)
at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:66)
at net.impro.portal.server.model.dao.TestConnectionStuff.testConnectionBroken(TestConnectionStuff.java:40)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:80)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
at org.testng.TestRunner.privateRun(TestRunner.java:767)
at org.testng.TestRunner.run(TestRunner.java:617)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:334)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:329)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:291)
at org.testng.SuiteRunner.run(SuiteRunner.java:240)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1197)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1122)
at org.testng.TestNG.run(TestNG.java:1030)
at org.testng.remote.RemoteTestNG.run(RemoteTestNG.java:111)
at org.testng.remote.RemoteTestNG.initAndRun(RemoteTestNG.java:204)
at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:175)
Caused by: org.hibernate.QueryTimeoutException: Could not open connection
at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:83)
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.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:235)
at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:171)
at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67)
at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:162)
at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1471)
at org.hibernate.jpa.internal.TransactionImpl.begin(TransactionImpl.java:61)
... 26 more
Caused by: java.sql.SQLTimeoutException: Timeout after 30004ms of waiting for a connection.
at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233)
at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183)
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93)
at com.zaxxer.hikari.hibernate.HikariConnectionProvider.getConnection(HikariConnectionProvider.java:101)
at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380)
at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:228)
... 31 more
Caused by: java.sql.SQLException: Network error IOException: Connection refused: connect
at net.sourceforge.jtds.jdbc.JtdsConnection.<init>(JtdsConnection.java:436)
at net.sourceforge.jtds.jdbc.Driver.connect(Driver.java:184)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:95)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:101)
at com.zaxxer.hikari.pool.BaseHikariPool.addConnection(BaseHikariPool.java:444)
at com.zaxxer.hikari.pool.BaseHikariPool$1.run(BaseHikariPool.java:419)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: java.net.ConnectException: Connection refused: connect
at java.net.DualStackPlainSocketImpl.waitForConnect(Native Method)
at java.net.DualStackPlainSocketImpl.socketConnect(Unknown Source)
at java.net.AbstractPlainSocketImpl.doConnect(Unknown Source)
at java.net.AbstractPlainSocketImpl.connectToAddress(Unknown Source)
at java.net.AbstractPlainSocketImpl.connect(Unknown Source)
at java.net.PlainSocketImpl.connect(Unknown Source)
at java.net.SocksSocketImpl.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at net.sourceforge.jtds.jdbc.SharedSocket.createSocketForJDBC3(SharedSocket.java:288)
at net.sourceforge.jtds.jdbc.SharedSocket.<init>(SharedSocket.java:251)
at net.sourceforge.jtds.jdbc.JtdsConnection.<init>(JtdsConnection.java:331)
... 10 more
您使用的是哪个版本的jTDS ?看起来该版本的驱动程序没有将SocketException包装为包含SQLState值以'08'开头的SQLException(表示断开连接)。
HikariCP检查这些sqlstate并标记连接以退出。该连接应该被关闭，并且永远不再返回。
如果我正确阅读了jTDS驱动程序的代码，那么新版本的jTDS驱动程序似乎可以正确处理它。
UPDATE:这当然是假设Hibernate在异常之后仍然关闭连接(就像在finally块中一样)。
UPDATE2:我错过了第二个异常部分，这对我来说像是Hibernate问题…没有正确地从第一个异常中恢复。如果您启用了com.zaxxer.hikari包的日志记录，您应该看到一条关于连接被驱逐的警告。你看到了吗?
UPDATE3:我看了看jTDS 1.3.0，它正在做正确的事情。您可以在这里看到它将生成一个SQLState="08S01"的SQLException，它将由HikariCP检查并驱逐连接。
现在更多的怀疑落在Hibernate上。我现在没有时间看他们的代码，但我建议你看一下，使用堆栈跟踪中的行号。
我终于发现了问题，这是一个已知的休眠错误与"blocker"状态。
如果没有任何合理的解决方案，数据库恢复似乎是不可能的，或者至少是非常不切实际的。