Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AWT dynamic shared libraries loading seems broken #6244

Closed
Karm opened this issue Mar 20, 2023 · 2 comments
Closed

AWT dynamic shared libraries loading seems broken #6244

Karm opened this issue Mar 20, 2023 · 2 comments

Comments

@Karm
Copy link
Contributor

Karm commented Mar 20, 2023

With this tiny reproducer app:

import javax.imageio.ImageIO;
import java.awt.Color;
import java.awt.FontFormatException;
import java.awt.Graphics2D;
import java.awt.image.BufferedImage;
import java.io.File;
import java.io.IOException;

public class Main {
    public static void main(String[] args) throws IOException, FontFormatException {
        final BufferedImage i = new BufferedImage(320, 200, BufferedImage.TYPE_4BYTE_ABGR);
        final Graphics2D g = (Graphics2D) i.getGraphics();
        g.setColor(Color.BLACK);
        g.fillRect(0, 0, 320, 200);
        g.setColor(Color.RED);
        g.fillOval(0, 0, 320, 200);
        g.dispose();
        ImageIO.write(i, "PNG", new File("image.png"));
    }
}

I am unable to make it work at runtime with neither GraalVM CE nor Mandrel, although with slightly different error reports.
GraalVM CE seems to fail at attempting to init the lib while Mandrel fails at dlopen (although the file is really there and it seems found and loaded by the native dl).

Steps to reproduce

$ export JAVA_HOME=/home/karm/X/JDKs/graalvm-ce-java17-23.0.0-dev/;export GRAALVM_HOME=${JAVA_HOME};export PATH=${JAVA_HOME}/bin:${PATH}
$ native-image --version
GraalVM 23.0.0-dev Java 17.0.7+4-jvmci-23.0-b09 CE (Java Version 17.0.7+4-jvmci-23.0-b09)
$ javac Main.java
$ java -agentlib:native-image-agent=config-output-dir=native-image Main
$ native-image --no-fallback Main
...
Produced artifacts:
 /home/karm/workspaceRH/dev-null/awt-circle/libawt.so (jdk_library)
 /home/karm/workspaceRH/dev-null/awt-circle/libawt_headless.so (jdk_library)
 /home/karm/workspaceRH/dev-null/awt-circle/libawt_xawt.so (jdk_library)
 /home/karm/workspaceRH/dev-null/awt-circle/libfontmanager.so (jdk_library)
 /home/karm/workspaceRH/dev-null/awt-circle/libjava.so (jdk_library_shim)
 /home/karm/workspaceRH/dev-null/awt-circle/libjavajpeg.so (jdk_library)
 /home/karm/workspaceRH/dev-null/awt-circle/libjvm.so (jdk_library_shim)
 /home/karm/workspaceRH/dev-null/awt-circle/liblcms.so (jdk_library)
 /home/karm/workspaceRH/dev-null/awt-circle/main (executable)
==============================================================================================
Finished generating 'main' in 55.6s.
...
$ LD_DEBUG=all ./main 2>&1 | tee graalvm.log

(or native-image --no-fallback -g -O0 -H:+TrackNodeSourcePosition Main to use gdb...)

GraalVM

See the full log: graalvm.log [1.6M]

Seems fine:

 2698     136835: file=/home/karm/workspaceRH/dev-null/awt-circle/libawt.so [0];  dynamically loaded by ./main [0]
 2699     136835: file=/home/karm/workspaceRH/dev-null/awt-circle/libawt.so [0];  generating link map
 2700     136835:   dynamic: 0x00007f3c7da9e2f8  base: 0x00007f3c7d9dd000   size: 0x00000000000f2168
 2701     136835:     entry: 0x00007f3c7d9dd000  phdr: 0x00007f3c7d9dd040  phnum:                  7

but it crashes

16285 Stacktrace for the failing thread 0x0000000001e31300:
16286   SP 0x00007ffec712fd50 IP 0x000000000043fa68  [image code] com.oracle.svm.core.code.IsolateEnterStub.JNIFunctions_FatalError_5ea28336426fe0a26a33d6b62307157f39a34d1c(IsolateEnterStub.java:0)
16287   SP 0x00007ffec7130e20 IP 0x0000000000498ae4  [image code] com.oracle.svm.core.jni.JNIOnLoadFunctionPointer.invoke(JNILibraryInitializer.java)
16288   SP 0x00007ffec7130e20 IP 0x0000000000498ae4  [image code] com.oracle.svm.core.jni.JNILibraryInitializer.callOnLoadFunction(JNILibraryInitializer.java:71)
16289   SP 0x00007ffec7130e60 IP 0x00000000004995ac  [image code] com.oracle.svm.core.jni.JNILibraryInitializer.initialize(JNILibraryInitializer.java:132)
16290   SP 0x00007ffec7130e80 IP 0x0000000000485b0a  [image code] com.oracle.svm.core.jdk.NativeLibrarySupport.addLibrary(NativeLibrarySupport.java:204)
16291   SP 0x00007ffec7130ef0 IP 0x00000000004866b3  [image code] com.oracle.svm.core.jdk.NativeLibrarySupport.loadLibrary0(NativeLibrarySupport.java:160)
16292   SP 0x00007ffec7130f10 IP 0x0000000000486b05  [image code] com.oracle.svm.core.jdk.NativeLibrarySupport.loadLibraryRelative(NativeLibrarySupport.java:123)
16293   SP 0x00007ffec7130f60 IP 0x000000000067fdbf  [image code] java.lang.ClassLoader.loadLibrary(ClassLoader.java:50)
16294   SP 0x00007ffec7130f60 IP 0x000000000067fdbf  [image code] java.lang.Runtime.loadLibrary0(Runtime.java:818)
16295   SP 0x00007ffec7130f60 IP 0x000000000067fdbf  [image code] java.lang.System.loadLibrary(System.java:1989)
16296   SP 0x00007ffec7130f60 IP 0x000000000067fdbf  [image code] java.awt.image.ColorModel$1.run(ColorModel.java:210)

Gdb quick poke around:

(gdb) b PosixUtils.java:223
Breakpoint 1 at 0x4b89fd: file com/oracle/svm/core/posix/PosixUtils.java, line 223.
(gdb) run
Thread 1 "main" hit Breakpoint 1, com.oracle.svm.core.posix.PosixUtils::dlopen(java.lang.String*, int) (file=0x7ffff63026f0, mode=1) at com/oracle/svm/core/posix/PosixUtils.java:223
223                 return Dlfcn.dlopen(pathPtr, mode);
...
com.oracle.svm.core.jdk.NativeLibrarySupport::addLibrary(bool, java.lang.String*, bool) (this=<optimized out>, asBuiltin=<optimized out>, canonical=<optimized out>, initialize=<optimized out>)
    at com/oracle/svm/core/jdk/NativeLibrarySupport.java:215
215                 lock.unlock();
(gdb) n
203                     if (initialize && libraryInitializer != null) {
(gdb) n
207                     NativeLibrary top = currentLoadContext.pop();
(gdb) n
204                         libraryInitializer.initialize(lib);
(gdb) n
Fatal error reported via JNI: Could not allocate set properties

Mandrel

Using a home built Mandrel, mandrel-23.0-SNAPSHOT.tar.xz [195M],

native-image 23.0.0-deva81ecbe6def2 Mandrel Distribution (Java Version 17.0.6+10)

made of GraalVM a81ecbe with this diff:

diff --git a/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixNativeLibraryFeature.java b/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixNativeLibraryFeature.java
index 358f4f4b649d..b1e1192df8a0 100644
--- a/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixNativeLibraryFeature.java
+++ b/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixNativeLibraryFeature.java
@@ -185,6 +185,7 @@ final class PosixNativeLibrarySupport extends JNIPlatformNativeLibrarySupport {
             }
             assert dlhandle.isNull();
             dlhandle = PosixUtils.dlopen(canonicalIdentifier, Dlfcn.RTLD_LAZY());
+            System.out.printf("KARM: RTLD_LAZY Status is null: %s of %s.\n", dlhandle.isNull(), canonicalIdentifier);
             return dlhandle.isNonNull();
         }
 
diff --git a/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixUtils.java b/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixUtils.java
index c07d6af2f65a..dfd8bd28465b 100644
--- a/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixUtils.java
+++ b/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixUtils.java
@@ -220,6 +220,7 @@ public class PosixUtils {
     public static PointerBase dlopen(String file, int mode) {
         try (CCharPointerHolder pathPin = CTypeConversion.toCString(file)) {
             CCharPointer pathPtr = pathPin.get();
+            System.out.printf("KARM: Calling Dlfcn.dlopen(%s,...)\n",file );
             return Dlfcn.dlopen(pathPtr, mode);
         }
     }

I get a similar failure with

 LD_DEBUG=all ./main 2>&1 | tee mandrel.log

see full log: mandrel.log [910K]

Although it seems to crash on dlopen returning null pointer as if the library wasn't found while it was clearly found just fine.

Thread 1 "main" hit Breakpoint 1, com.oracle.svm.core.posix.PosixUtils::dlopen(java.lang.String*, int) (file=0x7ffff63026f0, mode=1) at com/oracle/svm/core/posix/PosixUtils.java:223
223                 System.out.printf("KARM: Calling Dlfcn.dlopen(%s,...)\n",file );
(gdb) c
Continuing.
KARM: Calling Dlfcn.dlopen(/home/karm/workspaceRH/dev-null/awt-circle/libawt.so,...)
KARM: RTLD_LAZY Status is null: true of /home/karm/workspaceRH/dev-null/awt-circle/libawt.so.

Thread 1 "main" hit Breakpoint 1, com.oracle.svm.core.posix.PosixUtils::dlopen(java.lang.String*, int) (file=0x7ffff63031a0, mode=1) at com/oracle/svm/core/posix/PosixUtils.java:223
223                 System.out.printf("KARM: Calling Dlfcn.dlopen(%s,...)\n",file );
(gdb) c
Continuing.
KARM: Calling Dlfcn.dlopen(/usr/lib64/libawt.so,...)
KARM: RTLD_LAZY Status is null: true of /usr/lib64/libawt.so.

Thread 1 "main" hit Breakpoint 1, com.oracle.svm.core.posix.PosixUtils::dlopen(java.lang.String*, int) (file=0x7ffff6303ac0, mode=1) at com/oracle/svm/core/posix/PosixUtils.java:223
223                 System.out.printf("KARM: Calling Dlfcn.dlopen(%s,...)\n",file );
(gdb) c
Continuing.
KARM: Calling Dlfcn.dlopen(/usr/lib64/libawt.so,...)
KARM: RTLD_LAZY Status is null: true of /usr/lib64/libawt.so.

Thread 1 "main" hit Breakpoint 1, com.oracle.svm.core.posix.PosixUtils::dlopen(java.lang.String*, int) (file=0x7ffff63043e0, mode=1) at com/oracle/svm/core/posix/PosixUtils.java:223
223                 System.out.printf("KARM: Calling Dlfcn.dlopen(%s,...)\n",file );
(gdb) c
Continuing.
KARM: Calling Dlfcn.dlopen(/usr/lib/libawt.so,...)
KARM: RTLD_LAZY Status is null: true of /usr/lib/libawt.so.

Thread 1 "main" hit Breakpoint 1, com.oracle.svm.core.posix.PosixUtils::dlopen(java.lang.String*, int) (file=0x7ffff6304d40, mode=1) at com/oracle/svm/core/posix/PosixUtils.java:223
223                 System.out.printf("KARM: Calling Dlfcn.dlopen(%s,...)\n",file );
(gdb) c
Continuing.
KARM: Calling Dlfcn.dlopen(/usr/lib/libawt.so,...)
KARM: RTLD_LAZY Status is null: true of /usr/lib/libawt.so.
Exception in thread "main" java.lang.UnsatisfiedLinkError: no awt in java.library.path
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.NativeLibrarySupport.loadLibraryRelative(NativeLibrarySupport.java:136)
        at [email protected]/java.lang.ClassLoader.loadLibrary(ClassLoader.java:50)
        at [email protected]/java.lang.Runtime.loadLibrary0(Runtime.java:818)
        at [email protected]/java.lang.System.loadLibrary(System.java:1989)
        at [email protected]/java.awt.image.ColorModel$1.run(ColorModel.java:210)
        at [email protected]/java.awt.image.ColorModel$1.run(ColorModel.java:208)
        at [email protected]/java.security.AccessController.executePrivileged(AccessController.java:171)
        at [email protected]/java.security.AccessController.doPrivileged(AccessController.java:318)
        at [email protected]/java.awt.image.ColorModel.loadLibraries(ColorModel.java:207)
        at [email protected]/java.awt.image.ColorModel.<clinit>(ColorModel.java:220)
        at [email protected]/java.awt.image.BufferedImage.<clinit>(BufferedImage.java:286)
        at Main.main(Main.java:16)
[Thread 0x7ffff62ff700 (LWP 142912) exited]

Misc

Thx for pointers (pun intended)

K.

FYI: @jerboaa @zakkak

@fniephaus
Copy link
Member

fniephaus commented Mar 20, 2023

When I run your reproducer, I see the following recommendation:

AWT: Use the tracing agent to collect metadata for AWT.

This suggests that even though you generated reachability metadata with the tracing agent, it wasn't picked up.

When I build with:

$ $GRAALVM_HOME/bin/native-image --no-fallback -H:ConfigurationFileDirectories=native-image Main

the binary seems to run fine.

Please feel free to re-open if this doesn't fix the problem on your end

@fniephaus fniephaus self-assigned this Mar 20, 2023
@fniephaus fniephaus added question and removed bug labels Mar 20, 2023
@Karm
Copy link
Contributor Author

Karm commented Mar 20, 2023

@fniephaus Thank you 🙏

It fixed the GraalVM CE run, but it didn't help Mandrel's

Exception in thread "main" java.lang.UnsatisfiedLinkError: no awt in java.library.path
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.NativeLibrarySupport.loadLibraryRelative(NativeLibrarySupport.java:136)
        at [email protected]/java.lang.ClassLoader.loadLibrary(ClassLoader.java:50)
        at [email protected]/java.lang.Runtime.loadLibrary0(Runtime.java:818)
        at [email protected]/java.lang.System.loadLibrary(System.java:1989)
        at [email protected]/java.awt.image.ColorModel$1.run(ColorModel.java:210)
        at [email protected]/java.awt.image.ColorModel$1.run(ColorModel.java:208)
        at [email protected]/java.security.AccessController.executePrivileged(AccessController.java:171)
        at [email protected]/java.security.AccessController.doPrivileged(AccessController.java:318)
        at [email protected]/java.awt.image.ColorModel.loadLibraries(ColorModel.java:207)
        at [email protected]/java.awt.image.ColorModel.<clinit>(ColorModel.java:220)
        at [email protected]/java.awt.image.BufferedImage.<clinit>(BufferedImage.java:286)
        at Main.main(Main.java:16)

(yes, the .so file is there)

We will debug it in Mandrel's GH issues...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants