Scott Marlow (
https://hibernate.atlassian.net/secure/ViewProfile.jspa?accountId=557058%...
) *commented* on HHH-16275 (
https://hibernate.atlassian.net/browse/HHH-16275?atlOrigin=eyJpIjoiMzRkN2...
)
Re: LockTest.testLock*FkTarget fail on Sybase with timeout getting lock (
https://hibernate.atlassian.net/browse/HHH-16275?atlOrigin=eyJpIjoiMzRkN2...
)
With internal testing, we sometimes see failures with Oracle 19, I think while executing
the insert:
Took 4 sec
jakarta.persistence.RollbackException: Error while committing the transaction
at
app//org.hibernate.internal.ExceptionConverterImpl.convertCommitException(ExceptionConverterImpl.java:65)
at
app//org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:104)
at
app//org.hibernate.testing.transaction.TransactionUtil.doInJPA(TransactionUtil.java:260)
at
app//org.hibernate.testing.transaction.TransactionUtil.doInJPA(TransactionUtil.java:299)
at
app//org.hibernate.orm.test.jpa.lock.LockTest.lambda$testLockInsertFkTarget$79(LockTest.java:1193)
at
app//org.hibernate.testing.transaction.TransactionUtil.doInJPA(TransactionUtil.java:258)
at
app//org.hibernate.testing.transaction.TransactionUtil.doInJPA(TransactionUtil.java:299)
at
app//org.hibernate.orm.test.jpa.lock.LockTest.testLockInsertFkTarget(LockTest.java:1188)
at java.base(a)11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base@11.0.18/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base@11.0.18/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base@11.0.18/java.lang.reflect.Method.invoke(Method.java:566)
at
app//org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
at
app//org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
app//org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
at
app//org.hibernate.testing.junit4.ExtendedFrameworkMethod.invokeExplosively(ExtendedFrameworkMethod.java:45)
at app//org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
app//org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:299)
at
app//org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:293)
at java.base@11.0.18/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base@11.0.18/java.lang.Thread.run(Thread.java:834)
Caused by: org.hibernate.exception.JDBCConnectionException: could not execute statement
[IO Error: Socket read timed out] [insert into LockReference (lock_id,name,id) values
(?,?,?)]
at
app//org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:98)
at
app//org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:56)
at
app//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108)
at
app//org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:278)
at
app//org.hibernate.engine.jdbc.mutation.internal.AbstractMutationExecutor.performNonBatchedMutation(AbstractMutationExecutor.java:108)
at
app//org.hibernate.engine.jdbc.mutation.internal.MutationExecutorSingleNonBatched.performNonBatchedOperations(MutationExecutorSingleNonBatched.java:40)
at
app//org.hibernate.engine.jdbc.mutation.internal.AbstractMutationExecutor.execute(AbstractMutationExecutor.java:53)
at
app//org.hibernate.persister.entity.mutation.InsertCoordinator.doStaticInserts(InsertCoordinator.java:170)
at
app//org.hibernate.persister.entity.mutation.InsertCoordinator.coordinateInsert(InsertCoordinator.java:112)
at
app//org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2709)
at
app//org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:102)
at app//org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:618)
at
app//org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:489)
at java.base@11.0.18/java.util.LinkedHashMap.forEach(LinkedHashMap.java:684)
at app//org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:486)
at
app//org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:358)
at
app//org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
at
app//org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:127)
at app//org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1412)
at app//org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:485)
at
app//org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2296)
at
app//org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:1961)
at
app//org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:439)
at
app//org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:169)
at
app//org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:267)
at
app//org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
... 19 more
Caused by: java.sql.SQLRecoverableException: IO Error: Socket read timed out
at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:993)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1205)
at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3666)
at
oracle.jdbc.driver.T4CPreparedStatement.executeInternal(T4CPreparedStatement.java:1426)
at
oracle.jdbc.driver.OraclePreparedStatement.executeLargeUpdate(OraclePreparedStatement.java:3756)
at
oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:3736)
at
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeUpdate(OraclePreparedStatementWrapper.java:1063)
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:275)
... 41 more
Caused by: oracle.net.nt.TimeoutInterruptHandler$IOReadTimeoutException: Socket read timed
out
at app//oracle.net.nt.TimeoutSocketChannel.handleInterrupt(TimeoutSocketChannel.java:262)
at app//oracle.net.nt.TimeoutSocketChannel.read(TimeoutSocketChannel.java:188)
at app//oracle.net.ns.NSProtocolNIO.doSocketRead(NSProtocolNIO.java:572)
at app//oracle.net.ns.NIOPacket.readHeader(NIOPacket.java:263)
at app//oracle.net.ns.NIOPacket.readPacketFromSocketChannel(NIOPacket.java:195)
at app//oracle.net.ns.NIOPacket.readFromSocketChannel(NIOPacket.java:137)
at app//oracle.net.ns.NIOPacket.readFromSocketChannel(NIOPacket.java:110)
at
app//oracle.net.ns.NIONSDataChannel.readDataFromSocketChannel(NIONSDataChannel.java:91)
at app//oracle.jdbc.driver.T4CMAREngineNIO.prepareForUnmarshall(T4CMAREngineNIO.java:791)
at app//oracle.jdbc.driver.T4CMAREngineNIO.unmarshalUB1(T4CMAREngineNIO.java:449)
at app//oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:410)
at app//oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:269)
at app//oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:655)
at app//oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:270)
at app//oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:91)
at
app//oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:970)
... 48 more
Sometimes the same test also passes so clearly Hibernate ORM is working correctly some of
the time. I suspect that Hibernate ORM is also working correctly all of the time actually
as our internal Oracle testing is using a Oracle 19 server that deals with multiple tests
concurrently for which the current one second timeout is not long enough to wait.
We could consider updating the test to call TransactionUtil.setJdbcTimeout(
entityManager.unwrap( Session.class ), 4000L ) instead of TransactionUtil.setJdbcTimeout(
entityManager.unwrap( Session.class ) but even the 4000L milliseconds may not be long
enough. Another thought is we could consider updating the test to wait no longer then one
minute which could be helpful. I’ll create a pr with a change.
(
https://hibernate.atlassian.net/browse/HHH-16275#add-comment?atlOrigin=ey...
) Add Comment (
https://hibernate.atlassian.net/browse/HHH-16275#add-comment?atlOrigin=ey...
)
Get Jira notifications on your phone! Download the Jira Cloud app for Android (
https://play.google.com/store/apps/details?id=com.atlassian.android.jira....
) or iOS (
https://itunes.apple.com/app/apple-store/id1006972087?pt=696495&ct=Em...
) This message was sent by Atlassian Jira (v1001.0.0-SNAPSHOT#100225- sha1:4a1ccf9 )