native-image fails only on Windows when using --initialize-at-build-time with args

lread commented 2 years ago

Thanks! First and foremost: thanks to the Graal team for native-image, it is truly an awesome work!

Describe the issue The Clojure community is adapting to the fact that --initialize-at-build-time without arguments has been deprecated and will be removed in GraalVM v22.0. (Clojure-created classes typically need to be initialized at build time and, for this reason, many Clojure projects that use Graal native-image currently use a global --initialize-at-build-time with no args).

While testing my project with --initialize-at-build-time with specific arguments, I have found that native-image works fine on macOS and Linux but fails with a should not reach here error under Windows.
(Please note that native-image works without error on this same project across all OSes with an --initialize-at-build-time with no args)

I fully expect that I've missed some nuance, but also assume that a should not reach here under Windows is an internal error and one that the Graal team would be interested to hear about.

An oddity worth mentioning is that even though native-image fails with a should not reach here error on Windows, it still produces an image that runs and produces the expected output.

I have created a reproduction of the issue in a GitHub repo. You can see evidence of the behaviour in output from GitHub Actions for GraalVM v21.2.0 and GraalVM nightly (output for v21.2.0 run from my Windows dev box also pasted below under "More details").

Steps to reproduce the issue From a Windows computer, witness the failure via a PowerShell terminal session with native-image setup appropriatly:

git clone https://github.com/lread/repro-graal-build-time-windows.git
cd repro-graal-build-time-windows
From here you have options:
1. To reproduce from pre-built jar: .\repro1-jar.ps1
2. For other options see notes for Graal team in repo.

To witness success on maOS and Linux, repeat above in bash and run ./repro1-jar.sh.

On all OSes the resulting image can be run and will output:

Hello, running tests in sample namespace.

Testing hello-world.sample-test

Ran 1 tests containing 1 assertions.
0 failures, 0 errors.
All done.

Describe GraalVM and your environment:

GraalVM version 21.2.0 (also tried nightly 21.3.0-dev-20211008_1804-java11-amd64 via GitHub Actions)
JDK major version: 11
OS: Windows 10 (failing) macOS 10.15 (passing), Linux (passing)

More details Output from native-image on Windows:

Executing [
'C:\Users\lee\scoop\apps\graalvm\current\bin\java.exe' \
-XX:+UseParallelGC \
-XX:+UnlockExperimentalVMOptions \
-XX:+EnableJVMCI \
-Dtruffle.TrustAllTruffleRuntimeProviders=true \
-Dtruffle.TruffleRuntime=com.oracle.truffle.api.impl.DefaultTruffleRuntime \
-Dgraalvm.ForcePolyglotInvalid=true \
-Dgraalvm.locatorDisabled=true \
-Dsubstratevm.IgnoreGraalVersionCheck=true \
--add-exports=java.base/com.sun.crypto.provider=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.event=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.loader=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.logger=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.misc=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.module=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.org.objectweb.asm=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.org.xml.sax.helpers=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.perf=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.ref=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.util.xml.impl=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.util.xml=ALL-UNNAMED \
--add-exports=java.base/sun.invoke.util=ALL-UNNAMED \
--add-exports=java.base/sun.nio.ch=ALL-UNNAMED \
--add-exports=java.base/sun.reflect.annotation=ALL-UNNAMED \
--add-exports=java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED \
--add-exports=java.base/sun.reflect.generics.repository=ALL-UNNAMED \
--add-exports=java.base/sun.reflect.generics.tree=ALL-UNNAMED \
--add-exports=java.base/sun.security.jca=ALL-UNNAMED \
--add-exports=java.base/sun.security.provider=ALL-UNNAMED \
--add-exports=java.base/sun.security.util=ALL-UNNAMED \
--add-exports=java.base/sun.text.spi=ALL-UNNAMED \
--add-exports=java.base/sun.util.calendar=ALL-UNNAMED \
--add-exports=java.base/sun.util.locale.provider=ALL-UNNAMED \
--add-exports=java.base/sun.util.resources=ALL-UNNAMED \
--add-exports=java.xml.crypto/org.jcp.xml.dsig.internal.dom=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.aarch64=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.amd64=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.code.site=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.code.stack=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.code=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.common=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.hotspot.aarch64=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.hotspot.amd64=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.hotspot.sparc=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.hotspot=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.meta=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.runtime=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.services=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.sparc=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.events=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.internal.consumer=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.internal.handlers=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.internal.jfc=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.internal=ALL-UNNAMED \
-XX:+UseJVMCINativeLibrary \
-Xss10m \
-Xms1g \
-Xmx5987224776 \
-Duser.country=US \
-Duser.language=en \
-Djava.awt.headless=true \
-Dorg.graalvm.version=21.2.0 \
-Dorg.graalvm.config=CE \
-Dcom.oracle.graalvm.isaot=true \
-Djava.system.class.loader=com.oracle.svm.hosted.NativeImageSystemClassLoader \
-Xshare:off \
--module-path \
'C:\Users\lee\scoop\apps\graalvm\current\lib\truffle\truffle-api.jar' \
-Djdk.internal.lambda.disableEagerInitialization=true \
-Djdk.internal.lambda.eagerlyInitialize=false \
-Djava.lang.invoke.InnerClassLambdaMetafactory.initializeLambdas=false \
'-javaagent:C:\Users\lee\scoop\apps\graalvm\current\lib\svm\builder\svm.jar' \
-cp \
'C:\Users\lee\scoop\apps\graalvm\current\lib\svm\builder\objectfile.jar;C:\Users\lee\scoop\apps\graalvm\current\lib\svm\builder\pointsto.jar;C:\Users\lee\scoop\apps\graalvm\current\lib\svm\builder\svm.jar' \
'com.oracle.svm.hosted.NativeImageGeneratorRunner$JDK9Plus' \
-imagecp \
'Z:\proj\oss\-verify\wintmp\repro-graal-build-time-windows\exhibit\uber.jar;C:\Users\lee\scoop\apps\graalvm\current\lib\svm\library-support.jar' \
'-H:Path=Z:\proj\oss\-verify\wintmp\repro-graal-build-time-windows' \
-H:FallbackThreshold=0 \
-H:ClassInitialization=clojure:build_time,hello_world:build_time \
'-H:Class@manifest from file:///Z:/proj/oss/-verify/wintmp/repro-graal-build-time-windows/exhibit/uber.jar=hello_world.main' \
'-H:Name@manifest from file:///Z:/proj/oss/-verify/wintmp/repro-graal-build-time-windows/exhibit/uber.jar=uber' \
-H:Name=target/hello-world \
'-H:CLibraryPath=C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64'
]
[target/hello-world:5964]    classlist:   2,448.66 ms,  0.96 GB
[target/hello-world:5964]        (cap):   2,025.90 ms,  0.96 GB
[target/hello-world:5964]        setup:   4,019.58 ms,  0.96 GB
[target/hello-world:5964]     (clinit):     421.76 ms,  2.80 GB
[target/hello-world:5964]   (typeflow):  14,845.19 ms,  2.80 GB
[target/hello-world:5964]    (objects):  14,304.87 ms,  2.80 GB
[target/hello-world:5964]   (features):     946.48 ms,  2.80 GB
[target/hello-world:5964]     analysis:  31,979.68 ms,  2.80 GB
[target/hello-world:5964]     universe:   1,801.26 ms,  2.80 GB
[target/hello-world:5964]      (parse):   1,608.98 ms,  2.80 GB
[target/hello-world:5964]     (inline):   3,179.87 ms,  2.62 GB
[target/hello-world:5964]    (compile):  25,275.50 ms,  2.56 GB
[target/hello-world:5964]      compile:  31,445.28 ms,  2.56 GB
[target/hello-world:5964]        image:   4,008.25 ms,  2.31 GB
[target/hello-world:5964]        write:     620.20 ms,  2.31 GB
Fatal error:com.oracle.svm.core.util.VMError$HostedError: should not reach here
        at com.oracle.svm.core.util.VMError.shouldNotReachHere(VMError.java:64)
        at com.oracle.svm.hosted.jdk.JNIRegistrationSupport.makeShimDLL(JNIRegistrationSupport.java:256)
        at com.oracle.svm.hosted.jdk.JNIRegistrationSupport.makeShimDLLs(JNIRegistrationSupport.java:230)
        at com.oracle.svm.hosted.jdk.JNIRegistrationSupport.afterImageWrite(JNIRegistrationSupport.java:175)
        at com.oracle.svm.hosted.NativeImageGenerator.lambda$doRun$8(NativeImageGenerator.java:666)
        at com.oracle.svm.hosted.FeatureHandler.forEachFeature(FeatureHandler.java:71)
        at com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:666)
        at com.oracle.svm.hosted.NativeImageGenerator.run(NativeImageGenerator.java:491)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.buildImage(NativeImageGeneratorRunner.java:380)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.build(NativeImageGeneratorRunner.java:543)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.main(NativeImageGeneratorRunner.java:119)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner$JDK9Plus.main(NativeImageGeneratorRunner.java:573)
[target/hello-world:5964]      [total]:  76,599.23 ms,  2.31 GB
# Printing build artifacts to: Z:\proj\oss\-verify\wintmp\repro-graal-build-time-windows\target\hello-world.build_artifacts.txt
Error: Image build request failed with exit status 1
com.oracle.svm.driver.NativeImage$NativeImageError: Image build request failed with exit status 1
        at com.oracle.svm.driver.NativeImage.showError(NativeImage.java:1916)
        at com.oracle.svm.driver.NativeImage.build(NativeImage.java:1584)
        at com.oracle.svm.driver.NativeImage.performBuild(NativeImage.java:1545)
        at com.oracle.svm.driver.NativeImage.main(NativeImage.java:1532)

fernando-valdez commented 2 years ago

Hello @lread, I will take a look at this issue. I will let you know if I have any questions

lread commented 2 years ago

Thanks so much @fernando-valdez, I look forward to learning more!

fernando-valdez commented 2 years ago

No, thanks to you for creating such great documentation for this issue. I am glad I am handling this :D

lread commented 2 years ago

For what it's worth: I just retried on Windows 10 using the new Graal v21.3.0 release and I see no difference (not that I was expecting any, just letting you know I tried).

galderz commented 2 years ago

See https://github.com/quarkusio/quarkus/issues/20681. Passing in -H:+TraceNativeToolUsage -H:Log=*ShimDLL:3,link:3,copy:3 will get you more info. For that issue, building with 64 bit toolchain should work, but not sure if it applies to you too. Depends on what the output of those extra flags show.

I've also created https://github.com/oracle/graal/issues/3923 to address the JNI registration code properly. I'm unsure what's the best way to fix it: either fix machine to x64, or somehow detect it, or allow extra parameters.

lread commented 2 years ago

See quarkusio/quarkus#20681. Passing in -H:+TraceNativeToolUsage -H:Log=*ShimDLL:3,link:3,copy:3 will get you more info. For that issue, building with 64 bit toolchain should work, but not sure if it applies to you too. Depends on what the output of those extra flags show.

Thanks for the update @galderz! Windows has not been my primary development platform for many, many years so please do forgive any blatant naivete on my part here. Is my understanding correct?:

Visual Studio 2019 is 32-bit only, but can produce 64-bit targets
Visual Studio 2022 will be 64-bit

So, are you suggesting I try a Visual Studio 2022 preview? Or to simply ensure that I am set up correctly on Visual Studio 2019 to produce 64-bit binaries?

I've also created #3923 to address the JNI registration code properly. I'm unsure what's the best way to fix it: either fix machine to x64, or somehow detect it, or allow extra parameters.

Thanks for the info!

lread commented 2 years ago

And, not directly related, but related: my compliments to the Graal team on their new warning in v21.3.0:

--initialize-at-build-time without arguments has been deprecated when not using --diagnostics-mode. With GraalVM 22.0.0 --initialize-at-build-time will only work with --diagnostics-mode for debugging purposes.
The reason for deprecation is that --initalize-at-build-time does not compose, i.e., a single library can make assumptions that the whole classpath can be safely initialized at build time; that assumption is often incorrect.

Very clear!

lread commented 2 years ago

@galderz I've retried my reproduction with your suggested -H:+TraceNativeToolUsage -H:Log=*ShimDLL:3,link:3,copy:3.

> cat .\repro1-jar.ps1
echo "-[Clean]-"
Remove-Item -Recurse -Force -ErrorAction Ignore target
mkdir target

echo "-[Running native image]-"
native-image --no-fallback --verbose --initialize-at-build-time=clojure,hello_world -H:+TraceNativeToolUsage -H:Log=*ShimDLL:3,link:3,copy:3 -jar exhibit/uber.jar -H:Name=target/hello-world

echo "-[Running produced image]"
.\target\hello-world.exe

Here's the output:


> .\repro1-jar.ps1
-[Clean]-

    Directory: Z:\proj\oss\lread\repro-graal-build-time-windows

Mode                 LastWriteTime         Length Name
----                 -------------         ------ ----
d-----        10/22/2021  11:08 AM                target
-[Running native image]-
Executing [
'C:\Users\lee\scoop\apps\graalvm\current\bin\java.exe' \
-XX:+UseParallelGC \
-XX:+UnlockExperimentalVMOptions \
-XX:+EnableJVMCI \
-Dtruffle.TrustAllTruffleRuntimeProviders=true \
-Dtruffle.TruffleRuntime=com.oracle.truffle.api.impl.DefaultTruffleRuntime \
-Dgraalvm.ForcePolyglotInvalid=true \
-Dgraalvm.locatorDisabled=true \
-Dsubstratevm.IgnoreGraalVersionCheck=true \
--add-exports=java.base/com.sun.crypto.provider=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.event=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.loader=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.logger=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.misc=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.module=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.org.objectweb.asm=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.org.xml.sax.helpers=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.perf=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.ref=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.reflect=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.util.xml.impl=ALL-UNNAMED \
--add-exports=java.base/jdk.internal.util.xml=ALL-UNNAMED \
--add-exports=java.base/sun.invoke.util=ALL-UNNAMED \
--add-exports=java.base/sun.nio.ch=ALL-UNNAMED \
--add-exports=java.base/sun.reflect.annotation=ALL-UNNAMED \
--add-exports=java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED \
--add-exports=java.base/sun.reflect.generics.repository=ALL-UNNAMED \
--add-exports=java.base/sun.reflect.generics.tree=ALL-UNNAMED \
--add-exports=java.base/sun.security.jca=ALL-UNNAMED \
--add-exports=java.base/sun.security.provider=ALL-UNNAMED \
--add-exports=java.base/sun.security.util=ALL-UNNAMED \
--add-exports=java.base/sun.text.spi=ALL-UNNAMED \
--add-exports=java.base/sun.util.calendar=ALL-UNNAMED \
--add-exports=java.base/sun.util.locale.provider=ALL-UNNAMED \
--add-exports=java.base/sun.util.resources=ALL-UNNAMED \
--add-exports=java.xml.crypto/org.jcp.xml.dsig.internal.dom=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.aarch64=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.amd64=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.code.site=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.code.stack=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.code=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.common=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.hotspot.aarch64=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.hotspot.amd64=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.hotspot.sparc=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.hotspot=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.meta=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.runtime=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.services=ALL-UNNAMED \
--add-exports=jdk.internal.vm.ci/jdk.vm.ci.sparc=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.events=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.internal.consumer=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.internal.handlers=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.internal.jfc=ALL-UNNAMED \
--add-exports=jdk.jfr/jdk.jfr.internal=ALL-UNNAMED \
-XX:+UseJVMCINativeLibrary \
-Xss10m \
-Xms1g \
-Xmx5987224776 \
-Duser.country=US \
-Duser.language=en \
-Djava.awt.headless=true \
-Dorg.graalvm.version=21.3.0 \
-Dorg.graalvm.config=CE \
-Dcom.oracle.graalvm.isaot=true \
-Djava.system.class.loader=com.oracle.svm.hosted.NativeImageSystemClassLoader \
-Xshare:off \
-Djdk.internal.lambda.disableEagerInitialization=true \
-Djdk.internal.lambda.eagerlyInitialize=false \
-Djava.lang.invoke.InnerClassLambdaMetafactory.initializeLambdas=false \
'-javaagent:C:\Users\lee\scoop\apps\graalvm\current\lib\svm\builder\svm.jar' \
-cp \
'C:\Users\lee\scoop\apps\graalvm\current\lib\svm\builder\objectfile.jar;C:\Users\lee\scoop\apps\graalvm\current\lib\svm\builder\pointsto.jar;C:\Users\lee\scoop\apps\graalvm\current\lib\svm\builder\svm.jar' \
--module-path \
'C:\Users\lee\scoop\apps\graalvm\current\lib\truffle\truffle-api.jar' \
'com.oracle.svm.hosted.NativeImageGeneratorRunner$JDK9Plus' \
-imagecp \
'Z:\proj\oss\lread\repro-graal-build-time-windows\exhibit\uber.jar;C:\Users\lee\scoop\apps\graalvm\current\lib\svm\library-support.jar' \
'-H:Path=Z:\proj\oss\lread\repro-graal-build-time-windows' \
-H:FallbackThreshold=0 \
-H:ClassInitialization=clojure:build_time,hello_world:build_time \
-H:+TraceNativeToolUsage \
'-H:Log=*ShimDLL:3,link:3,copy:3' \
'-H:Class@manifest from file:///Z:/proj/oss/lread/repro-graal-build-time-windows/exhibit/uber.jar=hello_world.main' \
'-H:Name@manifest from file:///Z:/proj/oss/lread/repro-graal-build-time-windows/exhibit/uber.jar=uber' \
-H:Name=target/hello-world \
'-H:CLibraryPath=C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64'
]
[target/hello-world:9136]    classlist:   3,720.50 ms,  0.96 GB
>> 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\cl.exe'
># Microsoft (R) C/C++ Optimizing Compiler Version 19.29.30136 for x64
># Copyright (C) Microsoft Corporation.  All rights reserved.
>#
># usage: cl [ option... ] filename... [ /link linkoption... ]
>> 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\cl.exe' /WX /W4 /wd4244 /wd4245 /wd4800 /wd4804 /wd4214 '/FeC:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\AArch64LibCHelperDirectives.exe' 'C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\AArch64LibCHelperDirectives.c'
># AArch64LibCHelperDirectives.c
># Microsoft (R) Incremental Linker Version 14.29.30136.0
># Copyright (C) Microsoft Corporation.  All rights reserved.
>#
># /out:C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\AArch64LibCHelperDirectives.exe
># AArch64LibCHelperDirectives.obj
>> 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\cl.exe' /WX /W4 /wd4244 /wd4245 /wd4800 /wd4804 /wd4214 '-IC:\Users\lee\scoop\apps\graalvm\current\include\win32' '/FeC:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\JNIHeaderDirectives.exe' 'C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\JNIHeaderDirectives.c'
># JNIHeaderDirectives.c
># Microsoft (R) Incremental Linker Version 14.29.30136.0
># Copyright (C) Microsoft Corporation.  All rights reserved.
>#
># /out:C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\JNIHeaderDirectives.exe
># JNIHeaderDirectives.obj
>> 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\cl.exe' /WX /W4 /wd4244 /wd4245 /wd4800 /wd4804 /wd4214 '/FeC:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\WindowsDirectives.exe' 'C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\WindowsDirectives.c'
># WindowsDirectives.c
># Microsoft (R) Incremental Linker Version 14.29.30136.0
># Copyright (C) Microsoft Corporation.  All rights reserved.
>#
># /out:C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\WindowsDirectives.exe
># WindowsDirectives.obj
>> 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\cl.exe' /WX /W4 /wd4244 /wd4245 /wd4800 /wd4804 /wd4214 '/FeC:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\BuiltinDirectives.exe' 'C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\BuiltinDirectives.c'
># BuiltinDirectives.c
># Microsoft (R) Incremental Linker Version 14.29.30136.0
># Copyright (C) Microsoft Corporation.  All rights reserved.
>#
># /out:C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\BuiltinDirectives.exe
># BuiltinDirectives.obj
>> 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\cl.exe' /WX /W4 /wd4244 /wd4245 /wd4800 /wd4804 /wd4214 '/FeC:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\AMD64LibCHelperDirectives.exe' 'C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\AMD64LibCHelperDirectives.c'
># AMD64LibCHelperDirectives.c
># Microsoft (R) Incremental Linker Version 14.29.30136.0
># Copyright (C) Microsoft Corporation.  All rights reserved.
>#
># /out:C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\AMD64LibCHelperDirectives.exe
># AMD64LibCHelperDirectives.obj
[target/hello-world:9136]        (cap):   2,341.26 ms,  0.96 GB
[target/hello-world:9136]        setup:   4,847.37 ms,  0.96 GB
[target/hello-world:9136]     (clinit):     459.24 ms,  2.86 GB
[target/hello-world:9136]   (typeflow):   9,194.20 ms,  2.86 GB
[target/hello-world:9136]    (objects):  31,216.10 ms,  2.86 GB
[target/hello-world:9136]   (features):   2,941.43 ms,  2.86 GB
[target/hello-world:9136]     analysis:  45,828.23 ms,  2.86 GB
[target/hello-world:9136]     universe:   2,542.23 ms,  2.86 GB
[target/hello-world:9136]      (parse):   3,922.89 ms,  2.93 GB
[target/hello-world:9136]     (inline):   3,163.25 ms,  2.91 GB
[target/hello-world:9136]    (compile):  28,648.22 ms,  2.95 GB
[target/hello-world:9136]      compile:  37,364.54 ms,  2.95 GB
[target/hello-world:9136]        image:   2,802.80 ms,  2.95 GB
>> 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\cl.exe' '/FeZ:\proj\oss\lread\repro-graal-build-time-windows\target\hello-world.exe' 'target\hello-world.obj' 'C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64\libchelper.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\net.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\nio.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\java.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\fdlibm.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\zip.lib' 'C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64\jvm.lib' /MD 'C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64\libchelper.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\net.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\nio.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\java.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\fdlibm.lib' 'C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\zip.lib' 'C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64\jvm.lib' /link /INCREMENTAL:NO /NODEFAULTLIB:LIBCMT '/IMPLIB:C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\target\hello-world.lib' '/LIBPATH:C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64' '/LIBPATH:C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64' winhttp.lib version.lib advapi32.lib ws2_32.lib secur32.lib iphlpapi.lib userenv.lib setargv.obj /include:JDK_LoadSystemLibrary /include:getEncodingFromLangID /include:getJavaIDFromLangID shell32.lib
># Microsoft (R) C/C++ Optimizing Compiler Version 19.29.30136 for x64
># Copyright (C) Microsoft Corporation.  All rights reserved.
>#
># Microsoft (R) Incremental Linker Version 14.29.30136.0
># Copyright (C) Microsoft Corporation.  All rights reserved.
>#
># /out:Z:\proj\oss\lread\repro-graal-build-time-windows\target\hello-world.exe
># /INCREMENTAL:NO
># /NODEFAULTLIB:LIBCMT
># /IMPLIB:C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\target\hello-world.lib
># /LIBPATH:C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64
># /LIBPATH:C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64
># winhttp.lib
># version.lib
># advapi32.lib
># ws2_32.lib
># secur32.lib
># iphlpapi.lib
># userenv.lib
># setargv.obj
># /include:JDK_LoadSystemLibrary
># /include:getEncodingFromLangID
># /include:getJavaIDFromLangID
># shell32.lib
># target\hello-world.obj
># C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64\libchelper.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\net.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\nio.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\java.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\fdlibm.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\zip.lib
># C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64\jvm.lib
># C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64\libchelper.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\net.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\nio.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\java.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\fdlibm.lib
># C:\Users\lee\scoop\apps\graalvm\21.3.0\lib\static\windows-amd64\zip.lib
># C:\Users\lee\scoop\apps\graalvm\current\lib\svm\clibraries\windows-amd64\jvm.lib
>#    Creating library C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\target\hello-world.lib and object C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\target\hello-world.exp
[Use -Dgraal.LogFile=<path> to redirect Graal log output to a file.]
[thread:1] scope: main
    [thread:1] scope: main.JDKLibs.copy
    from: C:\Users\lee\scoop\apps\graalvm\current\bin
      [thread:1] scope: main.JDKLibs.copy
      awt.dll: OK
      java.dll: SKIPPED
      net.dll: SKIPPED
      nio.dll: SKIPPED
      sunmscapi.dll: OK
      zip.dll: SKIPPED
    [thread:1] scope: main.JDKLibs.javaShimDLL
    exports: JDK_LoadSystemLibrary, JNU_CallMethodByName, JNU_CallMethodByNameV, JNU_CallStaticMethodByName, JNU_ClassString, JNU_GetEnv, JNU_GetFieldByName, JNU_GetStaticFieldByName, JNU_IsInstanceOfByName, JNU_NewObjectByName, JNU_NewStringPlatform, JNU_SetFieldByName, JNU_ThrowArrayIndexOutOfBoundsException, JNU_ThrowByName, JNU_ThrowIOException, JNU_ThrowIllegalArgumentException, JNU_ThrowInternalError, JNU_ThrowNullPointerException, JNU_ThrowOutOfMemoryError, getEncodingFromLangID, getJavaIDFromLangID
      [thread:1] scope: main.JDKLibs.javaShimDLL.link
      >> 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\cl.exe' '/FeZ:\proj\oss\lread\repro-graal-build-time-windows\target\java.dll' 'C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\hello-world.lib' msvcrt.lib /link /dll /implib:java.lib /export:JDK_LoadSystemLibrary /export:JNU_CallMethodByName /export:JNU_CallMethodByNameV /export:JNU_CallStaticMethodByName /export:JNU_ClassString /export:JNU_GetEnv /export:JNU_GetFieldByName /export:JNU_GetStaticFieldByName /export:JNU_IsInstanceOfByName /export:JNU_NewObjectByName /export:JNU_NewStringPlatform /export:JNU_SetFieldByName /export:JNU_ThrowArrayIndexOutOfBoundsException /export:JNU_ThrowByName /export:JNU_ThrowIOException /export:JNU_ThrowIllegalArgumentException /export:JNU_ThrowInternalError /export:JNU_ThrowNullPointerException /export:JNU_ThrowOutOfMemoryError /export:getEncodingFromLangID /export:getJavaIDFromLangID
      ># Microsoft (R) C/C++ Optimizing Compiler Version 19.29.30136 for x64
      ># Copyright (C) Microsoft Corporation.  All rights reserved.
      >#
      ># Microsoft (R) Incremental Linker Version 14.29.30136.0
      ># Copyright (C) Microsoft Corporation.  All rights reserved.
      >#
      ># /out:Z:\proj\oss\lread\repro-graal-build-time-windows\target\java.dll
      ># /dll
      ># /implib:java.lib
      ># /export:JDK_LoadSystemLibrary
      ># /export:JNU_CallMethodByName
      ># /export:JNU_CallMethodByNameV
      ># /export:JNU_CallStaticMethodByName
      ># /export:JNU_ClassString
      ># /export:JNU_GetEnv
      ># /export:JNU_GetFieldByName
      ># /export:JNU_GetStaticFieldByName
      ># /export:JNU_IsInstanceOfByName
      ># /export:JNU_NewObjectByName
      ># /export:JNU_NewStringPlatform
      ># /export:JNU_SetFieldByName
      ># /export:JNU_ThrowArrayIndexOutOfBoundsException
      ># /export:JNU_ThrowByName
      ># /export:JNU_ThrowIOException
      ># /export:JNU_ThrowIllegalArgumentException
      ># /export:JNU_ThrowInternalError
      ># /export:JNU_ThrowNullPointerException
      ># /export:JNU_ThrowOutOfMemoryError
      ># /export:getEncodingFromLangID
      ># /export:getJavaIDFromLangID
      ># C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\hello-world.lib
      ># msvcrt.lib
      ># LINK : fatal error LNK1181: cannot open input file 'C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\hello-world.lib'
[target/hello-world:9136]        write:     881.81 ms,  2.95 GB
Fatal error:com.oracle.svm.core.util.VMError$HostedError: should not reach here
        at com.oracle.svm.core.util.VMError.shouldNotReachHere(VMError.java:64)
        at com.oracle.svm.hosted.jdk.JNIRegistrationSupport.makeShimDLL(JNIRegistrationSupport.java:256)
        at com.oracle.svm.hosted.jdk.JNIRegistrationSupport.makeShimDLLs(JNIRegistrationSupport.java:230)
        at com.oracle.svm.hosted.jdk.JNIRegistrationSupport.afterImageWrite(JNIRegistrationSupport.java:175)
        at com.oracle.svm.hosted.NativeImageGenerator.lambda$doRun$8(NativeImageGenerator.java:663)
        at com.oracle.svm.hosted.FeatureHandler.forEachFeature(FeatureHandler.java:73)
        at com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:663)
        at com.oracle.svm.hosted.NativeImageGenerator.run(NativeImageGenerator.java:488)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.buildImage(NativeImageGeneratorRunner.java:403)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.build(NativeImageGeneratorRunner.java:569)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.main(NativeImageGeneratorRunner.java:122)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner$JDK9Plus.main(NativeImageGeneratorRunner.java:599)
[target/hello-world:9136]      [total]:  98,692.63 ms,  2.89 GB
# Printing build artifacts to: Z:\proj\oss\lread\repro-graal-build-time-windows\target\hello-world.build_artifacts.txtError: Image build request failed with exit status 1
com.oracle.svm.driver.NativeImage$NativeImageError: Image build request failed with exit status 1
        at com.oracle.svm.driver.NativeImage.showError(NativeImage.java:1762)
        at com.oracle.svm.driver.NativeImage.build(NativeImage.java:1473)
        at com.oracle.svm.driver.NativeImage.performBuild(NativeImage.java:1434)
        at com.oracle.svm.driver.NativeImage.main(NativeImage.java:1421)
-[Running produced image]
Hello, running tests in sample namespace.

Testing hello-world.sample-test

Ran 1 tests containing 1 assertions.
0 failures, 0 errors.
All done.

Observations from a guy who is out of his depth here:

The 2nd to last call has this:

>#    Creating library C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\target\hello-world.lib and object C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\target\hello-world.exp

The last spawn of cl.exe fails with:

># LINK : fatal error LNK1181: cannot open input file 'C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\hello-world.lib'

Is the fact that these do not match relevant?:
1. C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\target\hello-world.lib
2. C:\Users\lee\AppData\Local\Temp\SVM-16371069609590316844\hello-world.lib

Also, a reminder: although the last cl.exe failed, an .exe was produced that does seem to run correctly as evidenced by:

-[Running produced image]
Hello, running tests in sample namespace.

Testing hello-world.sample-test

Ran 1 tests containing 1 assertions.
0 failures, 0 errors.
All done.

galderz commented 2 years ago

@lread Thanks for posting debug log information. Your error looks different to the one I mentioned earlier. I don't know what causes your issue.

lread commented 2 years ago

Thanks for the tips and interest @galderz!

lread commented 2 years ago

@fernando-valdez, I have some good news: I have found the cause of the failure.

I use the native-image -H:Name option to specify my target executable.

My usage included a target dir: -H:Name=target/hello-world.

When running under Windows it seems that some native-image components recognize that -H:Name can include a directory and others do not. And/or some components recognize the forward slash as a path separator on Windows and others do not.

When I employed --initialize-at-build-time with args, I evidently evoked some different native-image components, hence the triggering of the failure on Windows.

My solution is to not specify any directory component in -H:Name. I instead specify the directory with -H:Path. So instead of -H:Name=target/hello-world, I now have -H:Path=target -H:Name=hello-world.

I tested the changes to my repro repo in this branch which has the following differences from the main branch. The ephemeral evidence of this passing can be found in GitHub Actions results.

I do see some current docs that describe -H:Name and -H:Path. I wonder if something more could be done to avoid this misuse (if that's what it was), of -H:Name. Ideas:

Stress proper usage in docs
Stress proper usage in native-image --expert-options help.
Fail fast on improper usage
Or... Allow and support directory within -H:Name

oracle / graal

native-image fails only on Windows when using --initialize-at-build-time with args #3882