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.

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

NPE warning in native mode #37956

Closed
yanxuehe opened this issue Dec 29, 2023 · 18 comments
Closed

NPE warning in native mode #37956

yanxuehe opened this issue Dec 29, 2023 · 18 comments
Labels
area/hibernate-orm Hibernate ORM area/native-image kind/bug Something isn't working

Comments

@yanxuehe
Copy link

yanxuehe commented Dec 29, 2023

Describe the bug

2023-12-29 02:00:22,008 WARN  [org.hib.eng.jdb.env.int.JdbcEnvironmentInitiator] (JPA Startup Thread) HHH000342: Could not obtain connection to query metadata: java.lang.NullPointerException
	at org.hibernate.resource.transaction.backend.jta.internal.JtaIsolationDelegate.doTheWork(JtaIsolationDelegate.java:186)
	at org.hibernate.resource.transaction.backend.jta.internal.JtaIsolationDelegate.lambda$delegateWork$1(JtaIsolationDelegate.java:75)
	at org.hibernate.resource.transaction.backend.jta.internal.JtaIsolationDelegate.doInSuspendedTransaction(JtaIsolationDelegate.java:107)
	at org.hibernate.resource.transaction.backend.jta.internal.JtaIsolationDelegate.delegateWork(JtaIsolationDelegate.java:72)
	at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.getJdbcEnvironmentUsingJdbcMetadata(JdbcEnvironmentInitiator.java:279)
	at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:193)
	at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:69)
	at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.initiateService(StandardServiceRegistryImpl.java:119)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:264)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:239)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:216)
	at org.hibernate.engine.jdbc.internal.JdbcServicesImpl.configure(JdbcServicesImpl.java:52)
	at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.configureService(StandardServiceRegistryImpl.java:125)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:248)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:216)
	at org.hibernate.boot.internal.SessionFactoryOptionsBuilder.<init>(SessionFactoryOptionsBuilder.java:273)
	at io.quarkus.hibernate.orm.runtime.recording.PrevalidatedQuarkusMetadata.buildSessionFactoryOptionsBuilder(PrevalidatedQuarkusMetadata.java:70)
	at io.quarkus.hibernate.orm.runtime.boot.FastBootEntityManagerFactoryBuilder.build(FastBootEntityManagerFactoryBuilder.java:81)
	at io.quarkus.hibernate.orm.runtime.FastBootHibernatePersistenceProvider.createEntityManagerFactory(FastBootHibernatePersistenceProvider.java:74)
	at jakarta.persistence.Persistence.createEntityManagerFactory(Persistence.java:80)
	at jakarta.persistence.Persistence.createEntityManagerFactory(Persistence.java:55)
	at io.quarkus.hibernate.orm.runtime.JPAConfig$LazyPersistenceUnit.get(JPAConfig.java:156)
	at io.quarkus.hibernate.orm.runtime.JPAConfig$1.run(JPAConfig.java:64)
	at java.base@21.0.1/java.lang.Thread.runWith(Thread.java:1596)
	at java.base@21.0.1/java.lang.Thread.run(Thread.java:1583)
	at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:832)
	at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)

Expected behavior

no warnings.

Actual behavior

No response

How to Reproduce?

No response

Output of uname -a or ver

No response

Output of java -version

21

Mandrel or GraalVM version (if different from Java)

with docker builder

Quarkus version or git rev

3.6.4

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

No response

Additional information

No response

@yanxuehe yanxuehe added area/native-image kind/bug Something isn't working labels Dec 29, 2023
Copy link

quarkus-bot bot commented Dec 29, 2023

/cc @Karm (mandrel), @galderz (mandrel), @zakkak (mandrel,native-image)

@gastaldi
Copy link
Contributor

gastaldi commented Jan 2, 2024

Can you please share a small reproducer?

@gastaldi gastaldi added the triage/needs-reproducer We are waiting for a reproducer. label Jan 2, 2024
@yanxuehe
Copy link
Author

yanxuehe commented Jan 4, 2024

@gastaldi thanks for your help.

# java version
openjdk version "21.0.1" 2023-10-17
OpenJDK Runtime Environment GraalVM CE 21.0.1+12.1 (build 21.0.1+12-jvmci-23.1-b19)
OpenJDK 64-Bit Server VM GraalVM CE 21.0.1+12.1 (build 21.0.1+12-jvmci-23.1-b19, mixed mode, sharing)

# generate keystore
keytool -genkey -keyalg RSA -alias selfsigned -keystore keystore.jks -storepass changeit -validity 365 -keysize 2048

# build
./mvnw clean install \
  -Dmaven.test.skip=true \
  -Dnative \
-Dquarkus.native.additional-build-args=-J--enable-preview

# run (ref to application.yaml)
DB_USER=<> DB_PASS=<> DB_NAME=<> KEYSTORE_PASS=changeit ./target/37956-reproducer-1.0.0-SNAPSHOT-runner

37956-reproducer.zip

@gastaldi gastaldi added area/hibernate-orm Hibernate ORM and removed triage/needs-reproducer We are waiting for a reproducer. labels Jan 4, 2024
@gastaldi
Copy link
Contributor

gastaldi commented Jan 5, 2024

It seems that you're using H2 and that the server isn't running when the runner JAR is invoked?

@yanxuehe
Copy link
Author

yanxuehe commented Jan 8, 2024

No, h2 is used for the dev profile. the runner jar is with db2.

the db2 is up and running when the runner is starting

@gastaldi
Copy link
Contributor

gastaldi commented Jan 9, 2024

I've run your reproducer locally against a running DB2 instance and I don't see the stacktrace you mentioned.
Are you sure you have correctly set the DB_HOST environment on your end?

This is my output:

DB_USER=user DB_PASS=password DB_NAME=quarkus DB_HOST=my.host.com KEYSTORE_PASS=changeit ./target/37956-reproducer-1.0.0-SNAPSHOT-runner
Hibernate: create table TestEntity (id bigint not null, name varchar(255), primary key (id))
__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2024-01-09 11:03:11,239 INFO  [com.tes.Startup] (main) Startup.init
2024-01-09 11:03:11,348 INFO  [io.quarkus] (main) 37956-reproducer 1.0.0-SNAPSHOT native (powered by Quarkus 3.6.4) started in 2.047s. Listening on: http://0.0.0.0:8080 and https://0.0.0.0:8443
2024-01-09 11:03:11,348 INFO  [io.quarkus] (main) Profile prod activated.
2024-01-09 11:03:11,348 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, config-yaml, hibernate-orm, hibernate-orm-panache, hibernate-validator, jdbc-db2, jdbc-h2, kafka-client, kubernetes, narayana-jta, rest-client, rest-client-jackson, rest-client-mutiny, resteasy, resteasy-jackson, security, security-jpa, smallrye-context-propagation, smallrye-fault-tolerance, smallrye-health, smallrye-jwt, smallrye-openapi, smallrye-reactive-messaging, smallrye-reactive-messaging-kafka, vertx]

@yanxuehe
Copy link
Author

@gastaldi

i tried with postgres the warn issue will be gone, for db2 it will come for always (db2 on our lab and db2 on my podman)

could it be something wrong in the driver?

podman run -d --name db2server --restart=always --detach --privileged=true -p  50000:50000 --env-file env_list.txt icr.io/db2_community/db2
cat env_list.txt
LICENSE=accept
DB2INSTANCE=db2inst1
DB2INST1_PASSWORD=password
DBNAME=quarkus
BLU=false
ENABLE_ORACLE_COMPATIBILITY=false
UPDATEAVAIL=NO
TO_CREATE_SAMPLEDB=true
REPODB=true
IS_OSXFS=false
PERSISTENT_HOME=false
HADR_ENABLED=false
ETCD_ENDPOINT=
ETCD_USERNAME=
ETCD_PASSWORD=

@gastaldi
Copy link
Contributor

Can you post the complete output? It looks like the output in the issue description is caused by another error?

@yanxuehe
Copy link
Author

➜ mne 37956-reproducer
➜ 37956-reproducer (develop) ✗ DB_HOST=10.0.0.10 DB_USER=db2inst1 DB_PASS=password DB_TYPE=db2 DB_NAME=MNEAAS KEYSTORE_PASS=changeit ./target/37956-reproducer-1.0.0-SNAPSHOT-runner
__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2024-01-12 21:56:17,656 WARN  [org.hib.eng.jdb.env.int.JdbcEnvironmentInitiator] (JPA Startup Thread) HHH000342: Could not obtain connection to query metadata: java.lang.NullPointerException
	at org.hibernate.resource.transaction.backend.jta.internal.JtaIsolationDelegate.doTheWork(JtaIsolationDelegate.java:186)
	at org.hibernate.resource.transaction.backend.jta.internal.JtaIsolationDelegate.lambda$delegateWork$1(JtaIsolationDelegate.java:75)
	at org.hibernate.resource.transaction.backend.jta.internal.JtaIsolationDelegate.doInSuspendedTransaction(JtaIsolationDelegate.java:107)
	at org.hibernate.resource.transaction.backend.jta.internal.JtaIsolationDelegate.delegateWork(JtaIsolationDelegate.java:72)
	at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.getJdbcEnvironmentUsingJdbcMetadata(JdbcEnvironmentInitiator.java:279)
	at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:193)
	at org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator.initiateService(JdbcEnvironmentInitiator.java:69)
	at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.initiateService(StandardServiceRegistryImpl.java:119)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.createService(AbstractServiceRegistryImpl.java:264)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:239)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:216)
	at org.hibernate.engine.jdbc.internal.JdbcServicesImpl.configure(JdbcServicesImpl.java:52)
	at org.hibernate.boot.registry.internal.StandardServiceRegistryImpl.configureService(StandardServiceRegistryImpl.java:125)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService(AbstractServiceRegistryImpl.java:248)
	at org.hibernate.service.internal.AbstractServiceRegistryImpl.getService(AbstractServiceRegistryImpl.java:216)
	at org.hibernate.boot.internal.SessionFactoryOptionsBuilder.<init>(SessionFactoryOptionsBuilder.java:273)
	at io.quarkus.hibernate.orm.runtime.recording.PrevalidatedQuarkusMetadata.buildSessionFactoryOptionsBuilder(PrevalidatedQuarkusMetadata.java:70)
	at io.quarkus.hibernate.orm.runtime.boot.FastBootEntityManagerFactoryBuilder.build(FastBootEntityManagerFactoryBuilder.java:81)
	at io.quarkus.hibernate.orm.runtime.FastBootHibernatePersistenceProvider.createEntityManagerFactory(FastBootHibernatePersistenceProvider.java:74)
	at jakarta.persistence.Persistence.createEntityManagerFactory(Persistence.java:80)
	at jakarta.persistence.Persistence.createEntityManagerFactory(Persistence.java:55)
	at io.quarkus.hibernate.orm.runtime.JPAConfig$LazyPersistenceUnit.get(JPAConfig.java:156)
	at io.quarkus.hibernate.orm.runtime.JPAConfig$1.run(JPAConfig.java:64)
	at [email protected]/java.lang.Thread.runWith(Thread.java:1596)
	at [email protected]/java.lang.Thread.run(Thread.java:1583)
	at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:832)
	at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)

2024-01-12 21:56:17,677 INFO  [com.tes.Startup] (main) Startup.init
2024-01-12 21:56:17,805 INFO  [io.quarkus] (main) 37956-reproducer 1.0.0-SNAPSHOT native (powered by Quarkus 3.6.4) started in 5.191s. Listening on: http://0.0.0.0:8080 and https://0.0.0.0:8443
2024-01-12 21:56:17,805 INFO  [io.quarkus] (main) Profile prod activated.
2024-01-12 21:56:17,805 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, config-yaml, hibernate-orm, hibernate-orm-panache, hibernate-validator, jdbc-db2, kafka-client, kubernetes, narayana-jta, rest-client, rest-client-jackson, rest-client-mutiny, resteasy-jackson, security, security-jpa, smallrye-context-propagation, smallrye-fault-tolerance, smallrye-health, smallrye-jwt, smallrye-openapi, smallrye-reactive-messaging, smallrye-reactive-messaging-kafka, vertx]

@gastaldi
Copy link
Contributor

I tried my reproducer again and I don't see this error. Maybe this is a dumb question, but can you connect to the DB in 10.0.0.10 using another local client?

@yanxuehe
Copy link
Author

yes, i am 100% sure it is connectable.

@marko-bekhta
Copy link
Contributor

hey,
I've tried to reproduce this one with no luck as well 😕. But I did notice that the reason why Hibernate couldn't obtain the connection may be eaten by that java.lang.NullPointerException we see in the logs you've provided, so I've opened a PR here hibernate/hibernate-orm#7865

Do you only see this error in native mode? Could you please try to use DB2 in dev and see if you get the error there?

@yanxuehe
Copy link
Author

hi,

sorry for the late response, the error comes for native only.

@galderz
Copy link
Member

galderz commented Apr 18, 2024

@marko-bekhta Is there already a Quarkus version that includes the fix you did for hibernate/hibernate-orm#7865? If so maybe @yanxuehe can try and see what he sees now?

@marko-bekhta
Copy link
Contributor

Hey,

the fix we are talking about is for https://hibernate.atlassian.net/browse/HHH-17872, which is included in Hibernate ORM 6.4.5 and 6.5.0... 6.4.5 is not yet released and 6.5.0 is a CR2 (#40102) so for now it won't be trivial to test it 😔

@yrodiere
Copy link
Member

@marko-bekhta We just merged an upgrade to Hibernate ORM 6.4.5 in Quarkus. Snapshots of Quarkus should get deployed by tomorrow 2AM UTC. Testing may be easier now?

Here are instructions to use Quarkus snapshots: https://github.com/quarkusio/quarkus/blob/main/CONTRIBUTING.md#using-snapshots

@marko-bekhta
Copy link
Contributor

Nice! Let's ping @yanxuehe to see if that can be done.

@yrodiere
Copy link
Member

yrodiere commented Aug 1, 2024

Closing due to being unable to reproduce, and lack of update.
Feel free to comment/reopen if you have more information @yanxuehe.

@yrodiere yrodiere closed this as not planned Won't fix, can't repro, duplicate, stale Aug 1, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/hibernate-orm Hibernate ORM area/native-image kind/bug Something isn't working
Projects
None yet
Development

No branches or pull requests

5 participants