quarkusio / quarkus-quickstarts

Quarkus quickstart code
https://quarkus.io
Apache License 2.0
1.95k stars 1.45k forks source link

hibernate-search-elasticsearch-quickstart QS fails with GraalVM 19.3.1 #489

Open rsvoboda opened 4 years ago

rsvoboda commented 4 years ago

hibernate-search-elasticsearch-quickstart QS fails with GraalVM 19.3.1 in JVM mode It didn't fail when I used OpenJDK 8 and 11. elasticsearch-maven-plugin:6.15:runforked phase is failing.

14:07:09.110 PostgreSQL:2020-03-12 13:07:09.107 UTC [1] LOG:  database system is ready to accept connections
[INFO] Elasticsearch[0]: Executing command '[bin/elasticsearch-plugin, list]' in directory '/Users/rsvoboda/git/quarkus-quickstarts/hibernate-search-elasticsearch-quickstart/target/elasticsearch0'
[INFO] Elasticsearch[0]: The process finished with exit code 0
[INFO] Elasticsearch[0]: Executing command '[bin/elasticsearch, -p, pid, -Ecluster.name=test, -Ehttp.port=9200, -Etransport.tcp.port=9300, -Ehttp.cors.enabled=true]' in directory '/Users/rsvoboda/git/quarkus-quickstarts/hibernate-search-elasticsearch-quickstart/target/elasticsearch0'
Exception in thread "main" java.lang.RuntimeException: starting java failed with [1]
output:
Error occurred during initialization of VM
JVMCI Compiler does not support selected GC: concurrent mark sweep gc
error:
OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.
    at org.elasticsearch.tools.launchers.JvmErgonomics.flagsFinal(JvmErgonomics.java:123)
    at org.elasticsearch.tools.launchers.JvmErgonomics.finalJvmOptions(JvmErgonomics.java:88)
    at org.elasticsearch.tools.launchers.JvmErgonomics.choose(JvmErgonomics.java:59)
    at org.elasticsearch.tools.launchers.JvmOptionsParser.main(JvmOptionsParser.java:95)

Reproducer:

sdk use java 19.3.1.r11-grl && export GRAALVM_HOME=$JAVA_HOME
mvn clean verify -pl hibernate-search-elasticsearch-quickstart

Longer version from console:

[INFO] --- docker-maven-plugin:0.28.0:start (docker-start) @ hibernate-search-elasticsearch-quickstart ---
[INFO] DOCKER> [postgres:11.3] "postgresql": Start container d63242a9e2c3
[INFO] DOCKER> [postgres:11.3] "postgresql": Waiting for mapped ports [5432] on host localhost
[INFO] DOCKER> [postgres:11.3] "postgresql": Waited on tcp port '[localhost/127.0.0.1:5432]' 12 ms
[INFO]
[INFO] --- elasticsearch-maven-plugin:6.15:runforked (start-elasticsearch) @ hibernate-search-elasticsearch-quickstart ---
14:07:06.835 PostgreSQL:The files belonging to this database system will be owned by user "postgres".
14:07:06.835 PostgreSQL:This user must also own the server process.
14:07:06.835 PostgreSQL:
14:07:06.835 PostgreSQL:The database cluster will be initialized with locale "en_US.utf8".
14:07:06.835 PostgreSQL:The default database encoding has accordingly been set to "UTF8".
14:07:06.835 PostgreSQL:The default text search configuration will be set to "english".
14:07:06.835 PostgreSQL:
14:07:06.835 PostgreSQL:Data page checksums are disabled.
14:07:06.835 PostgreSQL:
14:07:06.836 PostgreSQL:fixing permissions on existing directory /var/lib/postgresql/data ... ok
14:07:06.838 PostgreSQL:creating subdirectories ... ok
14:07:06.862 PostgreSQL:selecting default max_connections ... 100
14:07:06.901 PostgreSQL:selecting default shared_buffers ... 128MB
14:07:06.901 PostgreSQL:selecting dynamic shared memory implementation ... posix
[INFO] Using Elasticsearch [0] configuration: com.github.alexcojocaru.mojo.elasticsearch.v2.InstanceConfiguration@442310fd[id=0,baseDir=/Users/rsvoboda/git/quarkus-quickstarts/hibernate-search-elasticsearch-quickstart/target/elasticsearch0,httpPort=9200,transportPort=9300,pathData=<null>,pathLogs=<null>,settings=<null>]
14:07:07.446 PostgreSQL:creating configuration files ... ok
14:07:07.610 PostgreSQL:running bootstrap script ... ok
14:07:08.150 PostgreSQL:performing post-bootstrap initialization ... ok
14:07:08.450 PostgreSQL:syncing data to disk ... ok
14:07:08.450 PostgreSQL:
14:07:08.451 PostgreSQL:WARNING: enabling "trust" authentication for local connections
14:07:08.451 PostgreSQL:You can change this by editing pg_hba.conf or using the option -A, or
14:07:08.451 PostgreSQL:--auth-local and --auth-host, the next time you run initdb.
14:07:08.451 PostgreSQL:
14:07:08.451 PostgreSQL:Success. You can now start the database server using:
14:07:08.451 PostgreSQL:
14:07:08.451 PostgreSQL:    pg_ctl -D /var/lib/postgresql/data -l logfile start
14:07:08.451 PostgreSQL:
14:07:08.484 PostgreSQL:waiting for server to start....2020-03-12 13:07:08.484 UTC [41] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
14:07:08.505 PostgreSQL:2020-03-12 13:07:08.504 UTC [42] LOG:  database system was shut down at 2020-03-12 13:07:08 UTC
14:07:08.512 PostgreSQL:2020-03-12 13:07:08.511 UTC [41] LOG:  database system is ready to accept connections
14:07:08.570 PostgreSQL: done
14:07:08.570 PostgreSQL:server started
14:07:08.931 PostgreSQL:CREATE DATABASE
14:07:08.934 PostgreSQL:
14:07:08.934 PostgreSQL:
14:07:08.934 PostgreSQL:/usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/*
14:07:08.935 PostgreSQL:
14:07:08.939 PostgreSQL:2020-03-12 13:07:08.939 UTC [41] LOG:  received fast shutdown request
14:07:08.941 PostgreSQL:waiting for server to shut down....2020-03-12 13:07:08.940 UTC [41] LOG:  aborting any active transactions
14:07:08.948 PostgreSQL:2020-03-12 13:07:08.947 UTC [41] LOG:  background worker "logical replication launcher" (PID 48) exited with exit code 1
14:07:08.949 PostgreSQL:2020-03-12 13:07:08.949 UTC [43] LOG:  shutting down
14:07:08.965 PostgreSQL:2020-03-12 13:07:08.965 UTC [41] LOG:  database system is shut down
14:07:09.042 PostgreSQL: done
14:07:09.042 PostgreSQL:server stopped
14:07:09.043 PostgreSQL:
14:07:09.043 PostgreSQL:PostgreSQL init process complete; ready for start up.
14:07:09.043 PostgreSQL:
14:07:09.068 PostgreSQL:2020-03-12 13:07:09.067 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
14:07:09.068 PostgreSQL:2020-03-12 13:07:09.067 UTC [1] LOG:  listening on IPv6 address "::", port 5432
14:07:09.072 PostgreSQL:2020-03-12 13:07:09.072 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
14:07:09.100 PostgreSQL:2020-03-12 13:07:09.097 UTC [59] LOG:  database system was shut down at 2020-03-12 13:07:08 UTC
14:07:09.110 PostgreSQL:2020-03-12 13:07:09.107 UTC [1] LOG:  database system is ready to accept connections
[INFO] Elasticsearch[0]: Executing command '[bin/elasticsearch-plugin, list]' in directory '/Users/rsvoboda/git/quarkus-quickstarts/hibernate-search-elasticsearch-quickstart/target/elasticsearch0'
[INFO] Elasticsearch[0]: The process finished with exit code 0
[INFO] Elasticsearch[0]: Executing command '[bin/elasticsearch, -p, pid, -Ecluster.name=test, -Ehttp.port=9200, -Etransport.tcp.port=9300, -Ehttp.cors.enabled=true]' in directory '/Users/rsvoboda/git/quarkus-quickstarts/hibernate-search-elasticsearch-quickstart/target/elasticsearch0'
Exception in thread "main" java.lang.RuntimeException: starting java failed with [1]
output:
Error occurred during initialization of VM
JVMCI Compiler does not support selected GC: concurrent mark sweep gc
error:
OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.
    at org.elasticsearch.tools.launchers.JvmErgonomics.flagsFinal(JvmErgonomics.java:123)
    at org.elasticsearch.tools.launchers.JvmErgonomics.finalJvmOptions(JvmErgonomics.java:88)
    at org.elasticsearch.tools.launchers.JvmErgonomics.choose(JvmErgonomics.java:59)
    at org.elasticsearch.tools.launchers.JvmOptionsParser.main(JvmOptionsParser.java:95)
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  13.066 s
[INFO] Finished at: 2020-03-12T14:07:14+01:00
[INFO] ------------------------------------------------------------------------
rsvoboda commented 4 years ago

@gsmet fyi

rsvoboda commented 4 years ago

PostgreSQL container is not stopped because of this and breaks other QS execution. In my case it caused failures of https://github.com/quarkusio/quarkus-quickstarts/blob/master/security-jdbc-quickstart/src/test/java/org/acme/elytron/security/jdbc/JdbcSecurityRealmTest.java#L25 (I use -fae for maven command)

aguibert commented 4 years ago

Regarding the leftover PostgreSQL container:

whenever testcontainers starts up a container, by default it will add that container to be automatically cleaned up in a JVM shutdown hook I think the only reason the container is left around in this case is because the JVM is crashing and shutdown hooks aren't running. Normally this wouldn't conflict with subsequent runs because by default testcontainers selects a random port on the host to use. But in this quickstart they always bind to 5432 specifically. The quickstart could be updated to use the default randomized ports, but it's probably more important to fix the JVM crash first.

gsmet commented 4 years ago

/cc @yrodiere any chance we could use a GC supported by GraalVM out of the box?

yrodiere commented 4 years ago

@gsmet Totally. We can customize jvm options easily. In fact we already do: https://github.com/quarkusio/quarkus-quickstarts/blob/master/hibernate-search-elasticsearch-quickstart/src/test/resources/elasticsearch-maven-plugin/configuration/jvm.options#L39

Ideally, I'd prefer using a separate JVM for Elasticsearch, as I don't think the Elasticsearch team supports running ES on GraalVM. That can be done with elasticsearch-maven-plugin, but it will make the Maven configuration more complex which probably is something you'll want to avoid in a quickstart.

Can't we just use a container instead of elasticsearch-maven-plugin? Since we already do that for postgreSQL? If I had some free time to set it up, and if I wasn't forced to support ES versions that don't have a standard, usable container available (ES 5.6), that's totally what I would do in the Hibernate Search build.