Exceptions with Hibernate Reactive under load

[turing85]

Describe the bug

When using reactive panache and stressing the application with some tests, the application starts throwing exceptions:

2023-04-11 14:00:24,747 ERROR [org.jbo.res.rea.com.cor.AbstractResteasyReactiveContext] (vert.x-eventloop-thread-6) Request failed: javax.persistence.PersistenceException: org.hibernate.HibernateException: java.util.concurrent.CompletionException: 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 [27]: 'vert.x-eventloop-thread-6' current Thread [23]: 'vert.x-eventloop-thread-2'
	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$firePersist$19(ReactiveSessionImpl.java:708)
	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.complete(CompletableFuture.java:2147)
	at java.base/java.util.concurrent.CompletableFuture.uniAcceptNow(CompletableFuture.java:757)
	at java.base/java.util.concurrent.CompletableFuture.uniAcceptStage(CompletableFuture.java:735)
	at java.base/java.util.concurrent.CompletableFuture.thenAccept(CompletableFuture.java:2182)
	at java.base/java.util.concurrent.CompletableFuture.thenAccept(CompletableFuture.java:144)
	at org.hibernate.reactive.id.impl.BlockingIdentifierGenerator.lambda$generate$1(BlockingIdentifierGenerator.java:94)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at org.hibernate.reactive.id.impl.BlockingIdentifierGenerator.lambda$generate$0(BlockingIdentifierGenerator.java:87)
	at java.base/java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:718)
	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.util.concurrent.CompletionException: 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 [27]: 'vert.x-eventloop-thread-6' current Thread [23]: 'vert.x-eventloop-thread-2'
	... 77 more
Caused by: java.util.concurrent.CompletionException: 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 [27]: 'vert.x-eventloop-thread-6' current Thread [23]: 'vert.x-eventloop-thread-2'
	at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315)
	at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1194)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:144)
	at org.hibernate.reactive.event.impl.AbstractReactiveSaveEventListener.reactivePerformSaveOrReplicate(AbstractReactiveSaveEventListener.java:252)
	at org.hibernate.reactive.event.impl.AbstractReactiveSaveEventListener.lambda$reactivePerformSave$2(AbstractReactiveSaveEventListener.java:175)
	at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:144)
	at org.hibernate.reactive.event.impl.AbstractReactiveSaveEventListener.reactivePerformSave(AbstractReactiveSaveEventListener.java:175)
	at org.hibernate.reactive.event.impl.AbstractReactiveSaveEventListener.lambda$reactiveSaveWithGeneratedId$0(AbstractReactiveSaveEventListener.java:125)
	at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150)
	... 73 more
Caused by: 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 [27]: 'vert.x-eventloop-thread-6' current Thread [23]: 'vert.x-eventloop-thread-2'
	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.getReactiveActionQueue(ReactiveSessionImpl.java:168)
	at org.hibernate.reactive.event.impl.AbstractReactiveSaveEventListener.addInsertAction(AbstractReactiveSaveEventListener.java:343)
	at org.hibernate.reactive.event.impl.AbstractReactiveSaveEventListener.lambda$reactivePerformSaveOrReplicate$4(AbstractReactiveSaveEventListener.java:279)
	at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187)
	... 83 more

Expected behavior

Application runs without throwing exceptions.

Actual behavior

Application throws exceptions.

How to Reproduce?

1. Checkout this github.com repository:

   git clone https://github.com/turing85/quarkus-reactive-stress-test.git
   cd quarkus-reactive-stress-test

2. Deploy dependencies:

   docker-compose --file local-deployment/docker-compose.yml up -d

3. Build the application, configure JMeter to use one thread:

   ./mvnw --define jmeter.threads=1 clean package

4. Create the database schema:

   ./mwnw flyway:migrate

5. Start the application:

   java -jar target/quarkus-app/quarkus-run.jar

6. In a separate terminal, start the JMeter tests (we will call this terminal the test-terminal, and the terminal running the application the application-terminal):

   ./mvnw jmeter:jmeter

7. Observe that the tests finish without errors:

   ...
   [INFO] summary =  10000 in 00:00:14 =  712.5/s Avg:     1 Min:     0 Max:   433 Err:     0 (0.00%)
   ...

8. Switch back to the application-terminal, stop it, and rebuild the application, configure JMeter to use 4 threads, start the application:

   ./mvnw --define jmeter.threads=4 clean package
   java -jar target/quarkus-app/quarkus-run.jar

9. Back to the test-terminal, re-execute the JMeter tests:

   ./mvnw jmeter:jmeter

10. Observe that there are errors in the tests:

    ...
    [INFO] summary =  40000 in 00:00:13 = 3034.4/s Avg:     1 Min:     0 Max:   482 Err:   927 (2.32%)
    ...

11. Find the stack trace mentioned above in the logs of the application-terminal
12. In the test-terminal, Run the wrk-tests, with 1 thread and 1 connection:

    wrk/run.sh 1 1 30s

13. Observe that the tests finish without erros:

    ...
    Non-2xx responses: 0 (0.00%)
    ...

14. Re-run the tests, with 1 thread and 2 connections:

    wrk/run.sh 1 2 30s

15. Immediately switch back to the application-terminal and observe that, for some time, exceptions are thrown and then, the exceptions stop
16. When the tests finish, switch back to the test-terminal, observe the (relatively low) error rate:

    ...
    Non-2xx responses: 242 (0.12%)
    ...

17. Re-run the wrk-tests, with 4 connections:

    wrk/run.sh 1 4 30s

18. Immediately switch back to the application-terminal, observe that the application prints stack traces constantly
19. When the tests are finished, switch back to the test-terminal and observe the significantly higher error rate:

    ...
    Non-2xx responses: 6597 (2.46%)
    ...

Output of uname -a or ver

Linux <redacted> 5.15.0-52-generic #58-Ubuntu SMP Thu Oct 13 08:03:55 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

Output of java -version

openjdk version "17.0.5" 2022-10-18
OpenJDK Runtime Environment Temurin-17.0.5+8 (build 17.0.5+8)
OpenJDK 64-Bit Server VM Temurin-17.0.5+8 (build 17.0.5+8, mixed mode, sharing)

GraalVM version (if different from Java)

GraalVM Mandrel, Version 22.3.1.0-java17

Quarkus version or git rev

2.16.6.Final
3.0.0.CR2

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

Apache Maven 3.8.7 (b89d5959fcde851dcb1c8946a785a163f14e1e29)
Maven home: /home/marco/.m2/wrapper/dists/apache-maven-3.8.7-bin/678cc9d4/apache-maven-3.8.7
Java version: 17.0.5, vendor: Eclipse Adoptium, runtime: /opt/java/mandrel/22.3.0.1-java17
Default locale: en_US, platform encoding: UTF-8
OS name: "linux", version: "5.15.0-52-generic", arch: "amd64", family: "unix"

Additional information

• The errors disappear when we export QUARKUS_VERTX_EVENT_LOOPS_POOL_SIZE=1
• The issue is similar to Error under load "Detected use of the reactive Session from a different Thread..." #23324, but in the case presented, no emitter is involved
• The code for quarkus 3 is on branch quarkus-3 (github.com)
• The behaviour is also observabiel when the app is compiled natively, for both 2.x and 3.x
• Relevant quarkusio.zupipchat.com discussion

[quarkus-bot]

/cc @FroMage (panache), @loicmathieu (panache)

[this-user]

I have been struggling with the exact same problem for days. Sequential requests work fine, but parallel ones reliably lead to that very error.

I am using Hibernate Reactive in combination with Panache, and I am using the @ReactiveTransactional annotation at my REST endpoint. I have attempted to use both Panache.withSession() as well as a Mutiny SessionFactory at various points in the code and in various combinations to resolve the problem as has been suggested in previous discussions about similar issues, but to no avail. I have also tried adding more @ReactiveTransactional annotations to relevant parts of the code, again with no results.

The only thing that has worked so far is restricting the size of the Vertx I/O pool to one thread.

Interestingly, if I do several sets of parallel requests, the issue only occurs during the first set, and usually on the first or second request. So far, I have not been able to reproduce the issue during subsequent sets of requests (with no restart of the application in between).

Judging from the logs, the issue seems to be that the request chain switches to a different I/O thread at some point, causing the issue. There is no discernible reason why this happens, as everything is purely reactive with no code that should block. I have not been able to determine the exact point at which the switch happens, but it seems to be related to code that invokes Hibernate.

• Issue happens with both Quarkus 2.16.5 and 2.16.6 final
• Issue happens with GraalVM CE 22.3.1 / JVM 19.0.2 in JVM mode as well as with the native build

EDIT:

• Issue happens with Postgres as well as MariaDB, using the respective reactive driver

[turing85]

Also tested with:

• quarkus, version 3.0.0.CR2 -> same behaviour
• native compilation (GraalVM Mandrel, version 22.3.1.0-java17) -> same behaviour
• quarkus, version 3.0.0.CR2 + native compilation (GraalVM Mandrel, version 22.3.1.0-java17) -> same behaviour

I updated the issue accordingly.

[franz1981]

@Sanne

[geoand]

cc @DavideD

[turing85]

Update: I removed the vertx-reactive:-prefix from the quarkus.datasource.reactive.url, and now there are "only" two or three exceptions per test run when running wrk, right at the beginning of the run. JMeter still behaves the same.

[DavideD]

Thanks, we can see the error related to the IllegalState.
Still working on it

[this-user]

Update: I removed the vertx-reactive:-prefix from the quarkus.datasource.reactive.url, and now there are "only" two or three exceptions per test run when running wrk, right at the beginning of the run. JMeter still behaves the same.

That sounds like it's in line with what I have been seeing. Although, in my case, I have been using dev mode with automatically configured dev services for testing.

[Sanne]

I've been working on this with @DavideD and our conclusion is that the task is being switched on a different thread by vert.x - which is entirely valid to do as it attempts to load balance different contexts on different threads, but the assertions we introduced in Hibernate Reactive are too strict as they don't deal with this case.

You can experiment with this by disabling the assertions; we had foreseen some level of risk when introducing them so there's a safeguard: set the system property org.hibernate.reactive.common.InternalStateAssertions.ENFORCE=false

• https://github.com/Sanne/hibernate-reactive/blob/f5f693bae3d938eff1f473e75c363b89ad8df18e/hibernate-reactive-core/src/main/java/org/hibernate/reactive/common/InternalStateAssertions.java#L28-L30

My conclusions from this is that I was mistaken in enforcing this assertion as there's some valid scenarious in which the thread switch is legal - at the time we were working to spot mistakes in Quarkus integration in which the thread switch was not intended.

On the other hand, I'm puzzled by the fact that we DID NEVER see this thread switch happen under other load tests (e.g. the Techempower benchmark - we've been runnig that extensively), while it's trivial to reproduce with this one. I'd love to investigate further and figure out why it wasn't being triggered on our other tests.

[turing85]

@Sanne Feel free to copy my tests.

[turing85]

@Sanne just implemented the change (setting -Dorg.hibernate.reactive.common.InternalStateAssertions.ENFORCE=false) in my tests. This leads to another problem:

2023-04-12 17:35:12,249 ERROR [org.jbo.res.rea.com.cor.AbstractResteasyReactiveContext] (vert.x-eventloop-thread-1) Request failed: javax.persistence.PersistenceException: org.hibernate.HibernateException: io.vertx.pgclient.PgException: ERROR: duplicate key value violates unique constraint "animals__pk__id" (23505)
	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(Unknown Source)
	at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(Unknown Source)
	at java.base/java.util.concurrent.CompletableFuture.postComplete(Unknown Source)
	at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(Unknown Source)
	at io.vertx.core.Future.lambda$toCompletionStage$3(Future.java:386)
	at io.vertx.core.impl.future.FutureImpl$3.onFailure(FutureImpl.java:153)
	at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
	at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
	at io.vertx.core.impl.future.PromiseImpl.tryFail(PromiseImpl.java:23)
	at io.vertx.sqlclient.impl.QueryResultBuilder.tryFail(QueryResultBuilder.java:116)
	at io.vertx.core.Promise.fail(Promise.java:89)
	at io.vertx.core.Promise.handle(Promise.java:53)
	at io.vertx.core.Promise.handle(Promise.java:29)
	at io.vertx.core.impl.future.FutureImpl$3.onFailure(FutureImpl.java:153)
	at io.vertx.core.impl.future.FutureBase.emitFailure(FutureBase.java:75)
	at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
	at io.vertx.core.impl.future.PromiseImpl.tryFail(PromiseImpl.java:23)
	at io.vertx.core.impl.future.PromiseImpl.onFailure(PromiseImpl.java:54)
	at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:43)
	at io.vertx.sqlclient.impl.TransactionImpl.lambda$wrap$0(TransactionImpl.java:72)
	at io.vertx.core.impl.future.FutureImpl$3.onFailure(FutureImpl.java:153)
	at io.vertx.core.impl.future.FutureBase.lambda$emitFailure$1(FutureBase.java:69)
	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.emitFailure(FutureBase.java:66)
	at io.vertx.core.impl.future.FutureImpl.tryFail(FutureImpl.java:230)
	at io.vertx.core.impl.future.PromiseImpl.tryFail(PromiseImpl.java:23)
	at io.vertx.core.impl.future.PromiseImpl.onFailure(PromiseImpl.java:54)
	at io.vertx.core.impl.future.PromiseImpl.handle(PromiseImpl.java:43)
	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(Unknown Source)
Caused by: org.hibernate.HibernateException: io.vertx.pgclient.PgException: ERROR: duplicate key value violates unique constraint "animals__pk__id" (23505)
	... 66 more
Caused by: io.vertx.pgclient.PgException: ERROR: duplicate key value violates unique constraint "animals__pk__id" (23505)
	at io.vertx.pgclient.impl.codec.ErrorResponse.toException(ErrorResponse.java:31)
	at io.vertx.pgclient.impl.codec.QueryCommandBaseCodec.handleErrorResponse(QueryCommandBaseCodec.java:57)
	at io.vertx.pgclient.impl.codec.ExtendedQueryCommandCodec.handleErrorResponse(ExtendedQueryCommandCodec.java:90)
	at io.vertx.pgclient.impl.codec.PgDecoder.decodeError(PgDecoder.java:246)
	at io.vertx.pgclient.impl.codec.PgDecoder.decodeMessage(PgDecoder.java:132)
	at io.vertx.pgclient.impl.codec.PgDecoder.channelRead(PgDecoder.java:112)
	... 17 more

This exception keeps appearing. From what I see, the database is set up correctly.

Setup of @Id in class Animal (github.com):

public class Animal extends PanacheEntityBase {
  @Id
  @SequenceGenerator(
      name = "animalSequenceGenerator",
      sequenceName = "animals__seq__id")
  @GeneratedValue(strategy = GenerationType.SEQUENCE, generator = "animalSequenceGenerator")
  @Column(name = "id")
  Long id;
  ...
}

Definition of the corresponding sequence in V2023_04_09__create_tables.sql (github.com):

CREATE SEQUENCE animals__seq__id START WITH 1 INCREMENT BY 50 OWNED BY public.animals.id;

[Sanne]

@turing85 that's a much easier one :)
Unfortunately the default definition of sequences in Hibernate ORM 6 is a bit confusing, I haven't double checked but I'm quite sure you're having an issue with this one:

• https://github.com/hibernate/hibernate-orm/blob/6.0/migration-guide.adoc#defaults-for-implicit-sequence-generators
• https://github.com/quarkusio/quarkus/wiki/Migration-Guide-3.0#the-default-id-generation-optimizer-is-now-pooled-lo

In short, have the sequence start from 51.

For Hibernate ORM we have some flags that help migration; unfortunately they aren't applicable for Hibernate Reactive so extra care is needed. I think asking the ORM to validate the schema should be able to flag this one.

[turing85]

@Sanne ... what the...? Isn't this a major breaking change for every system using sequences with allocation sizes?

[turing85]

@Sanne I set the sequence to start at 51 (CREATE SEQUENCE ... START WITH 51 ...), still same error. I also do not believe that I hit this change since I define the sequence in the database, through flyway. Also, the error rate is extremely low. Seems like a concurrency issue to me.

[Sanne]

@turing85 I had a better look, you're right the sequence is declared correctly (starting from 51 wasn't necessary) and there's indeed a problem in the ReactiveGeneratorWrapper.
Tracking as hibernate/hibernate-reactive#1587

[Sanne]

Changed title and labels as Panache seems unrelated

[Sanne]

Have now merged a fix in Hibernate Reactive, we'll release it soon and upgrade Quarkus.

• Identifier generator fix hibernate/hibernate-reactive#1608