DatabaseAccessor 在高负载场景下未连接
DatabaseAccessor not connected in a high load scenario
我在追查应用程序中“EclipseLink-4005 (..) DatabaseAccessor not connected”错误的罪魁祸首时遇到了问题。它是一个独立的应用程序（不是网络应用程序），有多个线程连接到同一个数据库（Oracle）。我们使用 EclipseLink 2.4.2 及其默认设置的内部连接池。交易在应用程序中管理，可以嵌套。该应用程序大部分时间都运行良好，但偶尔会在高负载下失败并显示“EclipseLink-4005 (..) DatabaseAccessor not connected”错误。
我能够在我们的测试环境中重现错误，但无法理解在什么条件下可能会发生错误。有些交易很长 运行。是否有可能其中一些超时，导致相应的会话注销并导致另一个线程中的错误？
下面是示例堆栈跟踪：
Exception [EclipseLink-4005] (Eclipse Persistence Services - 2.4.2.v20130514-5956486): org.eclipse.persistence.exceptions.DatabaseException
Exception Description: DatabaseAccessor not connected.
at org.eclipse.persistence.exceptions.DatabaseException.databaseAccessorNotConnected(DatabaseException.java:116)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:309)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.beginTransaction(DatasourceAccessor.java:238)
at org.eclipse.persistence.internal.sessions.AbstractSession.basicBeginTransaction(AbstractSession.java:526)
at org.eclipse.persistence.sessions.server.ClientSession.addWriteConnection(ClientSession.java:693)
at org.eclipse.persistence.sessions.server.ServerSession.acquireClientConnection(ServerSession.java:246)
at org.eclipse.persistence.sessions.server.ClientSession.getAccessor(ClientSession.java:333)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.getAccessor(UnitOfWorkImpl.java:1867)
at org.eclipse.persistence.internal.jpa.EntityManagerImpl.unwrap(EntityManagerImpl.java:2540)
(..)
和
Exception [EclipseLink-4005] (Eclipse Persistence Services - 2.4.2.v20130514-5956486): org.eclipse.persistence.exceptions.DatabaseException
Exception Description: DatabaseAccessor not connected.
at org.eclipse.persistence.exceptions.DatabaseException.databaseAccessorNotConnected(DatabaseException.java:116)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:309)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.rollbackTransaction(DatasourceAccessor.java:671)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.rollbackTransaction(DatabaseAccessor.java:1576)
at org.eclipse.persistence.internal.sessions.AbstractSession.basicRollbackTransaction(AbstractSession.java:629)
at org.eclipse.persistence.sessions.server.ClientSession.basicRollbackTransaction(ClientSession.java:186)
at org.eclipse.persistence.internal.sessions.AbstractSession.rollbackTransaction(AbstractSession.java:3561)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.rollbackTransaction(UnitOfWorkImpl.java:4641)
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.rollbackTransaction(RepeatableWriteUnitOfWork.java:522)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.release(UnitOfWorkImpl.java:4448)
at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.rollback(EntityTransactionImpl.java:127)
(..)
如果您需要更多信息，请告诉我。我很乐意分享它，因为我目前没有想法。
启用 EclipseLink 日志记录后的更多信息。
在日志中，我发现连接在错误发生前不久断开（见下文）。我的第一个想法是，这是因为它被标记为无效（使用 DatabaseAccessor.setIsValid），但在错误之前发生的唯一问题是 30 分钟前抛出的 OptimisticLockException，它很优雅由应用程序处理。此外，在接下来的半小时内，同样的连接被愉快地使用，所以我不认为它被标记为无效。
TRACE [2017-09-01 10:01:04.851/-0700] [Worker-659:org.eclipse.persistence.transaction] [ ] 2017-09-01 10:01:04.851--ClientSession(436256688)--Connection(148152749)--Thread(Thread[Worker-659,5,main])-- commit transaction
TRACE [2017-09-01 10:01:04.914/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.914--ServerSession(441145695)--Connection(148152749)--Thread(Thread[Worker-659,5,main])-- Connection released to connection pool [default].
DEBUG [2017-09-01 10:01:04.914/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.914--ServerSession(441145695)--Connection(148152749)--Thread(Thread[Worker-659,5,main])-- disconnect
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.transaction] [ ] 2017-09-01 10:01:04.929--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])-- end unit of work commit
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.transaction] [ ] 2017-09-01 10:01:04.929--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])-- resume unit of work
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.transaction] [ ] 2017-09-01 10:01:04.929--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])-- release unit of work
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.929--ClientSession(436256688)--Thread(Thread[Worker-659,5,main])-- client released
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.query] [ ] 2017-09-01 10:01:04.929--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])-- Execute query ReadAllQuery(...)
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.929--ServerSession(441145695)--Connection(985262420)--Thread(Thread[Worker-659,5,main])-- Connection acquired from connection pool [default].
TRACE [2017-09-01 10:01:04.961/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.961--ServerSession(441145695)--Connection(985262420)--Thread(Thread[Worker-659,5,main])-- Connection released to connection pool [default].
WARN [2017-09-01 10:01:04.961/-0700] [Worker-659:org.eclipse.persistence] [ ] 2017-09-01 10:01:04.961--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])--
Local Exception Stack:
Exception [EclipseLink-4005] (Eclipse Persistence Services - 2.4.2.v20130514-5956486): org.eclipse.persistence.exceptions.DatabaseException
Exception Description: DatabaseAccessor not connected.
at org.eclipse.persistence.exceptions.DatabaseException.databaseAccessorNotConnected(DatabaseException.java:116)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:309)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:581)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:537)
at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1805)
at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:566)
(..)
是否有任何其他原因可能会断开连接？
请允许我回答我自己的问题，以便其他人可以从我的发现中受益。
问题原来是由 Eclipse Link 中的错误引起的。请参阅 bug 432410，在撰写本文时仍处于打开状态。
在我的特殊情况下，解决方案是避免展开连接，即不要调用 EntityManager.unwrap(Connection.class)
我在追查应用程序中“EclipseLink-4005 (..) DatabaseAccessor not connected”错误的罪魁祸首时遇到了问题。它是一个独立的应用程序（不是网络应用程序），有多个线程连接到同一个数据库（Oracle）。我们使用 EclipseLink 2.4.2 及其默认设置的内部连接池。交易在应用程序中管理，可以嵌套。该应用程序大部分时间都运行良好，但偶尔会在高负载下失败并显示“EclipseLink-4005 (..) DatabaseAccessor not connected”错误。
我能够在我们的测试环境中重现错误，但无法理解在什么条件下可能会发生错误。有些交易很长 运行。是否有可能其中一些超时，导致相应的会话注销并导致另一个线程中的错误？
下面是示例堆栈跟踪：
Exception [EclipseLink-4005] (Eclipse Persistence Services - 2.4.2.v20130514-5956486): org.eclipse.persistence.exceptions.DatabaseException
Exception Description: DatabaseAccessor not connected.
at org.eclipse.persistence.exceptions.DatabaseException.databaseAccessorNotConnected(DatabaseException.java:116)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:309)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.beginTransaction(DatasourceAccessor.java:238)
at org.eclipse.persistence.internal.sessions.AbstractSession.basicBeginTransaction(AbstractSession.java:526)
at org.eclipse.persistence.sessions.server.ClientSession.addWriteConnection(ClientSession.java:693)
at org.eclipse.persistence.sessions.server.ServerSession.acquireClientConnection(ServerSession.java:246)
at org.eclipse.persistence.sessions.server.ClientSession.getAccessor(ClientSession.java:333)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.getAccessor(UnitOfWorkImpl.java:1867)
at org.eclipse.persistence.internal.jpa.EntityManagerImpl.unwrap(EntityManagerImpl.java:2540)
(..)
和
Exception [EclipseLink-4005] (Eclipse Persistence Services - 2.4.2.v20130514-5956486): org.eclipse.persistence.exceptions.DatabaseException
Exception Description: DatabaseAccessor not connected.
at org.eclipse.persistence.exceptions.DatabaseException.databaseAccessorNotConnected(DatabaseException.java:116)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:309)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.rollbackTransaction(DatasourceAccessor.java:671)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.rollbackTransaction(DatabaseAccessor.java:1576)
at org.eclipse.persistence.internal.sessions.AbstractSession.basicRollbackTransaction(AbstractSession.java:629)
at org.eclipse.persistence.sessions.server.ClientSession.basicRollbackTransaction(ClientSession.java:186)
at org.eclipse.persistence.internal.sessions.AbstractSession.rollbackTransaction(AbstractSession.java:3561)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.rollbackTransaction(UnitOfWorkImpl.java:4641)
at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.rollbackTransaction(RepeatableWriteUnitOfWork.java:522)
at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.release(UnitOfWorkImpl.java:4448)
at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.rollback(EntityTransactionImpl.java:127)
(..)
如果您需要更多信息，请告诉我。我很乐意分享它，因为我目前没有想法。
启用 EclipseLink 日志记录后的更多信息。
在日志中，我发现连接在错误发生前不久断开（见下文）。我的第一个想法是，这是因为它被标记为无效（使用 DatabaseAccessor.setIsValid），但在错误之前发生的唯一问题是 30 分钟前抛出的 OptimisticLockException，它很优雅由应用程序处理。此外，在接下来的半小时内，同样的连接被愉快地使用，所以我不认为它被标记为无效。
TRACE [2017-09-01 10:01:04.851/-0700] [Worker-659:org.eclipse.persistence.transaction] [ ] 2017-09-01 10:01:04.851--ClientSession(436256688)--Connection(148152749)--Thread(Thread[Worker-659,5,main])-- commit transaction
TRACE [2017-09-01 10:01:04.914/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.914--ServerSession(441145695)--Connection(148152749)--Thread(Thread[Worker-659,5,main])-- Connection released to connection pool [default].
DEBUG [2017-09-01 10:01:04.914/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.914--ServerSession(441145695)--Connection(148152749)--Thread(Thread[Worker-659,5,main])-- disconnect
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.transaction] [ ] 2017-09-01 10:01:04.929--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])-- end unit of work commit
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.transaction] [ ] 2017-09-01 10:01:04.929--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])-- resume unit of work
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.transaction] [ ] 2017-09-01 10:01:04.929--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])-- release unit of work
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.929--ClientSession(436256688)--Thread(Thread[Worker-659,5,main])-- client released
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.query] [ ] 2017-09-01 10:01:04.929--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])-- Execute query ReadAllQuery(...)
TRACE [2017-09-01 10:01:04.929/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.929--ServerSession(441145695)--Connection(985262420)--Thread(Thread[Worker-659,5,main])-- Connection acquired from connection pool [default].
TRACE [2017-09-01 10:01:04.961/-0700] [Worker-659:org.eclipse.persistence.connection] [ ] 2017-09-01 10:01:04.961--ServerSession(441145695)--Connection(985262420)--Thread(Thread[Worker-659,5,main])-- Connection released to connection pool [default].
WARN [2017-09-01 10:01:04.961/-0700] [Worker-659:org.eclipse.persistence] [ ] 2017-09-01 10:01:04.961--UnitOfWork(122187888)--Thread(Thread[Worker-659,5,main])--
Local Exception Stack:
Exception [EclipseLink-4005] (Eclipse Persistence Services - 2.4.2.v20130514-5956486): org.eclipse.persistence.exceptions.DatabaseException
Exception Description: DatabaseAccessor not connected.
at org.eclipse.persistence.exceptions.DatabaseException.databaseAccessorNotConnected(DatabaseException.java:116)
at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:309)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:581)
at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:537)
at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1805)
at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:566)
(..)
是否有任何其他原因可能会断开连接？
请允许我回答我自己的问题，以便其他人可以从我的发现中受益。
问题原来是由 Eclipse Link 中的错误引起的。请参阅 bug 432410，在撰写本文时仍处于打开状态。
在我的特殊情况下，解决方案是避免展开连接，即不要调用 EntityManager.unwrap(Connection.class)