Hibernate Reactive Session/EntityManager is closed #22433

gwenneg · 2021-12-21T09:54:12Z

Describe the bug

The following bug appeared at some point between 2.4.0.Final and 2.5.1.Final.

When used in a highly concurrent context, Hibernate Reactive can sometimes throw this exception:

2021-12-21 10:47:57,168 ERROR [org.hib.rea.errors] (vert.x-eventloop-thread-30) HR000057: Failed to execute statement [$1select fruit0_.id as id1_0_, fruit0_.name as name2_0_ from known_fruits fruit0_ order by fruit0_.name]: $2could not execute query: java.util.concurrent.CompletionException: java.lang.IllegalStateException: Session/EntityManager is closed
        at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)
        at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319)
        at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1081)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
        at io.vertx.core.Future.lambda$toCompletionStage$2(Future.java:360)
        at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141)
        at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:60)
        at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:211)
        at io.vertx.core.impl.future.PromiseImpl.tryComplete(PromiseImpl.java:23)
        at io.vertx.sqlclient.impl.QueryResultBuilder.tryComplete(QueryResultBuilder.java:102)
        at io.vertx.sqlclient.impl.QueryResultBuilder.tryComplete(QueryResultBuilder.java:35)
        at io.vertx.core.Promise.complete(Promise.java:66)
        at io.vertx.core.Promise.handle(Promise.java:51)
        at io.vertx.core.Promise.handle(Promise.java:29)
        at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141)
        at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.IllegalStateException: Session/EntityManager is closed
        at org.hibernate.internal.AbstractSharedSessionContract.checkOpen(AbstractSharedSessionContract.java:393)
        at org.hibernate.engine.spi.SharedSessionContractImplementor.checkOpen(SharedSessionContractImplementor.java:148)
        at org.hibernate.reactive.session.impl.ReactiveSessionImpl.checkOpen(ReactiveSessionImpl.java:1558)
        at org.hibernate.internal.AbstractSharedSessionContract.checkOpenOrWaitingForAutoClose(AbstractSharedSessionContract.java:399)
        at org.hibernate.internal.SessionImpl.getEntityUsingInterceptor(SessionImpl.java:617)
        at org.hibernate.loader.Loader.getRow(Loader.java:1610)
        at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:748)
        at org.hibernate.loader.Loader.getRowsFromResultSet(Loader.java:1047)
        at org.hibernate.reactive.loader.hql.impl.ReactiveQueryLoader.getRowsFromResultSet(ReactiveQueryLoader.java:223)
        at org.hibernate.reactive.loader.ReactiveLoaderBasedResultSetProcessor.reactiveExtractResults(ReactiveLoaderBasedResultSetProcessor.java:73)
        at org.hibernate.reactive.loader.hql.impl.ReactiveQueryLoader$1.reactiveExtractResults(ReactiveQueryLoader.java:72)
        at org.hibernate.reactive.loader.ReactiveLoader.reactiveProcessResultSet(ReactiveLoader.java:145)
        at org.hibernate.reactive.loader.ReactiveLoader.lambda$doReactiveQueryAndInitializeNonLazyCollections$0(ReactiveLoader.java:77)
        at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072)
        ... 21 more

2021-12-21 10:47:57,168 ERROR [org.acm.hib.rea.FruitMutinyResource] (vert.x-eventloop-thread-30) Failed to handle request: java.lang.IllegalStateException: Session/EntityManager is closed
        at org.hibernate.internal.AbstractSharedSessionContract.checkOpen(AbstractSharedSessionContract.java:393)
        at org.hibernate.engine.spi.SharedSessionContractImplementor.checkOpen(SharedSessionContractImplementor.java:148)
        at org.hibernate.reactive.session.impl.ReactiveSessionImpl.checkOpen(ReactiveSessionImpl.java:1558)
        at org.hibernate.internal.AbstractSharedSessionContract.checkOpenOrWaitingForAutoClose(AbstractSharedSessionContract.java:399)
        at org.hibernate.internal.SessionImpl.getEntityUsingInterceptor(SessionImpl.java:617)
        at org.hibernate.loader.Loader.getRow(Loader.java:1610)
        at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:748)
        at org.hibernate.loader.Loader.getRowsFromResultSet(Loader.java:1047)
        at org.hibernate.reactive.loader.hql.impl.ReactiveQueryLoader.getRowsFromResultSet(ReactiveQueryLoader.java:223)
        at org.hibernate.reactive.loader.ReactiveLoaderBasedResultSetProcessor.reactiveExtractResults(ReactiveLoaderBasedResultSetProcessor.java:73)
        at org.hibernate.reactive.loader.hql.impl.ReactiveQueryLoader$1.reactiveExtractResults(ReactiveQueryLoader.java:72)
        at org.hibernate.reactive.loader.ReactiveLoader.reactiveProcessResultSet(ReactiveLoader.java:145)
        at org.hibernate.reactive.loader.ReactiveLoader.lambda$doReactiveQueryAndInitializeNonLazyCollections$0(ReactiveLoader.java:77)
        at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
        at io.vertx.core.Future.lambda$toCompletionStage$2(Future.java:360)
        at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141)
        at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:60)
        at io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:211)
        at io.vertx.core.impl.future.PromiseImpl.tryComplete(PromiseImpl.java:23)
        at io.vertx.sqlclient.impl.QueryResultBuilder.tryComplete(QueryResultBuilder.java:102)
        at io.vertx.sqlclient.impl.QueryResultBuilder.tryComplete(QueryResultBuilder.java:35)
        at io.vertx.core.Promise.complete(Promise.java:66)
        at io.vertx.core.Promise.handle(Promise.java:51)
        at io.vertx.core.Promise.handle(Promise.java:29)
        at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141)
        at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.base/java.lang.Thread.run(Thread.java:829)

Expected behavior

No response

Actual behavior

No response

How to Reproduce?

Reproducer: https://github.com/quarkusio/quarkus-quickstarts/tree/main/hibernate-reactive-quickstart

Steps to reproduce the behavior:

Change the Quarkus version to something between 2.4.0.Final and 2.5.4.Final
Run jmeter test plan.zip with JMeter
The exception should show up in log eventually

Output of `uname -a` or `ver`

Linux glepage.remote.csb 4.18.0-348.2.1.el8_5.x86_64 #1 SMP Mon Nov 8 13:30:15 EST 2021 x86_64 x86_64 x86_64 GNU/Linux

Output of `java -version`

openjdk version "11.0.13" 2021-10-19 LTS

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.5.4.Final

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

No response

Additional information

No response

The text was updated successfully, but these errors were encountered:

quarkus-bot · 2021-12-21T09:54:14Z

/cc @DavideD, @Sanne, @gavinking

gwenneg · 2021-12-21T09:59:40Z

In case you have an issue with the enclosed zip file, here's the JMeter configuration I used:

gwenneg · 2022-01-07T08:31:00Z

@Sanne If you need more information or if I can help with something, please don't hesitate to ask.

DavideD · 2022-01-10T14:55:01Z

At first glance, I'd say it's related to this other issue: hibernate/hibernate-reactive#1073

gwenneg · 2022-01-10T15:24:52Z

Indeed.

Sanne · 2022-01-11T10:00:54Z

Nice, I was able to reproduce it now - indeed it happens reliably. Hopefully it's downhill from here but it still seems complex :)

DavideD · 2022-01-11T13:51:57Z

@gwenneg Could you try this branch, please? https://github.com/DavideD/hibernate-reactive/tree/1073

gwenneg · 2022-01-11T14:31:21Z

I should be able to test that in a couple hours.

gwenneg · 2022-01-11T17:41:54Z

Which Quarkus version should I use to test your branch @DavideD? I tried with 2.5.4.Final and 2.6.2.Final but the application won't start because of this:

Caused by: java.lang.NoSuchMethodError: 'void org.hibernate.id.IdentifierGenerator.configure(org.hibernate.type.Type, java.util.Properties, org.hibernate.service.ServiceRegistry)'

DavideD · 2022-01-11T18:02:07Z

@gwenneg We are still looking into this. It seems that the two issues weren't related after all

This reverts commit e89a6e4.

DavideD · 2022-01-14T11:08:31Z

We have just released a new Hibernate Reactive version (1.1.2.Final) that should fix this issue.
I've just sent a PR for Quarkus: #22898

gwenneg · 2022-01-27T08:11:58Z

This may not be entirely fixed. We just had the same exception on our stage environment with Quarkus 2.6.3.Final.

I'll try to reproduce it later today.

LajosPolya · 2022-10-12T20:47:55Z

Was this fixed in the end?

DavideD · 2022-10-13T10:14:15Z

I think so. Unless you have a usecase that causing the exception again.

gwenneg · 2022-10-13T12:56:44Z

Yes it was fixed.

LajosPolya · 2022-10-13T13:36:46Z

I'm running into an issue where this exception is thrown when multiple calls are made to the DB either in rapid succession or concurrently (a GraphQL data fetcher fetching children entities), but I'm not sure it's something I'm not doing right. Are there docs on how to avoid this exception?

DavideD · 2022-10-13T13:50:37Z

This exception happens when trying to use a session that's been closed before time.
This usually happens when some operations don't happen in the right order. For example, the session might get closed because a previous Uni using the same session has finished too quickly.

I don't think we can help without seeing some code.

LajosPolya · 2022-10-14T17:54:49Z

@DavideD I was able to solve my problem by using withTransaction on the failing query instead of withSession. I was trying to run two queries but the second one always failed. I am able to confirm that the second query runs within a second session object regardless of whether I'm using withTransaction or withSession. "If" both queries are run on the same reactive stream then is it expected behaviour that a new session is created for the second query and how come withTransaction seems to fix the issue?

In the last sentence I put "if" in quotes because I'm not sure if they're run on the same reactive stream.

DavideD · 2022-10-15T01:45:10Z

withTransaction and withSession will look for an existing session in the current stream. No new session is created.
The only difference is that in one case you have a transaction and in the other you don't. I don't know what kind of queries you are running, but I suspect you are reusing the same session to run queries in parallel. And this is not supported when using the session.

If you could show an example of the code you are working with, we might be more helpful.

LajosPolya · 2022-10-17T19:15:53Z

@DavideD I created a repo with a code example: https://github.com/LajosPolya/GraphQL-Hibernate-Reactive

To give you a quick description. I have defined a Parent entity to have a one-many relationship with a Child entity. If more than one Parents and Children exists and I try to query for the Children after querying for the Parents then the exception is throw.
lmk if you need something else

DavideD · 2022-10-18T08:36:04Z

Thanks @LajosPolya.
I'm not familiar with Postman, so it's gonna take a while to figure out how to test the project.

If you could create a test class that I can run, it would save a lot of time.

By the way, any particular reason for using MySQL 5.7? We don't test that version.

LajosPolya · 2022-10-18T13:10:40Z

I'll try to create a test by today or tomorrow. The other project I'm working on uses MySQL 5.7 (the version is out of my hands) and I wanted to replicate the environment in this demo.

LajosPolya · 2022-10-18T15:44:06Z

@DavideD I added a test case. The test case populates all the data it needs so as long as it connects to a DB with the correct schema you should be good to go. Should this conversation be transferred to hibernate/hibernate-reactive#1073 since I'm not using Quarkus?

DavideD · 2022-10-18T15:48:36Z

I want to see the error before deciding where/if to open an issue

DavideD · 2022-10-18T16:09:46Z

Thanks @LajosPolya, I can see the error now. I will try to figure out what's going on and let you know

DavideD · 2022-10-19T13:44:20Z

I'm not familiar with any of the technologies you are using and it's not easy to debug all the layers, but I think ChildRepository#findForParent gets called in parallel for each parent (maybe you can double check this).
What I mean by it is that the second findForParent gets called when the first one hasn't finished yet.
This means that the same session is reused and as soon as the first list of children for a parent is returned, the session gets closed while it's still working on the children for the other parent.

One solution for this would be not to use withSession but use openSession in ChildRepository#findForParent :

    fun findForParent(id: Int): Mono<List<Child>> {
        return sessionFactory.openSession()
            .chain { session ->
                findChildQuery(id)
                    .chain { criteriaQuery -> session.createQuery(criteriaQuery).resultList }
                    // You need to make sure that the session gets always closed
                    .eventually(session::close)
            }
            .toMono()
    }

    private fun findChildQuery(id: Int): Uni<CriteriaQuery<Child>> {
        return try {
            val criteriaBuilder = sessionFactory.criteriaBuilder
            val criteriaQuery = criteriaBuilder.createQuery(Child::class.java)
            val root = criteriaQuery.from(Child::class.java)
            val predicates = mutableListOf(criteriaBuilder.equal(root.get<Int>("parent"), id))
            criteriaQuery.where(*predicates.toTypedArray())
            Uni.createFrom().item(criteriaQuery)
        } catch (t: Throwable) {
            Uni.createFrom().failure(t);
        }
    }

Basically, for each query we create a new session and make sure that's closed at the end.
I'm not sure why it works when using transactions, but I don't think it's something you should rely on: he session will still be shared. Maybe using transactions provides some sort of isolation but I'm not sure about it.

LajosPolya · 2022-10-19T18:09:59Z

Thanks for the code example, this fixed all of my issues!

but I think ChildRepository#findForParent gets called in parallel for each parent

Yes, the queries to the children will get called in parallel.

This means that the same session is reused and as soon as the first list of children for a parent is returned, the session gets closed while it's still working on the children for the other parent.

But how come this is the case? If a session is still being used by the second query then why is the first query able to close it?

for each query we create a new session and make sure that's closed at the end.

Can you explain/point me to documentation on how the eventually(session::close) works? How does it know when to close the session?

DavideD · 2022-10-20T08:40:30Z

But how come this is the case? If a session is still being used by the second query then why is the first query able to close it?

The session gets closed at the end of the withSession: https://github.com/hibernate/hibernate-reactive/blob/main/hibernate-reactive-core/src/main/java/org/hibernate/reactive/mutiny/impl/MutinySessionFactoryImpl.java#L250

The session is not thread-safe. There are no check in place to make sure that it doesn't get closed if somebody else is still using it.
In this case, thread-safe doesn't only mean that it must not be shared between threads. It means that when you have two parallel async pipelines, they cannot share the session.

Also, withSession doesn't always creates a new session. It checks first if one exists in the current Vert.x context and, if it's the case, it will reuse it.

openSession doesn't check anything, it just creates a new session every time. That's why in this case it solves the issue.

Can you explain/point me to documentation on how the eventually(session::close) works? How does it know when to close the session?

It's part of the Mutiny API: https://github.com/smallrye/smallrye-mutiny/blob/main/implementation/src/main/java/io/smallrye/mutiny/Uni.java#L549

It's similar to a finally block:

if the previous uni completes successfully, it will chain the call to session.close and then return the result of the previous uni (basically, it behaves the same as .call{ () -> session.close()})
if the previous uni fails, it will run session.close and when it completes, propagate the failure

gwenneg added the kind/bug Something isn't working label Dec 21, 2021

quarkus-bot bot added area/hibernate-reactive Hibernate Reactive area/persistence OBSOLETE, DO NOT USE labels Dec 21, 2021

gwenneg added the triage/regression label Jan 3, 2022

Sanne added a commit to Sanne/hibernate-reactive that referenced this issue Jan 11, 2022

[Draft] to fix hibernate#1073 and quarkusio/quarkus#22433

e2ad587

Sanne mentioned this issue Jan 11, 2022

[Draft] to fix "java.lang.IllegalStateException: Session/EntityManager is closed" hibernate/hibernate-reactive#1118

Merged

gavinking pushed a commit to hibernate/hibernate-reactive that referenced this issue Jan 13, 2022

[Draft] to fix #1073 and quarkusio/quarkus#22433

e89a6e4

DavideD added a commit to DavideD/hibernate-reactive that referenced this issue Jan 13, 2022

Revert "[Draft] to fix hibernate#1073 and quarkusio/quarkus#22433"

ff822bd

This reverts commit e89a6e4.

DavideD added a commit to DavideD/hibernate-reactive that referenced this issue Jan 13, 2022

Revert "[Draft] to fix hibernate#1073 and quarkusio/quarkus#22433"

8dd823f

This reverts commit e89a6e4.

Sanne mentioned this issue Jan 14, 2022

Upgrade Hibernate Reactive to 1.1.2.Final #22898

Merged

DavideD pushed a commit to DavideD/hibernate-reactive that referenced this issue Jan 14, 2022

[Draft] to fix hibernate#1073 and quarkusio/quarkus#22433

5812d48

Sanne closed this as completed in #22898 Jan 14, 2022

quarkus-bot bot added this to the 2.7 - main milestone Jan 14, 2022

gsmet modified the milestones: 2.7 - main, 2.6.3.Final Jan 18, 2022

gwenneg mentioned this issue Jan 28, 2022

Hibernate Reactive Session/EntityManager is closed #23269

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Hibernate Reactive Session/EntityManager is closed #22433

Hibernate Reactive Session/EntityManager is closed #22433

gwenneg commented Dec 21, 2021

quarkus-bot bot commented Dec 21, 2021

gwenneg commented Dec 21, 2021

gwenneg commented Jan 7, 2022

DavideD commented Jan 10, 2022

gwenneg commented Jan 10, 2022

Sanne commented Jan 11, 2022

DavideD commented Jan 11, 2022

gwenneg commented Jan 11, 2022

gwenneg commented Jan 11, 2022

DavideD commented Jan 11, 2022

DavideD commented Jan 14, 2022

gwenneg commented Jan 27, 2022

LajosPolya commented Oct 12, 2022

DavideD commented Oct 13, 2022

gwenneg commented Oct 13, 2022

LajosPolya commented Oct 13, 2022

DavideD commented Oct 13, 2022 •

edited

Loading

LajosPolya commented Oct 14, 2022 •

edited

Loading

DavideD commented Oct 15, 2022

LajosPolya commented Oct 17, 2022 •

edited

Loading

DavideD commented Oct 18, 2022

LajosPolya commented Oct 18, 2022

LajosPolya commented Oct 18, 2022 •

edited

Loading

DavideD commented Oct 18, 2022

DavideD commented Oct 18, 2022

DavideD commented Oct 19, 2022 •

edited

Loading

LajosPolya commented Oct 19, 2022 •

edited

Loading

DavideD commented Oct 20, 2022

Hibernate Reactive Session/EntityManager is closed #22433

Hibernate Reactive Session/EntityManager is closed #22433

Comments

gwenneg commented Dec 21, 2021

Describe the bug

Expected behavior

Actual behavior

How to Reproduce?

Output of uname -a or ver

Output of java -version

GraalVM version (if different from Java)

Quarkus version or git rev

Build tool (ie. output of mvnw --version or gradlew --version)

Additional information

quarkus-bot bot commented Dec 21, 2021

gwenneg commented Dec 21, 2021

gwenneg commented Jan 7, 2022

DavideD commented Jan 10, 2022

gwenneg commented Jan 10, 2022

Sanne commented Jan 11, 2022

DavideD commented Jan 11, 2022

gwenneg commented Jan 11, 2022

gwenneg commented Jan 11, 2022

DavideD commented Jan 11, 2022

DavideD commented Jan 14, 2022

gwenneg commented Jan 27, 2022

LajosPolya commented Oct 12, 2022

DavideD commented Oct 13, 2022

gwenneg commented Oct 13, 2022

LajosPolya commented Oct 13, 2022

DavideD commented Oct 13, 2022 • edited Loading

LajosPolya commented Oct 14, 2022 • edited Loading

DavideD commented Oct 15, 2022

LajosPolya commented Oct 17, 2022 • edited Loading

DavideD commented Oct 18, 2022

LajosPolya commented Oct 18, 2022

LajosPolya commented Oct 18, 2022 • edited Loading

DavideD commented Oct 18, 2022

DavideD commented Oct 18, 2022

DavideD commented Oct 19, 2022 • edited Loading

LajosPolya commented Oct 19, 2022 • edited Loading

DavideD commented Oct 20, 2022

Output of `uname -a` or `ver`

Output of `java -version`

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

DavideD commented Oct 13, 2022 •

edited

Loading

LajosPolya commented Oct 14, 2022 •

edited

Loading

LajosPolya commented Oct 17, 2022 •

edited

Loading

LajosPolya commented Oct 18, 2022 •

edited

Loading

DavideD commented Oct 19, 2022 •

edited

Loading

LajosPolya commented Oct 19, 2022 •

edited

Loading