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

ImageIO AWT Quarkus IT test fails with GraalVM 23.0.0-dev build after AWT change #31596

Closed
jerboaa opened this issue Mar 3, 2023 · 28 comments · Fixed by #32432
Closed

ImageIO AWT Quarkus IT test fails with GraalVM 23.0.0-dev build after AWT change #31596

jerboaa opened this issue Mar 3, 2023 · 28 comments · Fixed by #32432
Assignees
Labels
Milestone

Comments

@jerboaa
Copy link
Contributor

jerboaa commented Mar 3, 2023

Describe the bug

The awt integration test io.quarkus.awt.it.ImageDecodersIT.testComplexImages fails like so:

[INFO] Running io.quarkus.awt.it.ImageDecodersIT
Executing "/home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-runner -Dquarkus.http.port=8081 -Dquarkus.http.ssl-port=8444 -Dtest.url=http://localhost:8081 -Dquarkus.log.file.path=/home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus.log -Dquarkus.log.file.enable=true -Dquarkus.native.native-image-xmx=5g"
__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2023-03-03 04:16:16,770 ERROR [io.qua.run.Application] (main) Failed to start application (with profile [prod]): 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 java.base@20-beta/java.lang.ClassLoader.loadLibrary(ClassLoader.java:50)
	at java.base@20-beta/java.lang.Runtime.loadLibrary0(Runtime.java:880)
	at java.base@20-beta/java.lang.System.loadLibrary(System.java:2051)
	at java.desktop@20-beta/java.awt.Toolkit$2.run(Toolkit.java:1384)
	at java.desktop@20-beta/java.awt.Toolkit$2.run(Toolkit.java:1382)
	at java.base@20-beta/java.security.AccessController.executePrivileged(AccessController.java:171)
	at java.base@20-beta/java.security.AccessController.doPrivileged(AccessController.java:319)
	at java.desktop@20-beta/java.awt.Toolkit.loadLibraries(Toolkit.java:1381)
	at java.desktop@20-beta/java.awt.Toolkit.initStatic(Toolkit.java:1419)
	at java.desktop@20-beta/java.awt.Toolkit.<clinit>(Toolkit.java:1393)
	at java.base@20-beta/java.lang.Class.ensureInitialized(DynamicHub.java:550)
	at java.desktop@20-beta/sun.awt.AppContext$2.run(AppContext.java:273)
	at java.desktop@20-beta/sun.awt.AppContext$2.run(AppContext.java:262)
	at java.base@20-beta/java.security.AccessController.executePrivileged(AccessController.java:171)
	at java.base@20-beta/java.security.AccessController.doPrivileged(AccessController.java:319)
	at java.desktop@20-beta/sun.awt.AppContext.initMainAppContext(AppContext.java:262)
	at java.desktop@20-beta/sun.awt.AppContext$3.run(AppContext.java:315)
	at java.desktop@20-beta/sun.awt.AppContext$3.run(AppContext.java:298)
	at java.base@20-beta/java.security.AccessController.executePrivileged(AccessController.java:171)
	at java.base@20-beta/java.security.AccessController.doPrivileged(AccessController.java:319)
	at java.desktop@20-beta/sun.awt.AppContext.getAppContext(AppContext.java:297)
	at java.desktop@20-beta/javax.imageio.spi.IIORegistry.getDefaultInstance(IIORegistry.java:123)
	at io.quarkus.awt.it.Application.init(Application.java:54)
	at io.quarkus.awt.it.Application_Bean.doCreate(Unknown Source)
	at io.quarkus.awt.it.Application_Bean.create(Unknown Source)
	at io.quarkus.awt.it.Application_Bean.create(Unknown Source)
	at io.quarkus.arc.impl.AbstractSharedContext.createInstanceHandle(AbstractSharedContext.java:113)
	at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:37)
	at io.quarkus.arc.impl.AbstractSharedContext$1.get(AbstractSharedContext.java:34)
	at io.quarkus.arc.impl.LazyValue.get(LazyValue.java:26)
	at io.quarkus.arc.impl.ComputingCache.computeIfAbsent(ComputingCache.java:69)
	at io.quarkus.arc.impl.AbstractSharedContext.get(AbstractSharedContext.java:34)
	at io.quarkus.arc.impl.ClientProxies.getApplicationScopedDelegate(ClientProxies.java:21)
	at io.quarkus.awt.it.Application_ClientProxy.arc$delegate(Unknown Source)
	at io.quarkus.awt.it.Application_ClientProxy.arc_contextualInstance(Unknown Source)
	at io.quarkus.awt.it.Application_Observer_Synthetic_c3d8ba8d0ca6557d80114d16f47388b320fb6386.notify(Unknown Source)
	at io.quarkus.arc.impl.EventImpl$Notifier.notifyObservers(EventImpl.java:344)
	at io.quarkus.arc.impl.EventImpl$Notifier.notify(EventImpl.java:326)
	at io.quarkus.arc.impl.EventImpl.fire(EventImpl.java:82)
	at io.quarkus.arc.runtime.ArcRecorder.fireLifecycleEvent(ArcRecorder.java:142)
	at io.quarkus.arc.runtime.ArcRecorder.handleLifecycleEvents(ArcRecorder.java:102)
	at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy_0(Unknown Source)
	at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent1144526294.deploy(Unknown Source)
	at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
	at io.quarkus.runtime.Application.start(Application.java:101)
	at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:111)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:124)
	at io.quarkus.runner.GeneratedMain.main(Unknown Source)

Failed to launch the application. The application logs can be found at: /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus.log
Error:  Tests run: 33, Failures: 0, Errors: 1, Skipped: 32, Time elapsed: 6.176 s <<< FAILURE! - in io.quarkus.awt.it.ImageDecodersIT
Error:  io.quarkus.awt.it.ImageDecodersIT.testComplexImages(String)[1]  Time elapsed: 0.017 s  <<< ERROR!
java.lang.RuntimeException: java.lang.RuntimeException: Unable to successfully launch process '2573'. Exit code is: '1'.
	at io.quarkus.test.junit.QuarkusIntegrationTestExtension.throwBootFailureException(QuarkusIntegrationTestExtension.java:347)

Expected behavior

Test passes.

Actual behavior

Test fails.

How to Reproduce?

Run the awt integration-test with a JDK 20-based GraalVM master build. Eg. from here:

Output of uname -a or ver

No response

Output of java -version

20+36

GraalVM version (if different from Java)

master

Quarkus version or git rev

main

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

Might be related to oracle/graal#6088 that got merged recently.

@jerboaa jerboaa added the kind/bug Something isn't working label Mar 3, 2023
@quarkus-bot
Copy link

quarkus-bot bot commented Mar 3, 2023

/cc @Karm (awt,mandrel), @galderz (awt,mandrel), @zakkak (awt,mandrel)

@jerboaa
Copy link
Contributor Author

jerboaa commented Mar 3, 2023

@jerboaa
Copy link
Contributor Author

jerboaa commented Mar 3, 2023

Seems related to: oracle/graal#4921. The native image build produces so files which need to be transplanted together with the generated native image.

The native image build produces these artefacts:

 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/libawt.so (jdk_library)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/libawt_headless.so (jdk_library)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/libawt_xawt.so (jdk_library)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/libfontmanager.so (jdk_library)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/libjava.so (jdk_library_shim)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/libjavajpeg.so (jdk_library)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/libjvm.so (jdk_library_shim)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/liblcms.so (jdk_library)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/libmlib_image.so (jdk_library)
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/awt/target/quarkus-integration-test-awt-999-SNAPSHOT-native-image-source-jar/quarkus-integration-test-awt-999-SNAPSHOT-runner (executable)

It would appear that those so's need to be available where the executable quarkus-integration-test-awt-999-SNAPSHOT-runner ends up being.

@Karm
Copy link
Member

Karm commented Mar 3, 2023

Thx @jerboaa , I'll process it.

@jerboaa jerboaa changed the title ImageIO AWT Quarkus IT test fails with JDK 20-based GraalVM 23.0.0-dev build ImageIO AWT Quarkus IT test fails with GraalVM 23.0.0-dev build after AWT change Mar 6, 2023
@jerboaa
Copy link
Contributor Author

jerboaa commented Mar 6, 2023

Failure seen with JDK 17-based Graal master as well. Updated the summary.

@Karm
Copy link
Member

Karm commented Mar 14, 2023

I'm running with mandrel-java17-23.0.0-dev6da6520d012-2023-03-14 and mandrel-java20-23.0.0-dev6da6520d012-2023-03-14 to see now.

@Karm
Copy link
Member

Karm commented Mar 14, 2023

O.K., well, I will gather the libs in target next to the executable, amend Dockerfile.native and QuickStart. It might make some things clearer. It's not like we hadn't had to shuffle libraries around or install additional ones before, we did: e.g. Dockerfile.native or Dockerfile.native-micro

@Karm
Copy link
Member

Karm commented Mar 20, 2023

Note: It doesn't seem easily configurable on the GraalVM's side atm:
https://github.com/oracle/graal/blob/master/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/jdk/JNIRegistrationSupport.java#L249
So it's really Quarkus who has to copy the artifacts.

@Karm
Copy link
Member

Karm commented Mar 20, 2023

Gonna test on Windows too now :)

@Karm
Copy link
Member

Karm commented Mar 20, 2023

I've got the files in place, according the strace, the .so location is tried:

lstat("/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so", {st_mode=S_IFREG|0755, st_size=871000, ...}) = 0

And yet, https://github.com/oracle/graal/blob/master/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/NativeLibrarySupport.java#L136 Hmm.

@Karm
Copy link
Member

Karm commented Mar 20, 2023

I can see that dlopen on PosixUtils.java is called as expected:

$ ./target/awt-graphics-rest-quickstart-1.0.0-SNAPSHOT-runner 
KARM: Calling Dlfcn.dlopen(/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so,...)

The file not only exists: (updated Quarkus NativeImageBuildStep put it there)

-rw-r--r--. 1 karm karm 851K Mar 20 13:03 /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so

but it's also intact:

bac27beb0e4583f057ca6353ae451d1f73416c54f29b02f520973d412ec76df2  target/awt-graphics-rest-quickstart-1.0.0-SNAPSHOT-native-image-source-jar/libawt.so
bac27beb0e4583f057ca6353ae451d1f73416c54f29b02f520973d412ec76df2  target/libawt.so
bac27beb0e4583f057ca6353ae451d1f73416c54f29b02f520973d412ec76df2  /home/karm/tmp/mandrel-23.0-SNAPSHOT/lib/libawt.so
bac27beb0e4583f057ca6353ae451d1f73416c54f29b02f520973d412ec76df2  /var/X/JDKs/jdk-17.0.5+8/lib/libawt.so

(neither SELinux nor permissions issue, I tried disabling the former and changing ugo+x the latter)

@jerboaa
Copy link
Contributor Author

jerboaa commented Mar 20, 2023

FWIW, I cannot get a simple swing app to work either. No quarkus involved:

native-image SwingPaintDemo2 
========================================================================================================================
GraalVM Native Image: Generating 'swingpaintdemo2' (executable)...
========================================================================================================================
[1/8] Initializing...                                                                                    (2.6s @ 0.18GB)
 Version info: 'GraalVM 23.0.0-dev Java 17.0.7-beta+1-202302142331 Mandrel Distribution'
 Java version info: '17.0.7-beta+1-202302142331'
 C compiler: gcc (redhat, x86_64, 12.2.1)
 Garbage collector: Serial GC (max heap size: 80% of RAM)
[2/8] Performing analysis...  [****]                                                                    (19.1s @ 2.35GB)
   7,103 (81.57%) of  8,708 types reachable
  13,715 (63.03%) of 21,758 fields reachable
  37,769 (56.28%) of 67,110 methods reachable
   2,126 types,    93 fields, and   854 methods registered for reflection
      59 types,    59 fields, and    52 methods registered for JNI access
       4 native libraries: dl, pthread, rt, z
[3/8] Building universe...                                                                               (3.5s @ 1.76GB)
[4/8] Parsing methods...      [**]                                                                       (2.2s @ 0.86GB)
[5/8] Inlining methods...     [***]                                                                      (1.3s @ 2.03GB)
[6/8] Compiling methods...    [****]                                                                    (18.9s @ 3.72GB)
[7/8] Layouting methods...    [**]                                                                       (2.9s @ 4.43GB)
[8/8] Creating image...       [**]                                                                       (3.9s @ 1.11GB)
  17.65MB (48.12%) for code area:    22,903 compilation units
  18.75MB (51.12%) for image heap:  214,109 objects and 144 resources
 282.91KB ( 0.75%) for other data
  36.68MB in total
------------------------------------------------------------------------------------------------------------------------
Top 10 origins of code area:                                Top 10 object types in image heap:
   6.84MB java.desktop                                         3.90MB byte[] for code metadata
   5.65MB java.base                                            2.13MB java.lang.String
   3.66MB java.xml                                             1.72MB byte[] for general heap data
 917.51KB svm.jar (Native Image)                               1.69MB java.lang.Class
 117.06KB java.logging                                         1.51MB byte[] for embedded resources
  93.07KB java.prefs                                           1.45MB byte[] for java.lang.String
  68.95KB java.datatransfer                                  610.41KB com.oracle.svm.core.hub.DynamicHubCompanion
  61.92KB org.graalvm.nativeimage.base                       526.73KB java.util.HashMap$Node
  54.39KB jdk.crypto.ec                                      513.00KB int[][]
  24.42KB org.graalvm.sdk                                    411.96KB java.lang.String[]
  38.77KB for 9 more packages                                  3.78MB for 1358 more object types
------------------------------------------------------------------------------------------------------------------------
                        2.9s (5.2% of total time) in 31 GCs | Peak RSS: 6.12GB | CPU load: 9.17
------------------------------------------------------------------------------------------------------------------------
Produced artifacts:
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/libawt.so (jdk_library)
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/libawt_headless.so (jdk_library)
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/libawt_xawt.so (jdk_library)
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/libfontmanager.so (jdk_library)
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/libjava.so (jdk_library_shim)
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/libjavajpeg.so (jdk_library)
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/libjvm.so (jdk_library_shim)
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/liblcms.so (jdk_library)
 /home/sgehwolf/Documents/mandrel/bugs/awt-test/swingpaintdemo2 (executable)
========================================================================================================================
$ ./swingpaintdemo2 
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.Toolkit$2.run(Toolkit.java:1388)
	at [email protected]/java.awt.Toolkit$2.run(Toolkit.java:1386)
	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.Toolkit.loadLibraries(Toolkit.java:1385)
	at [email protected]/java.awt.Toolkit.initStatic(Toolkit.java:1423)
	at [email protected]/java.awt.Toolkit.<clinit>(Toolkit.java:1397)
	at [email protected]/java.awt.EventQueue.invokeLater(EventQueue.java:1314)
	at [email protected]/javax.swing.SwingUtilities.invokeLater(SwingUtilities.java:1421)
	at SwingPaintDemo2.main(SwingPaintDemo2.java:12)

But the trace looks suspicious. It seems the JDK wants to load the library which fails. Strace indicates only /usr/lib and /usr/lib64 are being consulted, which indeed doesn't have libawt.so.

@Karm
Copy link
Member

Karm commented Mar 20, 2023

@jerboaa I know my dl is looking at the right file, but it returns null or at least GraalVM native integration thinks so:

karm@localhost:~/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart (q-issue-31596)$ ./target/awt-graphics-rest-quickstart-1.0.0-SNAPSHOT-runner 
KARM: Calling Dlfcn.dlopen(/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so,...)
KARM: RTLD_LAZY Status is not null: false of /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so.
            dlhandle = PosixUtils.dlopen(canonicalIdentifier, Dlfcn.RTLD_LAZY());
            System.out.printf("KARM: RTLD_LAZY Status is not null: %s of %s.\n", dlhandle.isNonNull(), canonicalIdentifier);

in https://github.com/oracle/graal/blob/master/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/PosixNativeLibraryFeature.java#L187

Hmm.

@Karm
Copy link
Member

Karm commented Mar 20, 2023

 54 /* Open the shared object FILE and map it in; return a handle that can be
 55    passed to `dlsym' to get symbol values from it.  */
 56 extern void *dlopen (const char *__file, int __mode) __THROWNL;

So, the handle is either NULL or
https://github.com/oracle/graal/blob/master/substratevm/src/com.oracle.svm.core.posix/src/com/oracle/svm/core/posix/headers/Dlfcn.java#L71
does not work as intended now...

gdb o'clock...

@Karm
Copy link
Member

Karm commented Mar 20, 2023

Using LD_DEBUG=all seems like dlopen works fine and then reporting back to graal fails? :-(

@Karm
Copy link
Member

Karm commented Mar 20, 2023

e.g.

 `PixelForIntBgr'
    116279:     symbol=PixelForIntRgbx;  lookup in file=./target/awt-graphics-rest-quickstart-1.0.0-SNAPSHOT-runner [0]
    116279:     symbol=PixelForIntRgbx;  lookup in file=/lib64/libz.so.1 [0]
    116279:     symbol=PixelForIntRgbx;  lookup in file=/lib64/libpthread.so.0 [0]
    116279:     symbol=PixelForIntRgbx;  lookup in file=/lib64/libdl.so.2 [0]
    116279:     symbol=PixelForIntRgbx;  lookup in file=/lib64/librt.so.1 [0]
    116279:     symbol=PixelForIntRgbx;  lookup in file=/lib64/libc.so.6 [0]
    116279:     symbol=PixelForIntRgbx;  lookup in file=/lib64/ld-linux-x86-64.so.2 [0]
    116279:     symbol=PixelForIntRgbx;  lookup in file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so [0]
    116279:     binding file /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so [0] to /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so [0]: normal symbol 

Full log: https://karms.biz/pastebin/dlopen-awt-q-full.txt

Beginning in

            dlhandle = PosixUtils.dlopen(canonicalIdentifier, Dlfcn.RTLD_LAZY());
KARM: Calling Dlfcn.dlopen(/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so,...)
    116279:	symbol=dlopen;  lookup in file=./target/awt-graphics-rest-quickstart-1.0.0-SNAPSHOT-runner [0]
    116279:	symbol=dlopen;  lookup in file=/lib64/libz.so.1 [0]
    116279:	symbol=dlopen;  lookup in file=/lib64/libpthread.so.0 [0]
    116279:	symbol=dlopen;  lookup in file=/lib64/libdl.so.2 [0]
    116279:	binding file ./target/awt-graphics-rest-quickstart-1.0.0-SNAPSHOT-runner [0] to /lib64/libdl.so.2 [0]: normal symbol `dlopen' [GLIBC_2.2.5]
    116279:	
    116279:	file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so [0];  dynamically loaded by ./target/awt-graphics-rest-quickstart-1.0.0-SNAPSHOT-runner [0]
    116279:	file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so [0];  generating link map
    116279:	  dynamic: 0x00007f32ad3a75d8  base: 0x00007f32ad2eb000   size: 0x00000000000ec168
    116279:	    entry: 0x00007f32ad3187f0  phdr: 0x00007f32ad2eb040  phnum:                  8
    116279:	
    116279:	
    116279:	file=libjvm.so [0];  needed by /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so [0]
    116279:	find library=libjvm.so [0]; searching
    116279:	 search path=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/glibc-hwcaps/x86-64-v3:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/glibc-hwcaps/x86-64-v2:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/tls/haswell/x86_64:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/tls/haswell:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/tls/x86_64:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/tls:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/haswell/x86_64:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/haswell:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/x86_64:/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target		(RPATH from file /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so)
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/glibc-hwcaps/x86-64-v3/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/glibc-hwcaps/x86-64-v2/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/tls/haswell/x86_64/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/tls/haswell/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/tls/x86_64/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/tls/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/haswell/x86_64/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/haswell/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/x86_64/libjvm.so
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libjvm.so
    116279:	
    116279:	file=libjvm.so [0];  generating link map
    116279:	  dynamic: 0x00007f329a5fee20  base: 0x00007f329a3fe000   size: 0x0000000000201028
    116279:	    entry: 0x00007f329a3fe460  phdr: 0x00007f329a3fe040  phnum:                  6
    116279:	
    116279:	
    116279:	file=libjava.so [0];  needed by /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so [0]
    116279:	find library=libjava.so [0]; searching
    116279:	 search path=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target		(RPATH from file /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libawt.so)
    116279:	  trying file=/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libjava.so
    116279:	
    116279:	file=libjava.so [0];  generating link map
    116279:	  dynamic: 0x00007f329a3fce20  base: 0x00007f329a1fc000   size: 0x0000000000201028
    116279:	    entry: 0x00007f329a1fc460  phdr: 0x00007f329a1fc040  phnum:                  6
    116279:	

@Karm
Copy link
Member

Karm commented Mar 20, 2023

See oracle/graal#6244

@Karm
Copy link
Member

Karm commented Mar 21, 2023

When we fix Temurin OpenJDK based Mandrel to correctly load awt libs at runtime:

or use either a LabsJDK based Mandrel or GraalVM CE distro, we also need to fix what we do in the AWT extension itself WRT initializing the state:

./src/java.desktop/unix/native/libawt/awt/awt_LoadLibrary.c

    144     CHECK_EXCEPTION_FATAL(env, "Could not allocate font manager name");
    145 
    146     if (fmanager && fmProp) {
    147         JNU_CallStaticMethodByName(env, NULL, "java/lang/System", "setProperty",
    148                                    "(Ljava/lang/String;Ljava/lang/String;)Ljava/lang/String;",
    149                                    fmProp, fmanager);
>>> 150         CHECK_EXCEPTION_FATAL(env, "Could not allocate set properties");
    151     }

Hmm. Deferring java.lang.System to runtime...

com.oracle.svm.core.code.IsolateEnterStub.JNIFunctions_FatalError_5ea28336426fe0a26a33d6b62307157f39a34d1c(IsolateEnterStub.java:0)
com.oracle.svm.core.jni.JNIOnLoadFunctionPointer.invoke(JNILibraryInitializer.java)
com.oracle.svm.core.jni.JNILibraryInitializer.callOnLoadFunction(JNILibraryInitializer.java:71)
com.oracle.svm.core.jni.JNILibraryInitializer.initialize(JNILibraryInitializer.java:132)
com.oracle.svm.core.jdk.NativeLibrarySupport.addLibrary(NativeLibrarySupport.java:204)
com.oracle.svm.core.jdk.NativeLibrarySupport.loadLibrary0(NativeLibrarySupport.java:160)
com.oracle.svm.core.jdk.NativeLibrarySupport.loadLibraryRelative(NativeLibrarySupport.java:123)
java.lang.ClassLoader.loadLibrary(ClassLoader.java:50)
java.lang.Runtime.loadLibrary0(Runtime.java:818)
java.lang.System.loadLibrary(System.java:1989)
sun.awt.X11GraphicsEnvironment$1.run(X11GraphicsEnvironment.java:63)

Full log:
mandrel-23-labs17.txt
graalvm-ce-23-labs17.txt

To get Quarkus up to this point, one needs the .so files to be found in the first place, I do it in the NativeImageBuildStep.java:

diff --git a/core/deployment/src/main/java/io/quarkus/deployment/pkg/steps/NativeImageBuildStep.java b/core/deployment/src/main/java/io/quarkus/deployment/pkg/steps/NativeImageBuildStep.java
index 396e3adf003..12b4d9c7573 100644
--- a/core/deployment/src/main/java/io/quarkus/deployment/pkg/steps/NativeImageBuildStep.java
+++ b/core/deployment/src/main/java/io/quarkus/deployment/pkg/steps/NativeImageBuildStep.java
@@ -5,6 +5,7 @@
 import java.io.IOException;
 import java.io.UncheckedIOException;
 import java.nio.charset.StandardCharsets;
+import java.nio.file.DirectoryStream;
 import java.nio.file.Files;
 import java.nio.file.Path;
 import java.nio.file.Paths;
@@ -265,6 +266,24 @@ public NativeImageBuildItem build(NativeConfig nativeConfig, LocalesBuildTimeCon
                     Files.delete(generatedSymbols);
                 }
             }
+
+            // See https://github.com/oracle/graal/issues/4921
+            try (DirectoryStream<Path> sharedLibs = Files.newDirectoryStream(outputDir, "*.{so,dll}")) {
+                sharedLibs.forEach(src -> {
+                    Path dst = null;
+                    try {
+                        dst = Path.of(outputTargetBuildItem.getOutputDirectory().toAbsolutePath().toString(),
+                                src.getFileName().toString());
+                        log.debugf("Copying a shared lib from %s to %s.", src, dst);
+                        Files.copy(src, dst, StandardCopyOption.REPLACE_EXISTING);
+                    } catch (IOException e) {
+                        log.errorf("Could not copy shared lib from %s to %s. Continuing. Error: %s", src, dst, e);
+                    }
+                });
+            } catch (IOException e) {
+                log.errorf("Could not list files in directory %s. Continuing. Error: %s", outputDir, e);
+            }
+
             System.setProperty("native.image.path", finalExecutablePath.toAbsolutePath().toString());
 
             return new NativeImageBuildItem(finalExecutablePath,

@Karm
Copy link
Member

Karm commented Mar 21, 2023

I'd need to access load and setProperty methods on java.lang.System (consequently props field) at runtime from native code, e.g. from awt_LoadLibrary.c, but I don't know how to fine grain the control like this in Quarkus just using the extension mechanism yet. I cannot jam the whole thing as that would result in
com.oracle.svm.hosted.substitute.DeletedElementException: Unsupported field java.lang.System.props is reachable
etc.
i.e. just plain JniRuntimeAccessBuildItem doesn't work for me now.

@Karm
Copy link
Member

Karm commented Mar 21, 2023

O.K., I'll enhance NativeImageJNIConfigStep for more fine-grained control.

@Karm
Copy link
Member

Karm commented Mar 26, 2023

Could not allocate library name over here https://github.com/openjdk/jdk17u-dev/blob/jdk-17.0.7+5/src/java.desktop/unix/native/libawt/awt/awt_LoadLibrary.c#L174

is a false alarm. There is nothing wrong with jstring jbuf = JNU_NewStringPlatform(env, buf); call above.

The error state originates way earlier, over here: https://github.com/openjdk/jdk17u-dev/blob/jdk-17.0.7+5/src/java.desktop/unix/native/libawt/awt/awt_LoadLibrary.c#L62

And is not cleared. I'll open a PR to enhance that part with a call to CHECK_EXCEPTION_FATAL as it would have saved me considerable time if it were there.

Adding

{
"name":"java.awt.GraphicsEnvironment",
"methods":[{"name":"isHeadless","parameterTypes":[]}]
}

to the JNI Config then solves this particular part.

@Karm
Copy link
Member

Karm commented Mar 28, 2023

I've got it finally working. The last thing to clear is this exception:

2023-03-28 08:51:34,695 INFO  [io.quarkus] (main) awt-graphics-rest-quickstart 1.0.0-SNAPSHOT native (powered by Quarkus 999-SNAPSHOT) started in 0.100s. Listening on: http://0.0.0.0:8080
2023-03-28 08:51:34,695 INFO  [io.quarkus] (main) Profile prod activated. 
2023-03-28 08:51:34,695 INFO  [io.quarkus] (main) Installed features: [awt, cdi, resteasy, resteasy-multipart, smallrye-context-propagation, vertx]
KARM: Calling Dlfcn.dlopen(/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libjavajpeg.so,...)
KARM: RTLD_LAZY Status is null: false of /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/libjavajpeg.so.
Exception in thread "AWT-XAWT" java.lang.IllegalMonitorStateException
        at [email protected]/java.util.concurrent.locks.ReentrantLock$Sync.tryRelease(ReentrantLock.java:175)
        at [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1007)
        at [email protected]/java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:494)
        at [email protected]/sun.awt.SunToolkit.awtUnlock(SunToolkit.java:247)
        at [email protected]/sun.awt.X11.XToolkit.run(XToolkit.java:739)
        at [email protected]/sun.awt.X11.XToolkit.run(XToolkit.java:647)
        at [email protected]/java.lang.Thread.run(Thread.java:833)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:807)
        at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:210)
KARM: Calling Dlfcn.dlopen(/home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/liblcms.so,...)
KARM: RTLD_LAZY Status is null: false of /home/karm/workspaceRH/quarkus-quickstarts/awt-graphics-rest-quickstart/target/liblcms.so.

The image gets generated just fine, but obviously, something is wrong in there. I will dive in and check it.

@Karm
Copy link
Member

Karm commented Mar 28, 2023

I have the Monitor fixed. The yield needed to be called from awt_util.c. 👍

I'll run the full TS now and polish the PR....

@Karm
Copy link
Member

Karm commented Mar 30, 2023

/me Currently on LUTs/colour profiles where something is still off, i.e. there are still some test images that could take down the app.

@Karm
Copy link
Member

Karm commented Mar 31, 2023

@Karm
Copy link
Member

Karm commented Mar 31, 2023

It's gonna be something in the lazy liblcms.so init.

@Karm
Copy link
Member

Karm commented Apr 3, 2023

Resolved. *.pf colour profile files needed to be included. The JDK code is just hiding this failure as it has never dealt with the situation that not even the handful of default, JDK-baked in profiles weren't present.
The whole TS passes finally. I'm polishing the changes to Q for a PR.
Then I'll follow up with a JDK PR to make the reporting better to save someone a headache in future...

@ayhanap
Copy link

ayhanap commented Nov 3, 2023

Any idea how to make this work with Jib builder? Should this be another issue?

------------------------------------------------------------------------------------------------------------------------
Produced artifacts:
 /project/libawt.so (jdk_library)
 /project/libawt_headless.so (jdk_library)
 /project/libawt_xawt.so (jdk_library)
 /project/libfontmanager.so (jdk_library)
 /project/libjava.so (jdk_library_shim)
 /project/libjavajpeg.so (jdk_library)
 /project/libjvm.so (jdk_library_shim)
 /project/liblcms.so (jdk_library)
 /project/libmlib_image.so (jdk_library)
 /project/media-processor-0.18.1.native-runner (executable)
 /project/media-processor-0.18.1.native-runner-build-output-stats.json (build_info)
========================================================================================================================
Finished generating 'media-processor-0.18.1.native-runner' in 9m 38s.
[INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildRunner] docker run --env LANG=C --rm --user 1001:127 -v /home/runner/work/xxx/xxx/media-processor/target/media-processor-0.18.1.native-native-image-source-jar:/project:z --entrypoint /bin/bash quay.io/quarkus/ubi-quarkus-mandrel-builder-image:jdk-17 -c objcopy --strip-debug media-processor-0.18.1.native-runner
[INFO] [io.quarkus.container.image.jib.deployment.JibProcessor] Starting (local) container image build for native binary using jib.
[INFO] [io.quarkus.container.image.jib.deployment.JibProcessor] Using docker to run the native image builder
Warning:  [io.quarkus.container.image.jib.deployment.JibProcessor] Base image 'europe-west1-docker.pkg.dev/xxx/xxx/openjdk-17-runtime-chrome' does not use a specific image digest - build may not be reproducible
[INFO] [io.quarkus.container.image.jib.deployment.JibProcessor] The base image requires auth. Trying again for europe-west1-docker.pkg.dev/xxx/xxx/openjdk-17-runtime-chrome...
[INFO] [io.quarkus.container.image.jib.deployment.JibProcessor] LogEvent [level=INFO, message=Docker config auths section defines credentials for europe-west1-docker.pkg.dev]
[INFO] [io.quarkus.container.image.jib.deployment.JibProcessor] LogEvent [level=LIFECYCLE, message=Using credentials from Docker config (/home/runner/.docker/config.json) for europe-west1-docker.pkg.dev/userowl-api/userowl/openjdk-17-runtime-chrome]
[INFO] [io.quarkus.container.image.jib.deployment.JibProcessor] Using base image with digest: sha256:6c13a25fac608f52b8dce996ef73fb3ba67ef3a39614050bf342d1cd64c67aa5
[INFO] [io.quarkus.container.image.jib.deployment.JibProcessor] Container entrypoint set to [./application]
[INFO] [io.quarkus.container.image.jib.deployment.JibProcessor] Created container image europe-west1-docker.pkg.dev/xxx/xxx/xxxx:0.18.1.native (sha256:12f666a2241f14e22cf112f9123514407776d2d1a9bb5ffd8a37bb6d1ae1b654)

Karm added a commit to Karm/jdk that referenced this issue Jul 13, 2024
If there is problem with finding and calling e.g. java/awt/GraphicsEnvironment
in AWTIsHeadless, the env' Exception remains set and it not cleared.
Later, that manifests as:

    Fatal error reported via JNI: Could not allocate library name

Which is misleading. The code path is perhaps rare in normal JDK usage,
but it has been complicating our users' bug reports in the GraalVM/native-image
ecosystem for quite some time.

Instead of failing later with some clear message that indicates that the
user has incorrectly configured JNI, it bails out very soon with a message
that seems as if a jstring could not have been allocated. It sends users
on wild goose chases, e.g.

oracle/graal#9138
oracle/graal#8475
oracle/graal#9300
quarkusio/quarkus#31596
graalvm/mandrel#292
Karm/mandrel-integration-tests#262

This commit fixes the error reporting in the AWTIsHeadless.

Furthermore, when AOT compiled, there is little sense for having a JAVA_HOME,
yet some parts of AWT code look for it to search fonts. In such case, an
empty directory structure is enough to accommodate it, e.g.

/tmp/JAVA_HOME/
/tmp/JAVA_HOME/conf
/tmp/JAVA_HOME/conf/fonts
/tmp/JAVA_HOME/lib

The exception is somewhat cryptic for users again, merely stating:

    Exception in thread "main" java.io.IOException: Problem reading font data.
        at [email protected]/java.awt.Font.createFont0(Font.java:1205)
        at [email protected]/java.awt.Font.createFont(Font.java:1076)
        at imageio.Main.loadFonts(Main.java:139

Adding the cause there makes it clearer, i.e. that JAVA_HOME might be missing:

    Exception in thread "main" java.io.IOException: Problem reading font data.
        at java.desktop@23-internal/java.awt.Font.createFont0(Font.java:1206)
        at java.desktop@23-internal/java.awt.Font.createFont(Font.java:1076)
        at imageio.Main.loadFonts(Main.java:139)
        at imageio.Main.paintRectangles(Main.java:97)
        at imageio.Main.main(Main.java:195)
        at java.base@23-internal/java.lang.invoke.LambdaForm$DMH/sa346b79c.invokeStaticInit(LambdaForm$DMH)
    Caused by: java.lang.Error: java.home property not set
        at java.desktop@23-internal/sun.awt.FontConfiguration.findFontConfigFile(FontConfiguration.java:180)
        at java.desktop@23-internal/sun.awt.FontConfiguration.<init>(FontConfiguration.java:97)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants