graal icon indicating copy to clipboard operation
graal copied to clipboard

crash native-image with eclipse paho

Open Reitz86 opened this issue 5 years ago • 6 comments

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:


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.<init>(MqttClient.java:224)
        at org.eclipse.paho.client.mqttv3.MqttClient.<init>(MqttClient.java:136)
        at micronaut.Mqtt.<init>(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.<clinit>(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```

Reitz86 avatar Jun 15 '19 13:06 Reitz86

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

thomaswue avatar Jun 15 '19 14:06 thomaswue

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

SergejIsbrecht avatar Jun 15 '19 17:06 SergejIsbrecht

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.

Reitz86 avatar Jun 15 '19 23:06 Reitz86

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.

thomaswue avatar Jun 16 '19 08:06 thomaswue

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.

miasma avatar Jul 01 '20 22:07 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 [native-image] Failed to build the native image when using java.prefs.Preferences #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.

colud you send a complete configuration? I tried to follow this configuration but it didn't work

toohandsome avatar Sep 06 '22 07:09 toohandsome

I'm also running into this issue. No amount of config changes has worked for me. Running the agent failed as well because the configuration it generated was basically empty.

timmattison avatar Sep 29 '22 22:09 timmattison

I'm also running into this issue. No amount of config changes has worked for me. Running the agent failed as well because the configuration it generated was basically empty.

https://github.com/toohandsome/xiaomi2meidi/blob/main/src/main/resources/META-INF/native-image/com.yxd/xiaomi2meidi/native-image.properties

https://github.com/toohandsome/xiaomi2meidi/blob/main/src/main/resources/META-INF/native-image/com.yxd/xiaomi2meidi/reflect-config.json

It works for me

toohandsome avatar Sep 30 '22 09:09 toohandsome