Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

quarkus-hibernate-reactive-panache does not work with scheduler #31132

Closed
jie-huang opened this issue Feb 13, 2023 · 12 comments
Closed

quarkus-hibernate-reactive-panache does not work with scheduler #31132

jie-huang opened this issue Feb 13, 2023 · 12 comments
Labels
area/devmode area/hibernate-reactive Hibernate Reactive area/panache area/persistence OBSOLETE, DO NOT USE area/scheduler kind/bug Something isn't working

Comments

@jie-huang
Copy link

Describe the bug

Using Scheduled to trigger a background job which process data with quarkus-hibernate-reactive-panache lib.
It does not work.

Expected behavior

It should work.

Actual behavior

It fails or hangs the whole app.

How to Reproduce?

  1. create a normal quarkus app with quarkus-hibernate-reactive-panache, quarkus-reactive-pg-client.
  2. create any table data with panache can add/update
  3. create a @scheduled job, e.g.
@ApplicationScoped
public class BackgroundJob {
@Scheduled
Uni<Void> cronJob() {
    return Panache.withTransaction(batchUpdateData());
}
}

Normally, unit test passed Panache.withTransaction(batchUpdateData()); easily. But, when running quarkus dev, it reports error like:

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 [488]: 'vert.x-eventloop-thread-4' current Thread [479]: 'executor-thread-0'

Or, sometime it just fails Timeout and the whole connection becomes not usable anymore.

Output of uname -a or ver

Darwin 21.6.0 Darwin Kernel Version 21.6.0 xnu-8020.240.18~2/RELEASE_ARM64_T8101 arm64

Output of java -version

openjdk 18 2022-03-22

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.12.0.Final

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

Gradle 7.4.1

Additional information

No response
@jie-huang jie-huang added the kind/bug Something isn't working label Feb 13, 2023
@quarkus-bot
Copy link

quarkus-bot bot commented Feb 13, 2023

/cc @DavideD (hibernate-reactive), @FroMage (panache), @Sanne (hibernate-reactive), @gavinking (hibernate-reactive), @loicmathieu (panache), @mkouba (scheduler)

@jie-huang
Copy link
Author

demo project for the problem: https://github.com/jie-huang/quarkus-reactive-panache

@geoand
Copy link
Contributor

geoand commented Feb 14, 2023

Can you try using Quarkus 2.16.2.Final?

@mkouba
Copy link
Contributor

mkouba commented Feb 14, 2023

I was not able to reproduce the problem with 2.16.2.Final.

@jie-huang
Copy link
Author

jie-huang commented Feb 14, 2023 •
edited
Loading

@geoand, @mkouba, you are right. The problem is gone on 2.16.2.Final.

Thanks

@geoand
Copy link
Contributor

geoand commented Feb 14, 2023

Thanks for checking!

@geoand geoand closed this as completed Feb 14, 2023
@geoand geoand added the triage/out-of-date This issue/PR is no longer valid or relevant label Feb 14, 2023
@jie-huang
Copy link
Author

@geoand, I updated the project a little.
It seems panache does not support background job yet.

The idea is, in some case, I want to handle requests like below:

  1. get a request
  2. process the request (save/update data to DB)
  3. start a background job (it will clean/process DB data, and take long time so client cannot wait), return result of 2 immediately.

It seems only one session could be used in the case and it throw exception.

You can just run quarkus dev, then curl http://localhost:8080/cronjob, curl http://localhost:8080/count several times.

Thanks

@geoand geoand reopened this Feb 15, 2023
@geoand geoand removed the triage/out-of-date This issue/PR is no longer valid or relevant label Feb 15, 2023
@geoand
Copy link
Contributor

geoand commented Feb 15, 2023

With the latest version of the reproducer, following the steps mentioned in the previous comment, we get:

2023-02-15 01:21:46,340 INFO  [ji.CronJob] (vert.x-eventloop-thread-0) start cronjob: 0
2023-02-15 01:21:46,638 INFO  [ji.CronJob] (vert.x-eventloop-thread-0) total number of records: 1
2023-02-15 01:21:46,651 INFO  [io.qu.ht.access-log] (vert.x-eventloop-thread-0) 127.0.0.1 - - 15/Feb/2023:11:21:46 +0200 "/cronjob" 200
2023-02-15 01:21:47,336 INFO  [ji.CronJob] (vert.x-eventloop-thread-0) start cronjob: 0
2023-02-15 01:21:47,382 INFO  [ji.CronJob] (vert.x-eventloop-thread-0) background job is starting: 0
2023-02-15 01:21:47,393 INFO  [ji.CronJob] (vert.x-eventloop-thread-0) cronjob is done: 0
2023-02-15 01:21:47,393 INFO  [io.qu.ht.access-log] (vert.x-eventloop-thread-0) 127.0.0.1 - - 15/Feb/2023:11:21:47 +0200 "/cronjob" 200
2023-02-15 01:21:47,403 ERROR [ji.CronJob] (vert.x-eventloop-thread-0) exception : javax.persistence.PersistenceException: org.hibernate.HibernateException: java.lang.NullPointerException: Cannot invoke "org.hibernate.engine.spi.EntityEntry.getPersister()" because "oldEntry" is null
	at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:154)
	at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181)
	at org.hibernate.reactive.session.impl.ReactiveExceptionConverter.convert(ReactiveExceptionConverter.java:31)
	at org.hibernate.reactive.session.impl.ReactiveSessionImpl.lambda$doFlush$33(ReactiveSessionImpl.java:938)
	at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
	at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
	at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
	at org.hibernate.reactive.util.async.impl.AsyncTrampoline$TrampolineInternal.lambda$unroll$0(AsyncTrampoline.java:123)
	at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863)
	at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841)
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
	at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147)
	at io.vertx.core.Future.lambda$toCompletionStage$3(Future.java:384)
	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:100)
	at io.vertx.sqlclient.impl.QueryResultBuilder.tryComplete(QueryResultBuilder.java:34)
	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.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.core.impl.future.PromiseImpl.onSuccess(PromiseImpl.java:49)
	at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:41)
	at io.vertx.sqlclient.impl.TransactionImpl.lambda$wrap$0(TransactionImpl.java:72)
	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.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:86)
	at io.vertx.core.impl.DuplicatedContext.execute(DuplicatedContext.java:163)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:51)
	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.core.impl.future.PromiseImpl.onSuccess(PromiseImpl.java:49)
	at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:41)
	at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:23)
	at io.vertx.sqlclient.impl.command.CommandResponse.fire(CommandResponse.java:46)
	at io.vertx.sqlclient.impl.SocketConnectionBase.handleMessage(SocketConnectionBase.java:292)
	at io.vertx.pgclient.impl.PgSocketConnection.handleMessage(PgSocketConnection.java:97)
	at io.vertx.sqlclient.impl.SocketConnectionBase.lambda$init$0(SocketConnectionBase.java:105)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:55)
	at io.vertx.core.impl.ContextBase.emit(ContextBase.java:239)
	at io.vertx.core.net.impl.NetSocketImpl.handleMessage(NetSocketImpl.java:390)
	at io.vertx.core.net.impl.ConnectionBase.read(ConnectionBase.java:157)
	at io.vertx.core.net.impl.VertxHandler.channelRead(VertxHandler.java:153)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
	at io.vertx.pgclient.impl.codec.PgEncoder.lambda$write$0(PgEncoder.java:98)
	at io.vertx.pgclient.impl.codec.PgCommandCodec.handleReadyForQuery(PgCommandCodec.java:139)
	at io.vertx.pgclient.impl.codec.PgDecoder.decodeReadyForQuery(PgDecoder.java:237)
	at io.vertx.pgclient.impl.codec.PgDecoder.channelRead(PgDecoder.java:96)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
	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:833)
Caused by: org.hibernate.HibernateException: java.lang.NullPointerException: Cannot invoke "org.hibernate.engine.spi.EntityEntry.getPersister()" because "oldEntry" is null
	... 72 more
Caused by: java.lang.NullPointerException: Cannot invoke "org.hibernate.engine.spi.EntityEntry.getPersister()" because "oldEntry" is null
	at org.hibernate.engine.internal.StatefulPersistenceContext.replaceDelayedEntityIdentityInsertKeys(StatefulPersistenceContext.java:1550)
	at org.hibernate.action.internal.EntityIdentityInsertAction.postInsert(EntityIdentityInsertAction.java:146)
	at org.hibernate.reactive.engine.impl.ReactiveEntityIdentityInsertAction.lambda$reactiveExecute$3(ReactiveEntityIdentityInsertAction.java:79)
	at java.base/java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:718)
	... 63 more

@DavideD does this ring a bell?

@mkouba
Copy link
Contributor

mkouba commented Feb 15, 2023

AFAIK it is not possible to use the Uni.combine().all() with Hibernate Reactive.

@geoand
Copy link
Contributor

geoand commented Feb 15, 2023

Ah yeah, I do think we have seen that in the past

@DavideD
Copy link
Contributor

DavideD commented Feb 15, 2023 •
edited
Loading

AFAIK it is not possible to use the Uni.combine().all() with Hibernate Reactive.

Yep, that's correct. There is not a specific error for this scenario, the one we see is probably because some operations don't get executed in the right order. It's important to make sure that the same session is not used in parallel, or that there is a newly created session for each uni. I've mentioned an alternative here: #14709 (comment)

@geoand
Copy link
Contributor

geoand commented Feb 15, 2023

Thanks @DavideD

@mkouba mkouba closed this as completed Feb 23, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/devmode area/hibernate-reactive Hibernate Reactive area/panache area/persistence OBSOLETE, DO NOT USE area/scheduler kind/bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@DavideD @mkouba @jie-huang @geoand