Unable to launch Thorntail app du to jolokia and logging subsystem

[dcdh]

Description

By reenabling Jolokia (#1217) my thorntail application can't be launched du to an issue between the logger used by Jolokia and Thorntail.

exec java -Dswarm.http.port=8080 -Deventstore.username=devuser -Deventstore.password=devpassword -Deventstore.database=eventstoredb -Deventstore.remote-host=eventstore-database.developer.svc -Deventstore.remote-port=27017 -javaagent:/opt/agent-bond/agent-bond.jar=jolokia{{host=0.0.0.0}},jmx_exporter{{9779:/opt/agent-bond/jmx_exporter_config.yml}} -agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=5005 -XX:+UseParallelGC -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 -XX:MinHeapFreeRatio=20 -XX:MaxHeapFreeRatio=40 -XX:+ExitOnOutOfMemoryError -cp . -jar /deployments/noteapp-write-thorntail.jarI> No access restrictor found, access to any MBean is allowed
Jolokia: Agent started with URL http://172.17.0.4:8778/jolokia/
...
Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: WFLYLOG0078: The logging subsystem requires the log manager to be org.jboss.logmanager.LogManager. The subsystem has not be initialized and cannot be used. To use JBoss Log Manager you must add the system property "java.util.logging.manager" and set it to "org.jboss.logmanager.LogManager"

Info

• f-m-p version : 3.5.41
• Maven version (mvn -v) :Apache Maven 3.5.2

• Kubernetes / OpenShift setup and version : 3.9.0
• If it's a bug, how to reproduce : mvn clean fabric8:deploy
• If it's a feature request, what is your use case :
• Sample project : [GitHub Clone URL]

[rohanKanojia]

@dcdh : Looks like a bug to me. Could you please provide us sample pom so that we can reproduce this issue?

[dcdh]

You will find a sample in this repository : https://github.com/dcdh/thorntail-helloworld.git

You need to have an openshift running with a developer namespace having developer defined as password (if using the openshift-run-developer.sh script provided).

[dcdh]

I guess that this bug impact wildfly swarm too.

However regarding Thorntail, you will need to update:
https://github.com/fabric8io/fabric8-maven-plugin/blob/master/generator/thorntail-v2/src/main/java/io/fabric8/maven/generator/thorntail/v2/ThorntailV2Generator.java

By adding this :

    ret.put("AB_OFF", "true");
    ret.put("AB_JOLOKIA_OFF", "true");

This code correspond to what was defined before for the wildfly swarm genertor and the objective is to disable Jolokia started in the docker image. (Remark: I don't know what AB_OFF should disable)

I guess that a test with wildfly swarm should be done to ensure that their is no regression. Impacted generator can be found here: https://github.com/fabric8io/fabric8-maven-plugin/blob/master/generator/wildfly-swarm/src/main/java/io/fabric8/maven/generator/wildflyswarm/WildFlySwarmGenerator.java

Many thanks by advance.
Regards, Damien

[rhuss]

Actually the issue with Jolokia and Wildfly Swarm has been fixed in Jolokia 1.3.6 so these lines shouldn't be necessary anymore (and that was the reason why it has been removed).

I will investigate your sample project soonish (this week, just back from PTO).

[rhuss]

@dcdh Unfortunately I can't reproduce the issue. When running your sample on minishift 1.23.0 with mvn -Popenshift fabric8:deploy the pod starts up properly (but seems to have ab other issue)

Log

exec java -javaagent:/opt/agent-bond/agent-bond.jar=jolokia{{host=0.0.0.0}},jmx_exporter{{9779:/opt/agent-bond/jmx_exporter_config.yml}} -XX:+UseParallelGC -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 -XX:MinHeapFreeRatio=20 -XX:MaxHeapFreeRatio=40 -XX:+ExitOnOutOfMemoryError -cp . -jar /deployments/demo-thorntail.jar
I> No access restrictor found, access to any MBean is allowed
Jolokia: Agent started with URL http://172.17.0.8:8778/jolokia/
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:     MicroProfile OpenAPI - STABLE          io.thorntail:microprofile-openapi:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:                  Elytron - STABLE          io.thorntail:elytron:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:                      CDI - STABLE          io.thorntail:cdi:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:          Bean Validation - STABLE          io.thorntail:bean-validation:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:      MicroProfile Config - STABLE          io.thorntail:microprofile-config:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:                  Logging - STABLE          io.thorntail:logging:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:        CDI Configuration - STABLE          io.thorntail:cdi-config:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:                 Undertow - STABLE          io.thorntail:undertow:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:                   JAX-RS - STABLE          io.thorntail:jaxrs:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.wildfly.swarm.container.runtime.ServerBootstrapImpl logFraction
INFO: WFSWARM0013: Installed fraction:             Transactions - STABLE          io.thorntail:transactions:2.1.0.Final
Sep 04, 2018 1:48:08 PM org.jboss.weld.bootstrap.WeldStartup <clinit>
INFO: WELD-000900: 2.4.3 (Final)
Sep 04, 2018 1:48:08 PM org.jboss.weld.util.ServiceLoader loadClass
WARNING: Could not load service class org.wildfly.swarm.cdi.config.deployment.InjectConfigViewExtension
Sep 04, 2018 1:48:08 PM org.jboss.weld.environment.deployment.discovery.DiscoveryStrategyFactory create
INFO: WELD-ENV-000020: Using jandex for bean discovery
Sep 04, 2018 1:48:11 PM org.jboss.weld.bootstrap.WeldStartup startContainer
INFO: WELD-000101: Transactional services not available. Injection of @Inject UserTransaction not available. Transactional observers will be invoked synchronously.
Sep 04, 2018 1:48:14 PM org.jboss.weld.interceptor.reader.InterceptorMetadataUtils isValidTargetClassLifecycleInterceptorMethod
WARN: WELD-001471: Interceptor method postConstruct defined on class org.wildfly.swarm.container.runtime.wildfly.ShrinkWrapFileSystem is not defined according to the specification. It should not throw java.io.IOException, which is a checked exception.
	at org.wildfly.swarm.container.runtime.wildfly.ShrinkWrapFileSystem.postConstruct(ShrinkWrapFileSystem.java:0)
  StackTrace
Sep 04, 2018 1:48:15 PM org.jboss.weld.interceptor.reader.InterceptorMetadataUtils isValidTargetClassLifecycleInterceptorMethod
WARN: WELD-001471: Interceptor method setupFactories defined on class org.wildfly.swarm.container.runtime.xmlconfig.StandaloneXMLParserProducer is not defined according to the specification. It should not throw java.lang.Exception, which is a checked exception.
	at org.wildfly.swarm.container.runtime.xmlconfig.StandaloneXMLParserProducer.setupFactories(StandaloneXMLParserProducer.java:0)
  StackTrace
Sep 04, 2018 1:48:15 PM org.jboss.weld.environment.se.WeldContainer fireContainerInitializedEvent
INFO: WELD-ENV-002003: Weld SE container internal initialized
Sep 04, 2018 1:48:20 PM org.jboss.msc.service.ServiceContainerImpl <clinit>

The import part is Jolokia: Agent started with URL http://172.17.0.8:8778/jolokia/ which indicates that Jolokia could be started.

Any idea how I could reproduce the error ?

[dcdh]

I have just try again with this following steps:

1/ git clone https://github.com/dcdh/thorntail-helloworld.git
2/ mvn clean fabric8:deploy -Popenshift OR ./openshift-run-developer.sh

Unfortunately the deployment keep failing.

I am using OpenShift Origin 3.9.0.

Here you will find my log.

helloworld-1-27hg2.log

And a screenshot

Regards,

Damien

[rhuss]

Thanks, I could reproduce it now.

It looks like that Thorntail again has changed how the logging system is initialized so that the fix in Jolokia 1.3.6 which was added specifically for the strange way how JBoss handles logging was introduced.

As background info, it all boils down that the JBoss logging subsystem needs to be initialized before java.util.logging has been used the first time, but Jolokia as a Java agent starts very early. Jolokia itself doesnt use java.util.logging but it used classes (the java http server) which in turn uses these classes.

So its in issue for Jolokia and Thorntail to fix this, so we would need another release from either Thorntail or Jolokia.

In the meantime I again recommend to switch off Jolokia in the Thorntail generator as mentioned above.

[dcdh]

It is possible to configure the activitation of Jolokia using the configuration ?

For example it is possible to setup options in the Java Exec generator (https://maven.fabric8.io/#generator-java-exec)
It is done in this java class https://github.com/fabric8io/fabric8-maven-plugin/blob/master/generator/java-exec/src/main/java/io/fabric8/maven/generator/javaexec/JavaExecGenerator.java using a Config enum constant and the magic is done in the customize method.

I guess it would be a good way to add the possibility to specify if we want to enable or not Jolokia in https://github.com/fabric8io/fabric8-maven-plugin/blob/master/generator/thorntail-v2/src/main/java/io/fabric8/maven/generator/thorntail/v2/ThorntailV2Generator.java by using the same kind of configuration.

[rhuss]

You can easily add the environment variables on your own to the deployment config --> https://github.com/rhuss/fabric8-maven-plugin/blob/a7ea12022b03b4730b8111dcd4bdaac525ba9216/samples/thorntail/pom.xml#L78-L83

I added a PR #1371 to add your sample to the fmp sample. I hope this ok ;)

It starts up now, but I can't still reach the endpoint via the service (i added a type NodePort to test in on minikube). Not sure what is going on here.

[stale]

This issue has been automatically marked as stale because it has not had any activity since 90 days. It will be closed if no further activity occurs within 7 days. Thank you for your contributions!