SoftInstigate / restheart

Rapid API Development with MongoDB
https://restheart.org
GNU Affero General Public License v3.0
807 stars 171 forks source link

v6.0.2, Docker, ERROR org.restheart.Bootstrapper (org.restheart.mongodb.db.MongoClientSingleton) #410

Closed mcardia closed 3 years ago

mcardia commented 3 years ago
restheart    |  13:46:55.065 [main] ERROR org.restheart.Bootstrapper - Linkage error executing initializer changeStreamActivator Check that it was compiled against restheart-commons v6.0.2
restheart    |  java.lang.ExceptionInInitializerError: null
restheart    |  at org.restheart.mongodb.db.MongoClientSingleton.getInstance(MongoClientSingleton.java:76)
restheart    | Caused by: java.lang.IllegalStateException: not initialized
restheart    |  at org.restheart.mongodb.db.MongoClientSingleton.<init>(MongoClientSingleton.java:97)
restheart    | 13:46:55.065 [main] ERROR org.restheart.Bootstrapper - Error executing initializer txnsActivator An external dependency is missing. Copy the missing dependency jar to the plugins directory to add it to the classpath
restheart    |  java.lang.NoClassDefFoundError: Could not initialize class org.restheart.mongodb.db.MongoClientSingleton$MongoClientSingletonHolder
restheart    |  at org.restheart.mongodb.db.MongoClientSingleton.getInstance(MongoClientSingleton.java:76)

Expected Behavior

We don't expect to get errors messages in the service

Current Behavior

ERROR org.restheart.Bootstrapper - Error executing initializer txnsActivator An external dependency is missing. Copy the missing dependency jar to the plugins directory to add it to the classpath restheart | java.lang.NoClassDefFoundError: Could not initialize class org.restheart.mongodb.db.MongoClientSingleton$MongoClientSingletonHolder

Context

Starting the service

My Compose:

version: "3"

services:
  restheart:
    image: softinstigate/restheart:latest
    container_name: restheart
    hostname: restheart
    volumes:
      - /etc/restheart:/opt/restheart/etc
    command: ["--envFile", "/opt/restheart/etc/default.properties"]
    networks:
      api-network:
        aliases:
          - restheart
          - restheart.api-network
      db-network:
        aliases:
          - restheart
          - restheart.db-network

networks:
  api-network:
    external: true
  db-network:
    external: true

Environment

Ubuntu 20.04 (at AWS) Mongo 4.4.6 Authentication and authorization using mongo instead of file. Others configurations are the default.

Steps to Reproduce

  1. docker-compose -f compose-file.yml up
ujibang commented 3 years ago

Hi @mcardia

I cannot reproduce it.

Please configure the logging with the following configuration (for help see custom logback configuration ) and reproduce the error.

Then paste the full exception to this thread.

  1. Add the file /opt/restheart/etc/logback.xml:
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <withJansi>true</withJansi>
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %highlight(%-5level) %logger{36} - %msg%n %throwable</pattern>
        </encoder>
    </appender>

    <root level="ERROR">
        <appender-ref ref="STDOUT" />
    </root>

    <logger name="org.restheart" level="ALL"/>
</configuration>
  1. Add to the docker compose the following entrypoint to the restheart service
services:
  restheart:
    image: softinstigate/restheart:latest
    container_name: restheart
    hostname: restheart
    entrypoint: [ "java", "-Dfile.encoding=UTF-8", "-Dlogback.configurationFile=etc/logback.xml", "-server", "-jar", "restheart.jar", "etc/restheart.yml"]
mkjsix commented 3 years ago

@mcardia as a quicker check, please set the image to the exact version instead of latest

image: softinstigate/restheart:6.0.2

I suspect an issue with the publishing of the latest tag during our build process.

mkjsix commented 3 years ago

As a second check, please verify that the latest and 6.0.2 tags has the same IMAGE ID, like in my case:

➜  ~ docker images
REPOSITORY                       TAG               IMAGE ID       CREATED        SIZE
softinstigate/restheart          6.0.2             15e46d558fef   30 hours ago   291MB
softinstigate/restheart          latest            15e46d558fef   30 hours ago   291MB

If not, re-pull both images and verify again.

mcardia commented 3 years ago

Hi @mcardia

I cannot reproduce it.

HI! Thank you for the answer. The log below:

WARNING: Found orphan containers (metabase) for this project. If you removed or renamed this service in your compose file, you can run this command with the --remove-orphans flag to clean it up.
Recreating restheart ... done
Attaching to restheart
restheart    | 11:26:44.830 [main] TRACE org.restheart.Configuration - configuration paramenter "ansi-console" set to "true"
restheart    |  11:26:44.834 [main] TRACE org.restheart.Configuration - configuration paramenter "https-listener" set to "false"
restheart    |  11:26:44.834 [main] TRACE org.restheart.Configuration - configuration paramenter "https-port" set to "4443"
restheart    |  11:26:44.835 [main] TRACE org.restheart.Configuration - configuration paramenter "https-host" set to "0.0.0.0"
restheart    |  11:26:44.835 [main] TRACE org.restheart.Configuration - configuration paramenter "http-listener" set to "true"
restheart    |  11:26:44.836 [main] TRACE org.restheart.Configuration - configuration paramenter "http-port" set to "27000"
restheart    |  11:26:44.836 [main] TRACE org.restheart.Configuration - configuration paramenter "http-host" set to "0.0.0.0"
restheart    |  11:26:44.836 [main] TRACE org.restheart.Configuration - configuration paramenter "ajp-listener" set to "false"
restheart    |  11:26:44.837 [main] TRACE org.restheart.Configuration - configuration paramenter "ajp-port" set to "8009"
restheart    |  11:26:44.837 [main] TRACE org.restheart.Configuration - configuration paramenter "ajp-host" set to "0.0.0.0"
restheart    |  11:26:44.838 [main] TRACE org.restheart.Configuration - configuration paramenter "instance-name" set to "default"
restheart    |  11:26:44.839 [main] TRACE org.restheart.Configuration - configuration parameter proxies not specified in the configuration file, using its default value []
restheart    |  11:26:44.839 [main] TRACE org.restheart.Configuration - configuration parameter static-resources-mounts not specified in the configuration file, using its default value []
restheart    |  11:26:44.839 [main] TRACE org.restheart.Configuration - configuration paramenter "plugins-directory" set to "plugins"
restheart    |  11:26:44.843 [main] TRACE org.restheart.Configuration - configuration paramenter "log-file-path" set to "restheart.log"
restheart    |  11:26:44.848 [main] TRACE org.restheart.Configuration - configuration paramenter "log-level" set to "INFO"
restheart    |  11:26:44.850 [main] TRACE org.restheart.Configuration - configuration paramenter "enable-log-console" set to "true"
restheart    |  11:26:44.851 [main] TRACE org.restheart.Configuration - configuration paramenter "enable-log-file" set to "false"
restheart    |  11:26:44.852 [main] TRACE org.restheart.Configuration - parameter requests-log-trace-headers not specified in the configuration file. Using its default value []
restheart    |  11:26:44.853 [main] TRACE org.restheart.Configuration - configuration paramenter "requests-limit" set to "1000"
restheart    |  11:26:44.856 [main] TRACE org.restheart.Configuration - configuration paramenter "io-threads" set to "4"
restheart    |  11:26:44.857 [main] TRACE org.restheart.Configuration - configuration paramenter "worker-threads" set to "16"
restheart    |  11:26:44.859 [main] TRACE org.restheart.Configuration - configuration paramenter "buffer-size" set to "16384"
restheart    |  11:26:44.860 [main] TRACE org.restheart.Configuration - configuration paramenter "direct-buffers" set to "true"
restheart    |  11:26:44.861 [main] TRACE org.restheart.Configuration - configuration paramenter "force-gzip-encoding" set to "false"
restheart    |  11:26:44.861 [main] TRACE org.restheart.Configuration - configuration paramenter "requests-log-level" set to "1"
restheart    |  11:26:44.862 [main] TRACE org.restheart.Configuration - configuration paramenter "allow-unescaped-characters-in-url" set to "true"
restheart    |  11:26:44.864 [main] INFO  org.restheart - Loglevel was set via logback configuration file with level ALL
restheart    |  11:26:47.421 [main] ERROR org.restheart.plugins.PluginsFactory - Error injecting dependency to Initializer changeStreamActivator: The connection string contains options without trailing slash
restheart    |  java.lang.reflect.InvocationTargetException: null
restheart    |  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
restheart    |  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
restheart    |  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
restheart    |  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
restheart    |  at org.restheart.plugins.PluginsFactory.invokeInjectConfigurationMethods(PluginsFactory.java:374)
restheart    |  at org.restheart.plugins.PluginsFactory.invokeCoreInjectMethods(PluginsFactory.java:337)
restheart    |  at org.restheart.plugins.PluginsFactory.injectCoreDependencies(PluginsFactory.java:294)
restheart    |  at org.restheart.plugins.PluginsRegistryImpl.instantiateAll(PluginsRegistryImpl.java:134)
restheart    |  at org.restheart.Bootstrapper.startServer(Bootstrapper.java:553)
restheart    |  at org.restheart.Bootstrapper.run(Bootstrapper.java:282)
restheart    |  at org.restheart.Bootstrapper.main(Bootstrapper.java:239)
restheart    | Caused by: java.lang.IllegalArgumentException: The connection string contains options without trailing slash
restheart    |  at com.mongodb.ConnectionString.<init>(ConnectionString.java:303)
restheart    |  at com.mongodb.MongoClientURI.<init>(MongoClientURI.java:250)
restheart    |  at com.mongodb.MongoClientURI.<init>(MongoClientURI.java:232)
restheart    |  at org.restheart.mongodb.handlers.changestreams.ChangeStreamsActivator.setConf(ChangeStreamsActivator.java:53)
restheart    |  ... 11 common frames omitted
restheart    | 11:26:47.431 [main] ERROR org.restheart.plugins.PluginsFactory - Error injecting dependency to Initializer mongoInitializer: The connection string contains options without trailing slash
restheart    |  java.lang.reflect.InvocationTargetException: null
restheart    |  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
restheart    |  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
restheart    |  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
restheart    |  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
restheart    |  at org.restheart.plugins.PluginsFactory.invokeInjectConfigurationMethods(PluginsFactory.java:374)
restheart    |  at org.restheart.plugins.PluginsFactory.invokeCoreInjectMethods(PluginsFactory.java:337)
restheart    |  at org.restheart.plugins.PluginsFactory.injectCoreDependencies(PluginsFactory.java:294)
restheart    |  at org.restheart.plugins.PluginsRegistryImpl.instantiateAll(PluginsRegistryImpl.java:134)
restheart    |  at org.restheart.Bootstrapper.startServer(Bootstrapper.java:553)
restheart    |  at org.restheart.Bootstrapper.run(Bootstrapper.java:282)
restheart    |  at org.restheart.Bootstrapper.main(Bootstrapper.java:239)
restheart    | Caused by: org.restheart.ConfigurationException: wrong parameter mongo-uri
restheart    |  at org.restheart.mongodb.MongoServiceConfiguration.<init>(MongoServiceConfiguration.java:217)
restheart    |  at org.restheart.mongodb.MongoServiceConfiguration.init(MongoServiceConfiguration.java:107)
restheart    |  at org.restheart.mongodb.MongoServiceConfiguration.init(MongoServiceConfiguration.java:103)
restheart    |  at org.restheart.mongodb.MongoServiceInitializer.init(MongoServiceInitializer.java:48)
restheart    |  ... 11 common frames omitted
restheart    | Caused by: java.lang.IllegalArgumentException: The connection string contains options without trailing slash
restheart    |  at com.mongodb.ConnectionString.<init>(ConnectionString.java:303)
restheart    |  at com.mongodb.MongoClientURI.<init>(MongoClientURI.java:250)
restheart    |  at com.mongodb.MongoClientURI.<init>(MongoClientURI.java:232)
restheart    |  at org.restheart.mongodb.MongoServiceConfiguration.<init>(MongoServiceConfiguration.java:215)
restheart    |  ... 14 common frames omitted
restheart    | 11:26:47.468 [main] ERROR org.restheart.plugins.PluginsFactory - Error injecting dependency to Service mongo: Cannot invoke "org.restheart.mongodb.MongoServiceConfiguration.getPluginsArgs()" because the return value of "org.restheart.mongodb.MongoServiceConfiguration.get()" is null
restheart    |  java.lang.reflect.InvocationTargetException: null
restheart    |  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
restheart    |  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
restheart    |  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
restheart    |  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
restheart    |  at org.restheart.plugins.PluginsFactory.invokeInjectPluginsRegistryMethods(PluginsFactory.java:399)
restheart    |  at org.restheart.plugins.PluginsFactory.invokeCoreInjectMethods(PluginsFactory.java:339)
restheart    |  at org.restheart.plugins.PluginsFactory.injectCoreDependencies(PluginsFactory.java:294)
restheart    |  at org.restheart.plugins.PluginsRegistryImpl.instantiateAll(PluginsRegistryImpl.java:134)
restheart    |  at org.restheart.Bootstrapper.startServer(Bootstrapper.java:553)
restheart    |  at org.restheart.Bootstrapper.run(Bootstrapper.java:282)
restheart    |  at org.restheart.Bootstrapper.main(Bootstrapper.java:239)
restheart    | Caused by: java.lang.NullPointerException: Cannot invoke "org.restheart.mongodb.MongoServiceConfiguration.getPluginsArgs()" because the return value of "org.restheart.mongodb.MongoServiceConfiguration.get()" is null
restheart    |  at org.restheart.mongodb.MongoService.myURI(MongoService.java:256)
restheart    |  at org.restheart.mongodb.MongoService.init(MongoService.java:89)
restheart    |  ... 11 common frames omitted
restheart    | 11:26:47.942 [main] ERROR org.restheart.Bootstrapper - Linkage error executing initializer changeStreamActivator Check that it was compiled against restheart-commons v6.0.2
restheart    |  java.lang.ExceptionInInitializerError: null
restheart    |  at org.restheart.mongodb.db.MongoClientSingleton.getInstance(MongoClientSingleton.java:76)
restheart    |  at org.restheart.mongodb.handlers.changestreams.ChangeStreamsActivator.init(ChangeStreamsActivator.java:58)
restheart    |  at org.restheart.Bootstrapper.lambda$startServer$3(Bootstrapper.java:651)
restheart    |  at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(Unknown Source)
restheart    |  at java.base/java.util.stream.ReferencePipeline$2$1.accept(Unknown Source)
restheart    |  at java.base/java.util.Iterator.forEachRemaining(Unknown Source)
restheart    |  at java.base/java.util.Spliterators$IteratorSpliterator.forEachRemaining(Unknown Source)
restheart    |  at java.base/java.util.stream.AbstractPipeline.copyInto(Unknown Source)
restheart    |  at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(Unknown Source)
restheart    |  at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(Unknown Source)
restheart    |  at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(Unknown Source)
restheart    |  at java.base/java.util.stream.AbstractPipeline.evaluate(Unknown Source)
restheart    |  at java.base/java.util.stream.ReferencePipeline.forEach(Unknown Source)
restheart    |  at org.restheart.Bootstrapper.startServer(Bootstrapper.java:649)
restheart    |  at org.restheart.Bootstrapper.run(Bootstrapper.java:282)
restheart    |  at org.restheart.Bootstrapper.main(Bootstrapper.java:239)
restheart    | Caused by: java.lang.IllegalStateException: not initialized
restheart    |  at org.restheart.mongodb.db.MongoClientSingleton.<init>(MongoClientSingleton.java:97)
restheart    |  at org.restheart.mongodb.db.MongoClientSingleton$MongoClientSingletonHolder.<clinit>(MongoClientSingleton.java:192)
restheart    |  ... 16 common frames omitted
restheart    | 11:26:47.943 [main] ERROR org.restheart.Bootstrapper - Error executing initializer txnsActivator An external dependency is missing. Copy the missing dependency jar to the plugins directory to add it to the classpath
restheart    |  java.lang.NoClassDefFoundError: Could not initialize class org.restheart.mongodb.db.MongoClientSingleton$MongoClientSingletonHolder
restheart    |  at org.restheart.mongodb.db.MongoClientSingleton.getInstance(MongoClientSingleton.java:76)
restheart    |  at org.restheart.mongodb.handlers.sessions.TxnsActivator.init(TxnsActivator.java:47)
restheart    |  at org.restheart.Bootstrapper.lambda$startServer$3(Bootstrapper.java:651)
restheart    |  at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(Unknown Source)
restheart    |  at java.base/java.util.stream.ReferencePipeline$2$1.accept(Unknown Source)
restheart    |  at java.base/java.util.Iterator.forEachRemaining(Unknown Source)
restheart    |  at java.base/java.util.Spliterators$IteratorSpliterator.forEachRemaining(Unknown Source)
restheart    |  at java.base/java.util.stream.AbstractPipeline.copyInto(Unknown Source)
restheart    |  at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(Unknown Source)
restheart    |  at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(Unknown Source)
restheart    |  at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(Unknown Source)
restheart    |  at java.base/java.util.stream.AbstractPipeline.evaluate(Unknown Source)
restheart    |  at java.base/java.util.stream.ReferencePipeline.forEach(Unknown Source)
restheart    |  at org.restheart.Bootstrapper.startServer(Bootstrapper.java:649)
restheart    |  at org.restheart.Bootstrapper.run(Bootstrapper.java:282)
restheart    |  at org.restheart.Bootstrapper.main(Bootstrapper.java:239)
mcardia commented 3 years ago

@mcardia as a quicker check, please set the image to the exact version instead of latest

image: softinstigate/restheart:6.0.2

I suspect an issue with the publishing of the latest tag during our build process.

Hi!

Same error in this try.

Thank you

mcardia commented 3 years ago

As a second check, please verify that the latest and 6.0.2 tags has the same IMAGE ID, like in my case:

➜  ~ docker images
REPOSITORY                       TAG               IMAGE ID       CREATED        SIZE
softinstigate/restheart          6.0.2             15e46d558fef   30 hours ago   291MB
softinstigate/restheart          latest            15e46d558fef   30 hours ago   291MB

If not, re-pull both images and verify again.

Hi! It is the same ID

softinstigate/restheart                 6.0.2           15e46d558fef   2 days ago      291MB
softinstigate/restheart                 latest          15e46d558fef   2 days ago      291MB
mcardia commented 3 years ago

@mcardia as a quicker check, please set the image to the exact version instead of latest image: softinstigate/restheart:6.0.2 I suspect an issue with the publishing of the latest tag during our build process.

Hi!

Same error in this try.

Thank you

I've also tried with 6.0.2-graalvm. Same error.

Then, I tried with 6.0.0-graalvm that was working ok. But now I get the same error. The only difference is that the host was Amazon Linux and now is Ubuntu... odd.

mcardia commented 3 years ago

Found the problem!!!

It was a question mark (?) in my mongodb password. I'v encoded with %3F and it worked.

Thank you all!

ujibang commented 3 years ago

good you have found the problem,

we will investigate to check why the error message is so misleading...

ujibang commented 3 years ago

well,

actually the very first error log message is

ERROR org.restheart.plugins.PluginsFactory - Error injecting dependency to Initializer changeStreamActivator: The connection string contains options without trailing slash

so I guess is not that misleading ;)