Skip to content

Improve stack trace for Session used across threads detection error HR000069 when using Mutiny #1376

@noobgramming

Description

@noobgramming

Hello again! We've been using Hibernate Reactive in prod for a while and there's a common mistake I would like to prevent when using Reactive DAO's.

We're writing DAO's much like you would in blocking code, here is an example DAO method:

  /**
   * List all entities. Force providing max results to avoid perf problems
   *
   * @return list of entities
   */
  @CheckReturnValue
  public Uni<List<E>> list(final int maxResults) {
    Preconditions.checkArgument(
        maxResults > 0, "maxResults must be more than zero. Value was %s", maxResults);
    return sessionFactory.withSession(
        session -> {
          final var query = sessionFactory.getCriteriaBuilder().createQuery(cls);
          // need root for query to be valid
          query.from(this.cls);
          return session.createQuery(query).setMaxResults(maxResults).getResultList();
        });
  }

A very common problem with this pattern is accidentally creating another Session because you have multiple reactive streams. And related, accidentally creating a second Reactive Session in a different thread because context wasn't propagated when using adapters between Mutiny/CompletableFuture/RxJava. This is actually detected and logged by Hibernate Reactive already, but at a Debug level and not exposed to the user API.

// EXISTING CODE  MutinySessionFactoryImpl.withSession()
	@Override
	public <T> Uni<T> withSession(Function<Mutiny.Session, Uni<T>> work) {
		Objects.requireNonNull( work, "parameter 'work' is required" );
		Mutiny.Session current = context.get( contextKeyForSession );
		if ( current != null && current.isOpen() ) {
			LOG.debug( "Reusing existing open Mutiny.Session which was found in the current Vert.x context" );
			return work.apply( current );
		}
		else {
			LOG.debug( "No existing open Mutiny.Session was found in the current Vert.x context: opening a new instance" );
			return withSession( openSession(), work, contextKeyForSession );
		}
	}

Can we expose this logic so I can warn or something when calling DAO methods without a session in progress?

           Optional<Mutiny.Session> getCurrentSession() {
               Mutiny.Session current = context.get( contextKeyForSession );
		if ( current != null && current.isOpen() ) {
			return Optional.of(current);
		}
		else {
			return Optional.empty();
		}
            }

Another option is exposing a set of withSession()/withTransaction() variants on SessionFactory that blow up if a session isn't in progress... maybe named withExistingSession(). This my plan for our code-base since we already wrap SessionFactory to hide Open*** variants because lack of automatic flush has bitten us so many times.

My goal is preventing implicit Session creation while transparently using an existing one in our DAO's. Because IMO it's too easy to accidentally drop your Session out of context using streams or threading improperly, and end up with utterly intractable and random
IllegalStateException: HR000069: Detected use of the reactive Session from a different Thread

Activity

pinned this issue on Aug 9, 2022
unpinned this issue on Aug 9, 2022
DavideD

DavideD commented on Aug 9, 2022

@DavideD
Member

I need to think about it, but you can get the context via the Implementor interface:

Implementor implementor = (Implementor)sessionFactory;
Context context = implementor.getContext();
Context.Key sessionKey = new BaseKey<>( Mutiny.Session.class, implementor.getUuid() );
Mutiny.Session current = context.get( sessionKey );
noobgramming

noobgramming commented on Aug 11, 2022

@noobgramming
Author

Hello David, I've been fiddling with this on my end. The ability to get current session remains useful, but I'm starting to doubt my other suggestions.

I found a more effective way to fix IllegalStateException: HR000069: Detected use of the reactive Session from a different Thread although I'm unsure if it can be done in a general way without causing unacceptable performance impact (I put our implementation behind a run-time modifiable config option)

I realized the main problem with Hibernate's existing error message is that it doesn't preserve the original stack trace. When you get HR000069, it can be coming from anywhere in your application as the provided trace doesn't contain any of the user's stack frames.

So for our SessionFactory wrapper, I'm now saving off a new RuntimeException() along with current threadId and name as the value in a concurrent map with weak keys of Mutiny.Session whenever the Session is used. Like this:

  private record ThreadInfo(
      @NonNull long threadId, @NonNull String name, @NonNull RuntimeException traceHolder) {}
  /** This cache has weak keys to prevent a memory leak holding onto Session objects forever * */
  private static final Cache<Mutiny.Session, ThreadInfo> sessionToThreadMap =
      CacheBuilder.newBuilder().weakKeys().build();

This allows me to lookup which thread the Session was created on each time it's used, and more importantly, the stored RuntimeException allows me to re-hydrate the original stack trace. Finally, the weak keys ensure I don't create a memory leak holding onto Sessions no longer in use. Usage looks something like this

final var threadInfo =
    Optional.ofNullable(sessionToThreadMap.getIfPresent(session));
threadInfo.ifPresent(
    originalThreadInfo -> {
      if (originalThreadInfo.threadId() != Thread.currentThread().getId()) { 
            log.error("Hibernate Session used in a different thread " +Thread.currentThread().getName() + 
            " than where it was created ("+originalThreadInfo.name()+") ! See trace", new RuntimeException());
            log.error("Session originated here", originalThreadInfo.traceHolder());

The main problem with my implementation is that creating a new RuntimeException() and stuffing it into the map every time a Session is used is very inefficient. I'm not clever or familiar enough with Hibernate to find a solution to this.

Maybe there is a similar but more performant way to improve the original HR000069 error messages that led me down this rabbithole?

DavideD

DavideD commented on Aug 12, 2022

@DavideD
Member

Ah, we didn't notice that. Good point!

When using the Mutiny API, we create a Uni that will eventually be executed at subscription and so, in case of error, it doesn't contain the caller of the session method causing the error.

For reference, this is the stacktrace when running InternalStateAssertionsTest#testFindWithStage:

java.lang.IllegalStateException: HR000069: Detected use of the reactive Session from a different Thread than the one which was used to open the reactive Session - this suggests an invalid integration; original thread [19]: 'vert.x-eventloop-thread-0' current Thread [26]: 'org.hibernate.reactive.InternalStateAssertionsTest-thread'
	at org.hibernate.reactive.common.InternalStateAssertions.assertCurrentThreadMatches(InternalStateAssertions.java:46)
	at org.hibernate.reactive.session.impl.ReactiveSessionImpl.threadCheck(ReactiveSessionImpl.java:158)
	at org.hibernate.reactive.session.impl.ReactiveSessionImpl.checkOpen(ReactiveSessionImpl.java:1580)
	at org.hibernate.reactive.session.impl.ReactiveSessionImpl.reactiveFind(ReactiveSessionImpl.java:1027)
	at org.hibernate.reactive.stage.impl.StageSessionImpl.find(StageSessionImpl.java:101)

        // Line in the test that causes the exception
        at org.hibernate.reactive.InternalStateAssertionsTest.lambda$testFindWithStage$1(InternalStateAssertionsTest.java:80)

	at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072)
	at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478)
	at java.base/java.lang.Thread.run(Thread.java:829)

And this is the stack trace when running InternalStateAssertionsTest#testFindWithMutiny:

java.lang.IllegalStateException: HR000069: Detected use of the reactive Session from a different Thread than the one which was used to open the reactive Session - this suggests an invalid integration; original thread [19]: 'vert.x-eventloop-thread-0' current Thread [27]: 'vert.x-eventloop-thread-1'
	at org.hibernate.reactive.common.InternalStateAssertions.assertCurrentThreadMatches(InternalStateAssertions.java:46)
	at org.hibernate.reactive.session.impl.ReactiveSessionImpl.threadCheck(ReactiveSessionImpl.java:158)
	at org.hibernate.reactive.session.impl.ReactiveSessionImpl.checkOpen(ReactiveSessionImpl.java:1580)
	at org.hibernate.reactive.session.impl.ReactiveSessionImpl.reactiveFind(ReactiveSessionImpl.java:1027)
	at org.hibernate.reactive.mutiny.impl.MutinySessionImpl.lambda$find$3(MutinySessionImpl.java:109)
	at io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage.subscribe(UniCreateFromCompletionStage.java:24)
	at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
	at io.smallrye.mutiny.operators.uni.UniRunSubscribeOn.lambda$subscribe$0(UniRunSubscribeOn.java:27)
	at org.hibernate.reactive.context.impl.VertxContext.lambda$execute$0(VertxContext.java:86)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:264)
	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:246)
	at io.vertx.core.impl.EventLoopContext.lambda$runOnContext$0(EventLoopContext.java:43)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	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)

And it doesn't contain any reference to InternalStateAssertionsTest.

added 2 commits that reference this issue on Aug 13, 2022
77d8bbd
6ce2e19
DavideD

DavideD commented on Aug 13, 2022

@DavideD
Member

I don't think I would keep a map around to fix this issue.
You can create a class that wraps the session and every time you call one of the method in it, keep track of possible errors.

You can see an example - it might become a future fix - here: https://github.com/DavideD/hibernate-reactive/blob/stacktrace/hibernate-reactive-core/src/main/java/org/hibernate/reactive/mutiny/impl/MutinySessionImpl.java#L57

changed the title [-]Expose check for Hibernate Session already in progress or otherwise prevent implicit Session creation? [/-] [+]Improve stack trace for Session used across threads detection error HR000069 when using Mutiny[/+] on Sep 1, 2022
gavinking

gavinking commented on Sep 6, 2022

@gavinking
Member

A very common problem with this pattern is accidentally creating another Session because you have multiple reactive streams.

@noobgramming not sure what you mean by this; different streams can't share Sessions, that's against the rules.

noobgramming

noobgramming commented on Sep 6, 2022

@noobgramming
Author

@gavinking I know, but it hasn't stopped people from doing it :( . At least in our projects

added
waitingWe are waiting for another PR or issue to be solved before merging this one
on Sep 6, 2022
paomian

paomian commented on Nov 17, 2022

@paomian

I do't want to share Session
In my situation. I will send email to an address which query from db. Unfortunately event loop of query email is different with send email.

consider code

  @GET
  @Path("/gaga")
  @ReactiveTransactional
  public Uni<Boolean> gagaga() {
    return Uni.createFrom()
        .item("xpaomian@gmail.com")
        .flatMap(this::sendInviteEmail);
  }

@ReactiveTransactional will check event loop which used by method gagaga but sendInviteEmail is wrapped aws ses service. aws ses service use this own event loop. aws ses return a CompletableFuture. I will get same error when i create Uni by Uni.createFrom().completionStage(future). Uni will use previous step executor I guess.
Now i can run blocking CompletableFuture by get and generate a Uni by item(result),but it will be blocking work thread.
So i try to use emitOn change sendInviteEmail event loop. but i do not know which executor to chose. Any one can help me?

DavideD

DavideD commented on Nov 17, 2022

@DavideD
Member

I'm not sure I understand what's going on, but can't you delay the creation of the session? it doesn't seem like you are using it in gagaga and I don't know what's happening in sendInviteEmail.

@ReactiveTransactional just wraps the method call using Panache.withTransaction. So you could try removing the annotation and use Panache.withTransaction when you actually need it.

It would help if you could create a project or test so that we can see the error.

Also, this issue is about improving the stack trace, I think you are asking for something different.

12 remaining items

Loading
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    enhancementNew feature or requestwaitingWe are waiting for another PR or issue to be solved before merging this one

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

      Development

      No branches or pull requests

        Participants

        @DavideD@blafond@gavinking@paomian@noobgramming

        Issue actions

          Improve stack trace for Session used across threads detection error HR000069 when using Mutiny · Issue #1376 · hibernate/hibernate-reactive