Quarkus: Having some issues with multi-threading and hibernate-with-panache

[nfau1]

Describe the bug
There are two things :

• If i call in the onStart() method (the one that allows to execute code once the server launched) the findAll() method from hibernate-with-panache ORM, i got this warning :

[io.agr.pool] (main) DataSource '':Closing open connection prior to commit"
[io.agr.pool] (main) DataSource '':JDBC ressources leaked 1 ResultSet(s)and 1 Statement(s)"

• If i create a thread in the same method (onStart()), and i try to call a method from hibernate-with-panache ORM, the application crashes and give me the next errors :

Exception in thread "Thread-29" javax.enterprise.context.ContextNotActiveException: interface javax.enterprise.context.RequestScoped
        at io.quarkus.hibernate.orm.runtime.RequestScopedEntityManagerHolder_ClientProxy.arc$delegate(RequestScopedEntityManagerHolder_ClientProxy.zig:83)
        at io.quarkus.hibernate.orm.runtime.RequestScopedEntityManagerHolder_ClientProxy.getOrCreateEntityManager(RequestScopedEntityManagerHolder_ClientProxy.zig:191)
        at io.quarkus.hibernate.orm.runtime.entitymanager.TransactionScopedEntityManager.getEntityManager(TransactionScopedEntityManager.java:78)
        at io.quarkus.hibernate.orm.runtime.entitymanager.TransactionScopedEntityManager.createQuery(TransactionScopedEntityManager.java:317)
        at io.quarkus.hibernate.orm.runtime.entitymanager.ForwardingEntityManager.createQuery(ForwardingEntityManager.java:142)
        at io.quarkus.hibernate.orm.panache.runtime.JpaOperations.findAll(JpaOperations.java:287)
        at io.quarkus.hibernate.orm.panache.runtime.JpaOperations.streamAll(JpaOperations.java:307) 

To Reproduce
Steps to reproduce the behavior:

1. create the simplest Quarkus application possible
2. create one Entity in your application (@Entity on the class and extends PanacheEntity)
3. create a class as this one :

@ApplicationScoped
public class AppLifecycleBean {
    @Transactional
    void onStart(@Observes StartupEvent ev) {
        Stream<PanacheEntityBase> a = Application.streamAll();
        /* If you use this Thread, it's gonna crash*/
//      new Thread(() ->{
//          Application.streamAll();
//      }).start();
    }
}

• The first bug is present with this code.
• The second one will be if you uncomment Thread

1. configure your application.properties
2. ./mvnw compile quarkus:dev

Configuration

quarkus.datasource.url=jdbc:postgresql:restcrud
quarkus.datasource.driver=org.postgresql.Driver
quarkus.datasource.username=restcrud
quarkus.datasource.password=restcrud
quarkus.hibernate-orm.database.generation=update

Screenshots
This is my Entity

@Entity
@Cacheable
public class Application extends PanacheEntity {

    @Column(name = "ID_APP")
    private int idApp;

    @Column(name = "NAME_APP")
    private String app;

    @Column(name = "PORT_APP")
    private int port;

    public Application() {
    }

    public Application(int id, String app, int port) {
        this.idApp = id;
        this.app = app;
        this.port = port;
    }

    public void update() {
        this.persist();
    }
}

Environment (please complete the following information):

• Output of uname -a or ver: Microsoft Windows [version 10.0.17763.864]
• Output of java -version: java version "11.0.2" 2019-01-15 LTS
• GraalVM version (if different from Java): Do not have Graal installed
• Quarkus version or git rev: 1.0.0.Final (same error for ealier versions)

[geoand]

cc @FroMage

[loicmathieu]

Be careful that when you use the stream() method, it needs to be inside a transaction boundary.
So if you use this stream inside a new Thread, you will be out of the transaction. That's why it crashes. And I think it's incorrect to do this.

For the first issue, I too saw those logs when using stream() methods since 1.0.0.CR1, I don't know why they start displaying. These messages are from Agroal.

[io.agr.pool] (main) DataSource '':Closing open connection prior to commit"
[io.agr.pool] (main) DataSource '':JDBC ressources leaked 1 ResultSet(s)and 1 Statement(s)"

[FroMage]

Yeah, if you want to extend your transaction to other threads, you need context propagation: https://quarkus.io/guides/context-propagation

You also need to make sure the transaction is not terminated until your thread is done by returning an async type: https://quarkus.io/guides/transaction#reactive-extensions

As for the first question, I'm pretty sure you need to close the Stream you just created, either manually, or by traversing it with a terminal operation.

In both cases I think this is not a bug, but please let us know if there's any documentation we need to improve that would have allowed you to not hit these issues?

[loicmathieu]

@FroMage the following code seems legit to me, works fine with Quarkus 0.28.1, and starts generating the Datasource logs since 1.0.0.CR1:

@Transactional
    public List<PrepaidCard> list(String language) {
        return prepaidCardRepository.find("statusId != 'DIS'").stream()
                .map(prepaidCard -> enhancePreparedCardWithAccountInfo(prepaidCard))
                .map(prepaidCard -> addStatusLabel(prepaidCard, language))
                .collect(Collectors.toList());
    }

Both enhancePreparedCardWithAccountInfo and addStatusLabel make database queries.

[FroMage]

That seems legit, but another bug. Could you try to track who is creating this non-closed ResultSet?

[nfau1]

Thanks !

Actually, closing the stream resolved the problem of the warning

[io.agr.pool] (main) DataSource '':Closing open connection prior to commit"
[io.agr.pool] (main) DataSource '':JDBC ressources leaked 1 ResultSet(s)and 1 Statement(s)"

And concerning the Thread issue, it seems obvious that the context is different (my bad). Calling a method which is annotated by @Transactional resolve the problem.

[gsmet]

OK, looks like we can close this one, then.

Thanks!

[nfau1]

@FroMage, just a last thing before closing the issue. Adding in the documentation that we need to close the Stream created with the stream() methods can be a good idea. I'm not sure this is mentioned.

[fabricepipart]

Hi!

That was quite unexpected to have to close the stream. Putting the stream in an auto-closable try-with-resource block does the trick. I had to change my code to something like:

      try (Stream<E> s = repository.findAll(pageIndex, pageSize)) {
        return s.map(repository::toDTO).collect(Collectors.toList());
      }

I have to say it is not so natural... I hope it is just needed because otherwise it actually leaks resources.

[loicmathieu]

@fabricepipart it's a bit strange but it's needed because the stream is backed by an I/O source (it's not a stream made on a collection of rows).

Reading the JavaDoc of Stream:

Streams have a BaseStream.close() method and implement AutoCloseable, but nearly all stream instances do not actually need to be closed after use. Generally, only streams whose source is an IO channel (such as those returned by Files.lines(Path, Charset)) will require closing. Most streams are backed by collections, arrays, or generating functions, which require no special resource management. (If a stream does require closing, it can be declared as a resource in a try-with-resources statement.)