Graal: Native Image: Classpath scan issues

[panga]

I'm trying to build a native image for a Java microservice project that uses CDI.
I'm struggling in an weird error even with -H:+ReportUnsupportedElementsAtRuntime set.
The stacktrace doesn't help me to identify what's happening.

Error: Detected a ZipFile object in the image heap. This is not supported. The object was reached from a static initializer. All static class initialization is done during native image construction, thus a static initializer cannot contain code that captures state dependent on the build machine. Write your own initialization methods and call them explicitly from your main entry point.
Trace:  object java.util.HashMap$Node
    object java.util.HashMap$Node[]
    object java.util.HashMap
    method sun.net.www.protocol.jar.JarFileFactory.get(URL, boolean)
Call path from entry point to sun.net.www.protocol.jar.JarFileFactory.get(URL, boolean): 
    at sun.net.www.protocol.jar.JarFileFactory.get(JarFileFactory.java:79)
    at sun.net.www.protocol.jar.JarURLConnection.connect(JarURLConnection.java:122)
    at sun.net.www.protocol.jar.JarURLConnection.getInputStream(JarURLConnection.java:152)
    at java.net.URL.openStream(URL.java:1045)
    at java.util.ServiceLoader.parse(ServiceLoader.java:304)
    at java.util.ServiceLoader.access$200(ServiceLoader.java:185)
    at java.util.ServiceLoader$LazyIterator.hasNextService(ServiceLoader.java:357)
    at java.util.ServiceLoader$LazyIterator.nextService(ServiceLoader.java:364)
    at java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:404)
    at java.util.ServiceLoader$1.next(ServiceLoader.java:480)
    at ws.ament.hammock.Bootstrap.main(Bootstrap.java:40)
    at com.oracle.svm.reflect.proxies.Proxy_1_Bootstrap_main.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.oracle.svm.core.JavaMainWrapper.run(JavaMainWrapper.java:173)
    at com.oracle.svm.core.code.CEntryPointCallStubs.com_002eoracle_002esvm_002ecore_002eJavaMainWrapper_002erun_0028int_002corg_002egraalvm_002enativeimage_002ec_002etype_002eCCharPointerPointer_0029(generated:0)

This error happens with two CDI implementations: Weld and OpenWebBeans.

Weld verbose log.
OpenWebBeans verbose log.

The source code and instructions are available at:

https://github.com/panga/hammock-graal.git

BTW I see an annoying pattern adding Service Provider classes contructor into ReflectionConfigurationFiles (e.g: https://github.com/panga/hammock-graal/blob/master/reflection-owb.json) why it's not automatically detected by SubstrateVM ?

Example: ServiceLoader.load(Bootstrapper.class) SubstrateVM detects the classes but fails when try to instantiate them.

[cstancu]

The problem is that JarFileFactory caches JarFile objects into its private static final HashMap<String, JarFile> fileCache = new HashMap<>() and private static final HashMap<JarFile, URL> urlCache = new HashMap<>() fields during image building and, as the Error: part of the error message describes, this is not supported. This most likely happens because sun.net.www.protocol.jar.JarFileFactory.get(URL, boolean) is called from a static initializer. I agree that the error message could be improved.

[cstancu]

Regarding the reflection configuration files we are working on automating the discovery of classes/methods/fields that need reflective access. In the meantime ReflectionConfigurationFiles is the only solution.

[panga]

@cstancu, thanks for quick answer.

If you look at my code it's a very simple callServiceLoader.load(clazz).next().
I didn't call JarFileFactory that's a Java core call during ServiceLoader.parse().

Do you mean that SubstrateVM doesn't support META-INF/services for loading service classes?

Specifically about ServiceLoader.load() reflective access, maybe you can substitute this method in SubstrateVM so we don't need to add those reflection configurations for each service class.

[panga]

I'm trying in a uber (shaded) jar now, got a slightly different stacktrace, but same error.

$GRAALVM_HOME/bin/native-image -H:+ReportUnsupportedElementsAtRuntime -H:ReflectionConfigurationFiles=reflection.json -jar target/hammock-graal-uber.jar

Error: Detected a ZipFile object in the image heap. This is not supported. The object was reached from a static initializer. All static class initialization is done during native image construction, thus a static initializer cannot contain code that captures state dependent on the build machine. Write your own initialization methods and call them explicitly from your main entry point.
Trace:  object java.util.HashMap$Node
    object java.util.HashMap$Node[]
    object java.util.HashMap
    method sun.net.www.protocol.jar.JarFileFactory.get(URL, boolean)
Call path from entry point to sun.net.www.protocol.jar.JarFileFactory.get(URL, boolean): 
    at sun.net.www.protocol.jar.JarFileFactory.get(JarFileFactory.java:79)
    at sun.net.www.protocol.jar.JarURLConnection.connect(JarURLConnection.java:122)
    at sun.net.www.protocol.jar.JarURLConnection.getInputStream(JarURLConnection.java:152)
    at java.net.URL.openStream(URL.java:1045)
    at com.sun.naming.internal.VersionHelper12$InputStreamEnumeration$1.run(VersionHelper12.java:228)
    at com.sun.naming.internal.VersionHelper12$InputStreamEnumeration$1.run(VersionHelper12.java:224)
    at com.oracle.svm.core.jdk.Target_java_security_AccessController.doPrivileged(SecuritySubstitutions.java:70)
    at javax.xml.parsers.FactoryFinder.findServiceProvider(FactoryFinder.java:289)
    at com.oracle.svm.reflect.proxies.Proxy_7_FactoryFinder_findServiceProvider.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.oracle.svm.core.JavaMainWrapper.run(JavaMainWrapper.java:173)
    at com.oracle.svm.core.code.CEntryPointCallStubs.com_002eoracle_002esvm_002ecore_002eJavaMainWrapper_002erun_0028int_002corg_002egraalvm_002enativeimage_002ec_002etype_002eCCharPointerPointer_0029(generated:0)

[cstancu]

That's correct, SubstrateVM doesn't currently have a general solution for loading service classes via META-INF/services. We will work on it as soon as we have support for dynamic class loading which is under development. (To be clear, dynamic class loading in the context of SubstrateVM is not "true" dynamic class loading: only classes available during image building will be available for dynamic loading.)
And it should also be possible to automatically register for reflective instantiation the service classes loaded via ServiceLoader.load().

Even if you didn't call JarFileFactory directly that code is still reachable. In general the way to fix this kind of issues is to try and move the static initializer code to a runtime method, however in this case that wouldn't be so easy since it is a JDK class. We are looking into pushing some static initializers execution to runtime to avoid this kind of issues where objects like ZipFile are cached in a static field and would end up in the image heap. For ServiceLoader that might not even be an issue in the end since we will probably parse the configuration and load the classes eagerly at image build time and all the offending code will become unreachable.

[panga]

@cstancu that works for me, I only expect to load services available at build time.

Please contact me once you have something, so I can test and give some feedback.

Thanks!

[cstancu]

We added class loader support. Please see https://github.com/oracle/graal/issues/470#issuecomment-401022008 for details. I also created a simple demo project for loading services with ServiceLoader at
https://github.com/cstancu/native-image-service-loader-demo.

[panga]

Thanks @cstancu !

This change will be out in next release?

[cstancu]

@panga yes, the ClassLoader changes should make it in the next release.

[panga]

@cstancu I tried RC3 without success. The same error ZipFile object happens because of a static initializer in sun.net.www.protocol.jar.JarFileFactory class from JDK.

For some reason, my demo app reaches some different code.
https://github.com/panga/hammock-graal.git

My last findings are that some of those JDK classes are being called and trigger ServiceLoader#load causing the issue.

[panga]

Update:

1. Found the cause of Error: Detected a ZipFile object in the image heap:
   If Log4j configuration is present (log4j2.xml or log4j2.properties) in my project, it causes a native-image compilation issue. Not sure why it happens, probably due some static initialization.
   My current workaround is to remove such configuration and disable logging for now.

2. beans.xml content isn't being read in native image due #513.

3. Now my issue is on the application side, CDI doesn't initialize properly.

• How I can debug a native image?
• There's any way to attach a Java debugger?

[olpaw]

There's any way to attach a Java debugger?

Nope. Java debugging is based on deopting to the interpreter. For SubstrateVM images this is not possible.

How I can debug a native image?

The Enterprise Edition (EE) has dwarf debug info generation (http://www.graalvm.org/downloads). If you build your image with the EE of native-image and use option -g (best combined with -O0) you will be able to debug the image with GDB (you need to build yourself a GDB 7.11.1 with Python 3.5.x). When you run your image in the debugger it will try to load a python file that is needed for proper debugging support (svmhelpers.py, that file is also part of EE). You need to copy that file to the current working directory so that GDB can load it when requested.

[panga]

I'll have to get familiar with GDB.

Thanks @olpaw

[panga]

@olpaw I had some fun with GDB which helped me to fix some issues and find others.
However, I need to use local builds from master branch (mx native-image).
Any chance to allow generating debug symbols from Graal CE ?

[olpaw]

We have currently no immediate plans, but we are discussing the option internally. @shelajev might be able to tell you more.

[panga]

Well, I'm basically stuck on the issue described at beginning.

I can't use native-image with libraries that are using log4j because they add loggers as static variables (very common) and try to load log4j2.xml|properties during image generation and raising an error.

If you want I can provide a very simple app with a main method with log.info("something)" and a log4j2.xml so you can see the error.

Second, but no less important, all service providers declared in META-INF/services resources need to be added in reflection configuration manually! such a pain that need work better.

[olpaw]

If you want I can provide a very simple app with a main method with log.info("something)" and a log4j2.xml so you can see the error.

@panga that would be nice. I can use that as a starting point for a log4j support feature.

[panga]

@olpaw the sample and instructions are available here: https://github.com/panga/graal-issues

[olpaw]

@panga thanks! I will have a look next week.

[cstancu]

@panga I created an issue for automatic registration for reflection of META-INF/services resources. Please see https://github.com/oracle/graal/issues/563.

[olpaw]

@panga I have a fix for https://github.com/panga/graal-issues
We were missing FieldValue recomputations on

sun.net.www.protocol.jar.JarFileFactory.fileCache
sun.net.www.protocol.jar.JarFileFactory.urlCache
sun.net.www.protocol.jar.JarFileFactory.instance

With my changes your sample works fine as native image.

The PR should make it to master today

[olpaw]

Fixed in d2989fa4986

[panga]

@olpaw ZipFile fix worked for me. Thank you!