'Why am i getting timeout exception after 4 requests to database?

I am building quarkus websocket test application with reactive panache connection to postgres. Code:

@Slf4j
@RequiredArgsConstructor
@ServerEndpoint(value = "/api/websocket",
        decoders = ObjectDecoder.class,
        encoders = ObjectEncoder.class)
public class Websocket {

    private final SimpleService simpleService;

    @OnOpen
    public void onOpen(Session session) {
        log.info("ON OPEN");
        simpleService.getAll().subscribe().with(item -> sendItem(session, item));
    }

    private void sendItem(Session session, SimpleObject item) {
        session.getAsyncRemote().sendObject(item, result -> {
            if (result.getException() != null) {
                result.getException().printStackTrace();
            }
        });
    }

//and other methods...

}

@ApplicationScoped
@RequiredArgsConstructor
public class SimpleService {

    private final SimpleObjectRepository repository; //default repo 

    public Multi<SimpleObject> getAll() {
        return repository.streamAll();
    }
}


@Entity
@Getter
@Setter
public class SimpleObject {

    @Id
    @GeneratedValue(generator = "UUID")
    @GenericGenerator(
            name = "UUID",
            strategy = "org.hibernate.id.UUIDGenerator"
    )
    @Column(name = "id")
    private UUID id;

    @Column(name = "message")
    private String message;
}

quarkus.http.port=8070

quarkus.datasource.db-kind=postgresql
quarkus.datasource.username=postgres
quarkus.datasource.password=docker
quarkus.datasource.reactive.url=postgresql://localhost:5432/reactive_test

quarkus.websocket.dispatch-to-worker=true

quarkus.websocket.dispatch-to-worker=true

without this setting i get session/entity manager is closed exception(Blocking IO Thread in Quarkus Websocket)

After 4 connections to websocket from postman i get timeout exception:

__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2022-02-01 13:33:02,159 INFO  [io.und.websockets] (Quarkus Main Thread) UT026003: Adding annotated server endpoint class org.example.reactive_websocket_
test.Websocket for path /api/websocket

2022-02-01 13:33:02,191 INFO  [org.hib.rea.pro.imp.ReactiveIntegrator] (JPA Startup Thread: default-reactive) HR000001: Hibernate Reactive
2022-02-01 13:33:02,200 INFO  [io.quarkus] (Quarkus Main Thread) reactive_websocket_test 1.0-SNAPSHOT on JVM (powered by Quarkus 2.6.3.Final) started in
 0.600s. Listening on: http://localhost:8070
2022-02-01 13:33:02,202 INFO  [io.quarkus] (Quarkus Main Thread) Profile dev activated. Live Coding activated.
2022-02-01 13:33:02,203 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [cdi, hibernate-orm, hibernate-reactive, hibernate-reactive-panache
, reactive-pg-client, resteasy-reactive, resteasy-reactive-jackson, smallrye-context-propagation, vertx, websockets, websockets-client]
2022-02-01 13:33:02,204 INFO  [io.qua.dep.dev.RuntimeUpdatesProcessor] (Aesh InputStream Reader) Live reload total time: 1.531s
2022-02-01 13:33:05,225 INFO  [org.exa.rea.Websocket] (executor-thread-0) ON OPEN
2022-02-01 13:33:10,962 INFO  [org.exa.rea.Websocket] (executor-thread-0) ON CLOSE
2022-02-01 13:33:12,948 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON OPEN
2022-02-01 13:33:14,502 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON CLOSE
2022-02-01 13:33:16,001 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON OPEN
2022-02-01 13:33:17,720 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON CLOSE
2022-02-01 13:33:19,312 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON OPEN
2022-02-01 13:33:21,830 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON CLOSE
2022-02-01 13:33:23,806 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON OPEN
2022-02-01 13:33:53,809 ERROR [org.hib.rea.errors] (vert.x-eventloop-thread-7) HR000057: Failed to execute statement [$1select simpleobje0_.id as id1_0_
, simpleobje0_.message as message2_0_ from SimpleObject simpleobje0_]: $2could not execute query: java.util.concurrent.CompletionException: io.vertx.cor
e.impl.NoStackTraceThrowable: Timeout
        at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331)
        at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346)
        at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
        at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
        at io.vertx.core.Future.lambda$toCompletionStage$2(Future.java:362)
        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.Mapping.onFailure(Mapping.java:45)
        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.core.impl.future.PromiseImpl.handle(PromiseImpl.java:23)
        at io.vertx.sqlclient.impl.pool.SqlConnectionPool$1PoolRequest.lambda$null$0(SqlConnectionPool.java:202)
        at io.vertx.core.net.impl.pool.SimpleConnectionPool$Cancel.run(SimpleConnectionPool.java:666)
        at io.vertx.core.net.impl.pool.CombinerExecutor.submit(CombinerExecutor.java:50)
        at io.vertx.core.net.impl.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:240)
        at io.vertx.core.net.impl.pool.SimpleConnectionPool.cancel(SimpleConnectionPool.java:629)
        at io.vertx.sqlclient.impl.pool.SqlConnectionPool$1PoolRequest.lambda$onEnqueue$1(SqlConnectionPool.java:199)
        at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:893)
        at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:860)
        at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:50)
        at io.vertx.core.impl.DuplicatedContext.emit(DuplicatedContext.java:168)
        at io.vertx.core.impl.AbstractContext.emit(AbstractContext.java:53)
        at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:883)
        at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
        at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
        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:834)
Caused by: io.vertx.core.impl.NoStackTraceThrowable: Timeout


java.lang.Exception: Missing onFailure/onError handler in the subscriber
        at io.smallrye.mutiny.subscription.Subscribers.lambda$static$0(Subscribers.java:18)
        at io.smallrye.mutiny.subscription.Subscribers$CallbackBasedSubscriber.onFailure(Subscribers.java:84)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber.handleTerminationIfDone(MultiFlatMapOp.java:511)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber.ifDoneOrCancelled(MultiFlatMapOp.java:486)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber.drainLoop(MultiFlatMapOp.java:286)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber.drain(MultiFlatMapOp.java:266)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber.onFailure(MultiFlatMapOp.java:210)
        at io.smallrye.mutiny.subscription.MultiSubscriber.onError(MultiSubscriber.java:73)
        at io.smallrye.mutiny.converters.uni.UniToMultiPublisher$UniToMultiSubscription.onFailure(UniToMultiPublisher.java:92)
        at io.smallrye.mutiny.operators.uni.UniOperatorProcessor.onFailure(UniOperatorProcessor.java:48)
        at io.smallrye.mutiny.operators.uni.UniOperatorProcessor.onFailure(UniOperatorProcessor.java:48)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription.forwardResult(UniCreateFromCompletionSt
age.java:58)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
        at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
        at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
        at io.vertx.core.Future.lambda$toCompletionStage$2(Future.java:362)
        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.Mapping.onFailure(Mapping.java:45)
        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.core.impl.future.PromiseImpl.handle(PromiseImpl.java:23)
        at io.vertx.sqlclient.impl.pool.SqlConnectionPool$1PoolRequest.lambda$null$0(SqlConnectionPool.java:202)
        at io.vertx.core.net.impl.pool.SimpleConnectionPool$Cancel.run(SimpleConnectionPool.java:666)
        at io.vertx.core.net.impl.pool.CombinerExecutor.submit(CombinerExecutor.java:50)
        at io.vertx.core.net.impl.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:240)
        at io.vertx.core.net.impl.pool.SimpleConnectionPool.cancel(SimpleConnectionPool.java:629)
        at io.vertx.sqlclient.impl.pool.SqlConnectionPool$1PoolRequest.lambda$onEnqueue$1(SqlConnectionPool.java:199)
        at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:893)
        at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:860)
        at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:50)
        at io.vertx.core.impl.DuplicatedContext.emit(DuplicatedContext.java:168)
        at io.vertx.core.impl.AbstractContext.emit(AbstractContext.java:53)
        at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:883)
        at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
        at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
        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:834)
Caused by: io.vertx.core.impl.NoStackTraceThrowable: Timeout

From reading logs - exception might be related to vertx pg client pool (PgPool class). After injecting it to main class and logging it size:

2022-02-01 13:54:00,189 INFO  [io.qua.dep.dev.RuntimeUpdatesProcessor] (Aesh InputStream Reader) Live reload total time: 1.461s
2022-02-01 13:54:03,018 INFO  [org.exa.rea.Websocket] (executor-thread-0) ON OPEN
2022-02-01 13:54:03,027 INFO  [org.exa.rea.Websocket] (executor-thread-0) pool size 1
2022-02-01 13:54:05,782 INFO  [org.exa.rea.Websocket] (executor-thread-0) ON CLOSE
2022-02-01 13:54:06,601 INFO  [org.exa.rea.Websocket] (executor-thread-0) ON OPEN
2022-02-01 13:54:06,604 INFO  [org.exa.rea.Websocket] (executor-thread-0) pool size 2
2022-02-01 13:54:09,492 INFO  [org.exa.rea.Websocket] (executor-thread-0) ON CLOSE
2022-02-01 13:54:11,842 INFO  [org.exa.rea.Websocket] (executor-thread-0) ON OPEN
2022-02-01 13:54:11,845 INFO  [org.exa.rea.Websocket] (executor-thread-0) pool size 3
2022-02-01 13:54:16,368 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON OPEN
2022-02-01 13:54:16,370 INFO  [org.exa.rea.Websocket] (executor-thread-2) pool size 4
2022-02-01 13:54:19,293 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON CLOSE
2022-02-01 13:54:21,238 INFO  [org.exa.rea.Websocket] (executor-thread-2) ON OPEN
2022-02-01 13:54:21,242 INFO  [org.exa.rea.Websocket] (executor-thread-2) pool size 4
2022-02-01 13:54:51,244 ERROR [org.hib.rea.errors] (vert.x-eventloop-thread-11) HR000057: Failed to execute statement [$1select simpleobje0_.id as id1_0
_, simpleobje0_.message as message2_0_ from SimpleObject simpleobje0_]: $2could not execute query: java.util.concurrent.CompletionException: io.vertx.co
re.impl.NoStackTraceThrowable: Timeout

Apparently pool connections are not reused as they meant to be. What am i doing wrong and how to fix this problem?

P.S. to reproduce https://github.com/hadouken900/quarkus-websocker-test

hibernatewebsocketquarkusreactive


Solution 1:[1]

The GraphQL issue is fixed and will be available in 2.10. (see https://github.com/quarkusio/quarkus/pull/25194) The Websocket one I am not sure about

Solution 2:[2]

I've got the same issue with quarkus-hibernate-reactive-panache + quarkus-reactive-pg-client + quarkus-smallrye-graphql

@GraphQLApi
public class BookResource {

    @Query("allBooks")
    @Description("Get all existing books")
    public Uni<List<Book>> listAllBooks() {
        return Book.listAll();
    }
}

The endpoint works well only 4 times, then mentioned above timeout exception appears. Always reproducible.

Sources

This article follows the attribution requirements of Stack Overflow and is licensed under CC BY-SA 3.0.

Source: Stack Overflow

Solution Source
Solution 1 Phillip Krüger
Solution 2 tehapap

Related Questions

Using @Fetch(FetchMode.Join) in Hibernate

Error creating bean with name 'entityManagerFactory'

How to run gradle based spring boot application in background using command line in ubuntu?

Hibernate: org.hibernate.service.spi.ServiceException: Unable to create requested service [org.hibernate.engine.spi.CacheImplementor]

How to read geography values using hibernate?

Hibernate throws org.hibernate.AnnotationException: No identifier specified for entity: com..domain.idea.MAE_MFEView

org.hibernate.QueryParameterException: could not locate named parameter [userId]

Hibernate cascade save parent and children - parent key not found

Spring Hibernate Jackson Hibernate5Module

not-null property references a null or transient value

How to fix org.hibernate.LazyInitializationException - could not initialize proxy - no Session

Hibernate not persisting enums (as String)

Calling Hibernate in background threads in grails

Getting a nullpointerexception for my EntityManager

Hibernate : Why is it trying to drop/create database on startup?