使用休眠从断开的数据库连接中恢复

【问题标题】：Recovering from broken database connection with hibernate使用休眠从断开的数据库连接中恢复
【发布时间】：2015-08-06 14:18:14
【问题描述】：

我无法从断开的数据库连接中恢复。我的测试用例使用以下库。
guice-persist 4.0
休眠核心 4.3.1
HikariCP-java6-2.3.9（连接池）。

我的测试在循环中运行一个简单的读取，每次读取之间有一个小的睡眠。 

@com.google.inject.persist.Transactional
protected void simpleRead() {
  dao = new MyDao(....)
  dao.findBy(...)
}

Dao 像这样获取它的 entityManager

@Inject
protected com.google.inject.Provider<EntityManager> entityManager;

guice模块是这样绑定的

@Override
public void configure() {
  install(new JpaPersistModule("test"));
  bind(JPAInitializer.class).asEagerSingleton();
}

我的 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

我发现很难确定是哪一层造成了这个问题。根据我的阅读，连接池应该测试断开的连接并清理内容，但我怀疑它的 guice-persist 永远具有与其线程本地对象关联的损坏的 EntityManager 引用。当然，这也可能是我使用它们的方式。

编辑

经过进一步调查，我注意到如果在每次测试读取之间等待 > 1000 毫秒，则代码的行为与预期相同。我得到下面的 StackTrace，然后在我恢复 SQLServer 服务后，它很高兴地重新连接。任何小于 1000 毫秒的时间，我都会在原始帖子中收到上面列出的错误。似乎休眠没有以相同的方式处理 IO/错误，并且连接永远处于断开状态。

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

【问题讨论】：

  • 您能否为“JDBC 开始事务失败”异常提供全栈跟踪，包括一直到驱动程序的子原因？
  • 我已经添加了完整的堆栈。有趣的是，当我升级我的 Hikari 和 guice-persist 库时，这条消息发生了变化。在升级之前，我认为它说它无法回滚事务。

标签： hibernate hikaricp guice-persist


【解决方案1】：

您使用的是什么版本的 jTDS？看起来该版本的驱动程序没有使用包含以“08”开头的 SQLState 值（表示断开连接）的 SQLException 包装 SocketException。

HikariCP checks for these SQLStates 并将连接标记为驱逐。那个连接should be closed 并且再也没有回来。

jTDS 驱动程序appears 的较新版本可以正确处理它，如果我正确阅读他们的代码的话。

更新：这当然假设 Hibernate 在异常之后仍然关闭连接（就像在 finally 块中一样）。

UPDATE2：我错过了第二个异常部分，这对我来说似乎是一个 Hibernate 问题……没有从第一个异常中正确恢复。如果您为 com.zaxxer.hikari 包启用日志记录，您应该会看到有关连接被驱逐的警告。看到了吗？

更新3： 我查看了 jTDS 1.3.0，它正在做正确的事情。你can see here 它会生成一个 SQLState="08S01" 的 SQLException，will be checked 被 HikariCP 和连接驱逐。

现在更多的怀疑在于 Hibernate。我现在没有时间查看他们的代码，但我建议您使用堆栈跟踪中的行号。

【讨论】：

  • 我使用的是 JTDS-1.3.0 但刚刚尝试了 1.3.1 并得到了相同的结果。
  • jTDS 1.3.x 对我来说看起来不错，但我会更仔细地看。你能在 HikariCP 的 ConnectionProxy.checkException() 方法中设置一个断点，然后检查那里的 SQLException 和 SQLState 吗？
  • 我星期二一回到办公室就去。长周末在这里。非常感谢您的帮助。
  • 抱歉，我没有看到您帖子的更新。 SQLState 如您所说，并且确实到达了警告消息。我会试着开始往下看hibernate路线。
  • 如果您仍然感兴趣，我已经在我的原始帖子中添加了一些发现。
【解决方案2】：

我终于找到了问题，它是一个已知的hibernate bug，具有“拦截器”状态。

如果没有任何合理的解决方法，数据库恢复似乎是不可能的，或者至少非常不切实际。

【讨论】：

  • 问题以“rejected”的分辨率关闭:(似乎它仍然存在。
猜你喜欢
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2012-06-05
  • 2016-02-02
  • 2013-11-24
  • 2015-10-01
相关资源
最近更新 更多
热门标签
Java Python linux javascript Mysql C# Docker 算法 前端 SpringBoot Redis Vue spring 设计模式 .net core .net kubernetes c++ 数据库 数据结构 大数据 js 机器学习 微服务 Android Go 程序员 面试 JVM ASP.net core 云原生 人工智能 后端 PHP git CSS golang k8s Nginx Django mybatis 深度学习 多线程 React 架构 devops 爬虫 云计算 Spring Boot LeetCode