Graal: crash native-image with eclipse paho

[Reitz86]

Hello,
just started playing around with micronaut, graalvm and native-image. Just tried to use the eclipse paho mqtt client. Works when using regular java -jar but the native image crashes. Pretty sure its just my ignorance of the inner workings of native-image but maybe you could give me a nudge in the right direction.

Error log of the native-image execution:
```13:11:32.698 [pool-5-thread-1] ERROR i.m.s.DefaultTaskExceptionHandler - Error invoking scheduled task Error instantiating bean of type [micronaut.ReadConfigJob]

Path Taken: new ReadConfigJob([Mqtt client])
io.micronaut.context.exceptions.BeanInstantiationException: Error instantiating bean of type [micronaut.ReadConfigJob]

Path Taken: new ReadConfigJob([Mqtt client])
at io.micronaut.context.DefaultBeanContext.doCreateBean(DefaultBeanContext.java:1512)
at io.micronaut.context.DefaultBeanContext.createAndRegisterSingleton(DefaultBeanContext.java:2170)
at io.micronaut.context.DefaultBeanContext.getBeanForDefinition(DefaultBeanContext.java:1856)
at io.micronaut.context.DefaultBeanContext.getBeanInternal(DefaultBeanContext.java:1836)
at io.micronaut.context.DefaultBeanContext.getBean(DefaultBeanContext.java:997)
at io.micronaut.context.AbstractBeanDefinition.getBeanForConstructorArgument(AbstractBeanDefinition.java:982)
at micronaut.$ReadConfigJobDefinition.build(Unknown Source)
at io.micronaut.context.DefaultBeanContext.doCreateBean(DefaultBeanContext.java:1494)
at io.micronaut.context.DefaultBeanContext.createAndRegisterSingleton(DefaultBeanContext.java:2170)
at io.micronaut.context.DefaultBeanContext.getBeanForDefinition(DefaultBeanContext.java:1856)
at io.micronaut.context.DefaultBeanContext.getBeanInternal(DefaultBeanContext.java:1836)
at io.micronaut.context.DefaultBeanContext.getBean(DefaultBeanContext.java:577)
at io.micronaut.scheduling.processor.ScheduledMethodProcessor.lambda$process$5(ScheduledMethodProcessor.java:108)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:473)
at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
Caused by: java.lang.ExceptionInInitializerError: null
at com.oracle.svm.core.hub.ClassInitializationInfo.initialize(ClassInitializationInfo.java:287)
at java.lang.Class.ensureInitialized(DynamicHub.java:437)
at org.eclipse.paho.client.mqttv3.MqttClient.(MqttClient.java:224)
at org.eclipse.paho.client.mqttv3.MqttClient.(MqttClient.java:136)
at micronaut.Mqtt.(Mqtt.java:20)
at micronaut.$MqttDefinition.build(Unknown Source)
at io.micronaut.context.DefaultBeanContext.doCreateBean(DefaultBeanContext.java:1494)
... 21 common frames omitted
Caused by: java.util.MissingResourceException: Error locating the logging class
at org.eclipse.paho.client.mqttv3.logging.LoggerFactory.getLogger(LoggerFactory.java:77)
at org.eclipse.paho.client.mqttv3.MqttAsyncClient.(MqttAsyncClient.java:79)
at com.oracle.svm.core.hub.ClassInitializationInfo.invokeClassInitializer(ClassInitializationInfo.java:347)
at com.oracle.svm.core.hub.ClassInitializationInfo.initialize(ClassInitializationInfo.java:267)
... 27 common frames omitted```

[thomaswue]

Can you ask this in the Micronaut tracker at https://github.com/micronaut-projects/micronaut-core/issues?

[SergejIsbrecht]

It looks like a class has not been registered for reflection:

If you look at the source-code, you will finde something like this:
https://github.com/eclipse/paho.mqtt.java/blob/6d7aafddb3a70d7c1eab69e1f9619af8f7ece47c/org.eclipse.paho.client.mqttv3/src/main/java/org/eclipse/paho/client/mqttv3/logging/LoggerFactory.java

        logger = getLogger(loggerClassName, ResourceBundle.getBundle(messageCatalogName), loggerID, null) ;
//      }

        if (null == logger) {
            throw new MissingResourceException("Error locating the logging class", CLASS_NAME, loggerID);
        }

getLogger

try {
            logClass = Class.forName(loggerClassName);
        } catch (NoClassDefFoundError ncdfe) {
            return null;
        } catch (ClassNotFoundException cnfe) {
            return null;
        }

Kind of looks like the exception will be caught, null returned and the null check later throws a MissingResourceException.

The Problem is, that you do not see, which CLASS_NAME it is.

Best guess would be:

private static final String CLASS_NAME = MqttAsyncClient.class.getName();
private Logger log = LoggerFactory.getLogger(LoggerFactory.MQTT_CLIENT_MSG_CAT, CLASS_NAME);

For further information on reflection please read: https://github.com/oracle/graal/blob/master/substratevm/REFLECTION.md

or use the agent:
https://github.com/oracle/graal/blob/9a580f75cb618ee64eb36d92720b7488cb75dd4d/substratevm/CONFIGURE.md

[Reitz86]

Thanks, I'll look into it.
@thomaswue: since it works using the standard vm, I guess the error is more likely in my code or in combination with the ahead of time compilation. Thanks for helping, though.

[thomaswue]

Can you share a way to reproduce? In case of no wrong configuration of native image, we should indeed at least produce a fallback image.

[miasma]

FWIW, I experimented with Eclipse Paho + Graal just recently. org.eclipse.paho:org.eclipse.paho.client.mqttv3:1.2.4 still required few steps to make it work with Graal:

1. Fixed https://github.com/oracle/graal/issues/2086 by using client-maven-plugin:0.1.27. This linked with the missing native library, which was missing when calling native-image directly from command line.
2. Fixed access to i18n msg strings by adding -H:IncludeResourceBundles=org.eclipse.paho.client.mqttv3.internal.nls.logcat,org.eclipse.paho.client.mqttv3.internal.nls.messages to native-image.properties
3. Set up -H:ReflectionConfigurationResources=reflection-config.json with reflection info for org.eclipse.paho.client.mqttv3.logging.JSR47Logger, org.eclipse.paho.client.mqttv3.internal.MessageCatalog, org.eclipse.paho.client.mqttv3.internal.ResourceBundleCatalog, and java.util.ResourceBundle.
4. Instantiated MqttClient with persistence = null, since the default persistence class couldn't access user home for some reason (null pointer on MqttDefaultFilePersistence line 259).

After these steps at least basic functionality works.