search

eclipse-ee4j / eclipselink

Eclipselink project
https://eclipse.dev/eclipselink/
Other
201 stars 170 forks source link

Getting "Could not open JPA EntityManager" because of "Connection is not available, request timed out after 30000ms" with HikariCP Datasource in Spring #2219

Open funfried opened 3 months ago

funfried commented 3 months ago

Describe the bug Recently I updated to EclipseLink 4.0.4 since then I get this error while booting my Spring Boot 3.3.2 app:

java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms (total=30, active=30, idle=0, waiting=0)
    at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:686)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:144)
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:127)
    at org.eclipse.persistence.sessions.JNDIConnector.connect(JNDIConnector.java:140)
    at org.eclipse.persistence.sessions.DatasourceLogin.connectToDatasource(DatasourceLogin.java:174)
    at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.connectInternal(DatasourceAccessor.java:374)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.connectInternal(DatabaseAccessor.java:318)
    at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.reconnect(DatasourceAccessor.java:617)
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.reconnect(DatabaseAccessor.java:1820)
    at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:345)
    at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.beginTransaction(DatasourceAccessor.java:269)
    at org.eclipse.persistence.sessions.server.ClientSession.retryTransaction(ClientSession.java:788)
    at org.eclipse.persistence.internal.sessions.AbstractSession.basicBeginTransaction(AbstractSession.java:751)
    at org.eclipse.persistence.sessions.server.ClientSession.addWriteConnection(ClientSession.java:757)
    at org.eclipse.persistence.sessions.server.ServerSession.acquireClientConnection(ServerSession.java:271)
    at org.eclipse.persistence.sessions.server.ClientSession.getAccessor(ClientSession.java:391)
    at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.getAccessor(UnitOfWorkImpl.java:1960)
    at org.eclipse.persistence.internal.jpa.EntityManagerImpl.unwrap(EntityManagerImpl.java:2906)
    at java.base\/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    at java.base\/java.lang.reflect.Method.invoke(Method.java:580)
    at org.springframework.orm.jpa.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler.invoke(ExtendedEntityManagerCreator.java:364)
    at jdk.proxy2\/jdk.proxy2.$Proxy146.unwrap(Unknown Source)
    at org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect.beginTransaction(EclipseLinkJpaDialect.java:131)
    at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:420)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:532)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:405)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:604)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:373)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:720)

I have no idea where this could come from, I just know as soon as I downgrade to EclipseLink 4.0.2 (didn't test with 4.0.3 as I can only reproduce this error on my production environment, it's not happening on my local machine nor on our testing environment).

It seems the EntityManager cannot get a database connection before a timeout kicks in. My HikariCP database connection pool has no special configurations except that I set the MaximumPoolSize to 30, everything else (besides the DB connection settings) are default values.

As mentioned before, it works on my local machine and in our testing environment, the only difference I can think of is the load on the service. As soon as the service starts up in production, it will be called by around 2k IoT devices which is not the case on my local machine and on testing, everything else is pretty much the same. I did not change anything but the EclipseLink version from 4.0.4 to 4.0.2 and the error was gone and everything worked perfectly well again.

To Reproduce Steps/resources to reproduce the behavior: I have no idea how this could be reproduced, I just thought you should know about the issue, I'll might be able to come up with a test application.

Cheers, Fabian

funfried commented 3 months ago

FYI: I just tried EclipseLink 4.0.3 and this version works also great for me, so the bug must have been introduced in 4.0.4

fwiesweg commented 3 months ago

I'm having a similar issue around locking after the upgrade from 4.0.3 to 4.0.4. Unfortunately, I went with DBCP's default no-timeout behaviour, causing my entire fleet of servers to deadlock every few minutes to hours.

My guess is that it is caused by https://github.com/eclipse-ee4j/eclipselink/pull/2181 -- this pull request replaces the synchronized methods incrementCallCount and decrementCallCount in DatasourceAccessor by a ReentrantLock.

The issue seems to be that the new ReentrantLock instanceLock at 3cadbb11 in that class is held by one thread, which is waiting for a new connection from my connection pool. Unfortunately, this pool has been exhausted at the moment the stack has been recorded, as evident from waiting in LinkedBlockingDeque.takeFirst (it's waiting for caec1e6), so this thread is starved. At the same time, I have a bunch of other threads waiting for that exact instanceLock at 3cadbb11 to be released in order to make progress and finally return their connection object to the connection pool.

I seriously wonder as to why this is triggered now, the locking schema looks exactly the same. I guess we got lucky before because of some minor semantic difference between synchronized and ReentrantLock? I feel it should have been possible to starve before as well, it just never happened.

Starved thread:

        at java.base@17.0.11/jdk.internal.misc.Unsafe.park(Native Method)
        - parking to wait for <caec1e6> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.base@17.0.11/java.util.concurrent.locks.LockSupport.park(LockSupport.java:341)
        at java.base@17.0.11/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:506)
        at java.base@17.0.11/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3465)
        at java.base@17.0.11/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3436)
        at java.base@17.0.11/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1625)
        at app//org.apache.commons.pool2.impl.LinkedBlockingDeque.takeFirst(LinkedBlockingDeque.java:1324)
        at app//org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:313)
        at app//org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:233)
        at app//de.isatech.water.regenwolke.persistence.eclipselink.DbcpDataSource$ConnectionObjectPool.borrowObject(DbcpDataSource.java:72)
        at app//de.isatech.water.regenwolke.persistence.eclipselink.DbcpDataSource$ConnectionObjectPool.borrowObject(DbcpDataSource.java:56)
        at app//org.apache.commons.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:139)
        at app//org.eclipse.persistence.sessions.JNDIConnector.connect(JNDIConnector.java:140)
        at app//org.eclipse.persistence.sessions.DatasourceLogin.connectToDatasource(DatasourceLogin.java:174)
        at app//org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.connectInternal(DatasourceAccessor.java:374)
        at app//org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.connectInternal(DatabaseAccessor.java:318)
        at app//org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.reconnect(DatasourceAccessor.java:617)
        at app//org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.reconnect(DatabaseAccessor.java:1820)
        at app//org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:345)
        at app//org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:624)
        at app//org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:569)
        at app//org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2048)
        at app//org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:611)
        at app//org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:263)
        at app//org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:280)
        at app//org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:266)
        at app//org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:352)
        at app//org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:792)
        at app//org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2848)
        at app//org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2801)
        at app//org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:584)

   Locked ownable synchronizers:
        - locked <3cadbb11> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

Multiple threads trying to return the connection objects (just an example here):

        at java.base@17.0.11/jdk.internal.misc.Unsafe.park(Native Method)
        - waiting to lock <3cadbb11> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) 
        at java.base@17.0.11/java.util.concurrent.locks.LockSupport.park(LockSupport.java:211)
        at java.base@17.0.11/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:715)
        at java.base@17.0.11/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:938)
        at java.base@17.0.11/java.util.concurrent.locks.ReentrantLock$Sync.lock(ReentrantLock.java:153)
        at java.base@17.0.11/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:322)
        at app//org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.decrementCallCount(DatasourceAccessor.java:298)
        at app//org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeStatement(DatabaseAccessor.java:422)
        at app//org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.releaseStatement(DatabaseAccessor.java:1860)
        at app//org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:723)
        at app//org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:569)
        at app//org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2048)
        at app//org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:611)
        at app//org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:263)
        at app//org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:280)
        at app//org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:266)
        at app//org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:352)
        at app//org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:792)
        at app//org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2848)
        at app//org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2801)
        at app//org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:584)

   Locked ownable synchronizers:
        - ... ( a series of unrelated locks)
avgustinmm commented 3 months ago

Hi, we experienced the same issue with 4.0.4 and the downgrade to 4.0.3 seemed to fix the issue. Into the changes introduced into 4.0.4 I see:

image

which seems a little bit strange - could that be related to the bug?

rfelcman commented 3 months ago

Hello, this change #2228 was due issue issue #1970 , but into 4.x branch was merged yesterday (08-AUG-2024). It's not part of already released 4.0.4 . Master branch is 5.x line.

rfelcman commented 3 months ago

Maybe try latest snapshot from https://jakarta.oss.sonatype.org/content/groups/staging/org/eclipse/persistence/eclipselink/4.0.5-SNAPSHOT/ .

chschu commented 2 months ago

@fwiesweg: I'm encountering the exact same deadlocks during load tests. Replacing synchronized with ReentrantLock might have introduced subtle changes. DatabaseAccessor has some synchronized methods that used to lock the same monitor as the no longer synchronized methods of DatasourceAccessor.

Downgrading to 4.0.3 for now.

SAPJens commented 2 months ago

@rfelcman This issue seems to be introduced with #2181 The following happens: Scenario: Springboot app with Hikari as database pool. Prerequisite: Enough requests to get the DB pool full.

Now the following seems to happen: Thread 1 tries to get a connection, but the pool is full and the thread needs to wait. However, this thread has set a lock through DatasourceAccessor. Thread 2 already has a connection and wants to close it. This does not work as DatasourceAccessor is locked by thread 1. This now means, that no old connections can be released anymore and thus the system is in a deadlock.

Stacktraces: Thread 1

"Thread 1" - Thread t@10272
   java.lang.Thread.State: TIMED_WAITING
        at java.base@17.0.12/jdk.internal.misc.Unsafe.park(Native Method)
        - parking to wait for <3643bb91> (a java.util.concurrent.SynchronousQueue$TransferQueue)
        at java.base@17.0.12/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:252)
        at java.base@17.0.12/java.util.concurrent.SynchronousQueue$TransferQueue.transfer(SynchronousQueue.java:704)
        at java.base@17.0.12/java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:903)
        at com.zaxxer.hikari.util.ConcurrentBag.borrow(ConcurrentBag.java:151)
        at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)
        at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:144)
        at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:127)
        at org.eclipse.persistence.sessions.JNDIConnector.connect(JNDIConnector.java:140)
        at org.eclipse.persistence.sessions.DatasourceLogin.connectToDatasource(DatasourceLogin.java:174)
        at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.connectInternal(DatasourceAccessor.java:374)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.connectInternal(DatabaseAccessor.java:318)
        at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.reconnect(DatasourceAccessor.java:617)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.reconnect(DatabaseAccessor.java:1820)
        at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.incrementCallCount(DatasourceAccessor.java:345)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:624)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:569)
        at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2048)
        at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:611)
        at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:263)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:280)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:266)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:352)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:792)
        at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2848)
        at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2801)
        at org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:584)
        at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery(ObjectLevelReadQuery.java:1236)
        at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:913)
        at org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1195)
        at org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:485)
        at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1283)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:3028)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1841)
        at org.eclipse.persistence.internal.sessions.AbstractSession.retryQuery(AbstractSession.java:1912)
        at org.eclipse.persistence.sessions.server.ClientSession.retryQuery(ClientSession.java:704)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.retryQuery(UnitOfWorkImpl.java:5828)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1878)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1823)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1788)
        at org.eclipse.persistence.internal.jpa.QueryImpl.executeReadQuery(QueryImpl.java:263)
        at org.eclipse.persistence.internal.jpa.QueryImpl.getSingleResult(QueryImpl.java:531)
        at org.eclipse.persistence.internal.jpa.EJBQueryImpl.getSingleResult(EJBQueryImpl.java:400)
        at jdk.internal.reflect.GeneratedMethodAccessor88.invoke(Unknown Source)
        at java.base@17.0.12/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base@17.0.12/java.lang.reflect.Method.invoke(Method.java:569)
        at org.springframework.orm.jpa.SharedEntityManagerCreator$DeferredQueryInvocationHandler.invoke(SharedEntityManagerCreator.java:418)
        at jdk.proxy3/jdk.proxy3.$Proxy206.getSingleResult(Unknown Source)
        at org.springframework.data.jpa.repository.query.JpaQueryExecution$SingleEntityExecution.doExecute(JpaQueryExecution.java:223)
        at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:92)
        at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:152)
        at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:140)
        at org.springframework.data.repository.core.support.RepositoryMethodInvoker$RepositoryQueryMethodInvoker$$Lambda$1645/0x0000000800ea7800.invoke(Unknown Source)
        at org.springframework.data.repository.core.support.RepositoryMethodInvoker.doInvoke(RepositoryMethodInvoker.java:170)
        at org.springframework.data.repository.core.support.RepositoryMethodInvoker.invoke(RepositoryMethodInvoker.java:158)
        at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.doInvoke(QueryExecutorMethodInterceptor.java:164)
        at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.invoke(QueryExecutorMethodInterceptor.java:143)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:70)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.transaction.interceptor.TransactionInterceptor$$Lambda$1644/0x0000000800ea71c0.proceedWithInvocation(Unknown Source)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:379)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:138)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:136)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:223)
        at jdk.proxy3/jdk.proxy3.$Proxy204.findOneByTenantId(Unknown Source)

Thread 2

"Thread 2" - Thread t@4530
   java.lang.Thread.State: WAITING
        at java.base@17.0.12/jdk.internal.misc.Unsafe.park(Native Method)
        - waiting to lock <4c14ce1b> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) owned by "http-nio-8080-exec-52" t@10272
        at java.base@17.0.12/java.util.concurrent.locks.LockSupport.park(LockSupport.java:211)
        at java.base@17.0.12/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:715)
        at java.base@17.0.12/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:938)
        at java.base@17.0.12/java.util.concurrent.locks.ReentrantLock$Sync.lock(ReentrantLock.java:153)
        at java.base@17.0.12/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:322)
        at org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.decrementCallCount(DatasourceAccessor.java:298)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeStatement(DatabaseAccessor.java:422)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.releaseStatement(DatabaseAccessor.java:1860)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:723)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:569)
        at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2048)
        at org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:611)
        at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:263)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:280)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:266)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:352)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:792)
        at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2848)
        at org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2801)
        at org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:584)
        at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery(ObjectLevelReadQuery.java:1236)
        at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:913)
        at org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1195)
        at org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:485)
        at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1283)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:3028)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1841)
        at org.eclipse.persistence.internal.sessions.AbstractSession.retryQuery(AbstractSession.java:1912)
        at org.eclipse.persistence.sessions.server.ClientSession.retryQuery(ClientSession.java:704)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.retryQuery(UnitOfWorkImpl.java:5828)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1878)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1823)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1788)
        at org.eclipse.persistence.internal.jpa.QueryImpl.executeReadQuery(QueryImpl.java:263)
        at org.eclipse.persistence.internal.jpa.QueryImpl.getSingleResult(QueryImpl.java:531)
        at org.eclipse.persistence.internal.jpa.EJBQueryImpl.getSingleResult(EJBQueryImpl.java:400)
        at jdk.internal.reflect.GeneratedMethodAccessor88.invoke(Unknown Source)
        at java.base@17.0.12/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base@17.0.12/java.lang.reflect.Method.invoke(Method.java:569)
        at org.springframework.orm.jpa.SharedEntityManagerCreator$DeferredQueryInvocationHandler.invoke(SharedEntityManagerCreator.java:418)
        at jdk.proxy3/jdk.proxy3.$Proxy206.getSingleResult(Unknown Source)
        at org.springframework.data.jpa.repository.query.JpaQueryExecution$SingleEntityExecution.doExecute(JpaQueryExecution.java:223)
        at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:92)
        at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:152)
        at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:140)
        at org.springframework.data.repository.core.support.RepositoryMethodInvoker$RepositoryQueryMethodInvoker$$Lambda$1645/0x0000000800ea7800.invoke(Unknown Source)
        at org.springframework.data.repository.core.support.RepositoryMethodInvoker.doInvoke(RepositoryMethodInvoker.java:170)
        at org.springframework.data.repository.core.support.RepositoryMethodInvoker.invoke(RepositoryMethodInvoker.java:158)
        at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.doInvoke(QueryExecutorMethodInterceptor.java:164)
        at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.invoke(QueryExecutorMethodInterceptor.java:143)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:70)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.transaction.interceptor.TransactionInterceptor$$Lambda$1644/0x0000000800ea71c0.proceedWithInvocation(Unknown Source)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:379)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:138)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:136)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:223)
        at jdk.proxy3/jdk.proxy3.$Proxy185.findOneByKey(Unknown Source)
rfelcman commented 2 months ago

Could You please provide complete stack trace, or at least into EntityManager calls. Described case above looks like, that same instance of the EntityManager is shared across multiple threads which is wrong pattern.

SAPJens commented 2 months ago

Could You please provide complete stack trace, or at least into EntityManager calls. Described case above looks like, that same instance of the EntityManager is shared across multiple threads which is wrong pattern.

@rfelcman I have updated my original comment with the extended stacktrace: https://github.com/eclipse-ee4j/eclipselink/issues/2219#issuecomment-2343349950

rfelcman commented 1 month ago

Hello, in the attachment You can find initial test project which is passing now (simple test with one thread). It's based on Apache Derby (in-memory mode) which is automatically started during Maven lifecycle mvn clean verify. Test is in org.eclipse.persistence.testing.tests.jpa.springboot.TestPersonRepository#testPerson and Derby should be started by mvn derby:run if test is called from IDE. As I don't have experience with Springboot, I'd like ask You check and extend this test case to simulate mentioned bug. E.g. it's not clear how is @Repository class/interface designed. Just interface or interface plus some implementation class. Another question leads into application.properties and Hikari DataSource related properties which are specified in Your project. jpa-bug-2219-SpringbootHikariDSDeadLock.tar.gz