Debug info generation fails in combination with -O0 flag

[CRefice]

Trying to build the "helloworld" image with debug info and with an optimization level of 0 leads to a failing assertion during debug info installation, presumably due to the lack of AOT inlining.

Steps to reproduce the issue
This failure is most easily reproducible with mx. Check the full log for the list of flags passed to native-image.

1. git clone https://github.com/oracle/graal.git
2. cd graal/substratevm
3. mx build
4. mx debuginfotest -O0

Tested with:

• GraalVM CE built from source (commit ID 7be05d70eb2)
• JDK 17
• OS: Ubuntu 21.10
• Architecture: AMD64

Full build log and stacktrace

parent=/home/carlo/work/graal/substratevm
sourcepath=/home/carlo/work/graal/substratevm/src/com.oracle.svm.test/src
sourcecache=/home/carlo/work/graal/substratevm/svmbuild/sources
native_image ['--native-image-info', '-H:Path=/home/carlo/work/graal/substratevm/svmbuild', '-H:+VerifyNamingConventions', '-cp', '/home/carlo/.mx/cache/HAMCREST_42a25dc3219429f0e5d060061f71acb49bf010a0/hamcrest.jar:/home/carlo/.mx/cache/JUNIT_2973d150c0dc1fefe998f834810d68f278ea58ec/junit.jar:/home/carlo/work/mx/mxbuild/jdk17/dists/jdk9/junit-tool.jar:/home/carlo/work/graal/sdk/mxbuild/jdk17/dists/jdk17/graal-sdk.jar:/home/carlo/work/graal/truffle/mxbuild/jdk17/dists/jdk17/truffle-api.jar:/home/carlo/work/graal/compiler/mxbuild/jdk17/dists/jdk17/graal.jar:/home/carlo/work/graal/substratevm/mxbuild/jdk17/dists/jdk11/objectfile.jar:/home/carlo/work/graal/substratevm/mxbuild/jdk17/dists/jdk11/native-image-base.jar:/home/carlo/work/graal/substratevm/mxbuild/jdk17/dists/jdk11/pointsto.jar:/home/carlo/work/graal/substratevm/mxbuild/jdk17/dists/jdk17/svm.jar:/home/carlo/work/graal/substratevm/mxbuild/jdk17/com.oracle.svm.test/bin', '-Dgraal.LogFile=graal.log', '-g', '-H:-OmitInlinedMethodDebugLineInfo', '-H:DebugInfoSourceSearchPath=/home/carlo/work/graal/substratevm/src/com.oracle.svm.test/src', '-H:DebugInfoSourceCacheRoot=/home/carlo/work/graal/substratevm/svmbuild/sources', 'hello.Hello', '-O0', '-Dllvm.bin.dir=/home/carlo/work/graal/sdk/mxbuild/linux-amd64/LLVM_TOOLCHAIN/bin/', '-H:+SpawnIsolates']
Warning: Invalid option --add-exports org.graalvm.nativeimage.builder/com.oracle.svm.core.containers=ALL-UNNAMED provided by file:///home/carlo/work/graal/substratevm/mxbuild/jdk17/com.oracle.svm.test/bin/META-INF/native-image/com.oracle.svm.test/native-image.properties. Specified module 'org.graalvm.nativeimage.builder' is unknown.
========================================================================================================================
GraalVM Native Image: Generating 'hello.hello'...
========================================================================================================================
[1/7] Initializing...                                                                                    (3.1s @ 0.26GB)
 Version info: 'GraalVM dev Java 17 CE'
 4 user-provided feature(s)
  - com.oracle.svm.test.AbstractServiceLoaderTest$TestFeature
  - com.oracle.svm.test.NativeImageResourceFileSystemProviderTest$RegisterResourceFeature
  - com.oracle.svm.test.NoProviderConstructorServiceLoaderTest$TestFeature
  - com.oracle.svm.test.SerializationRegistrationTestFeature
# Printing compilation-target information to: /home/carlo/work/graal/substratevm/svmbuild/reports/target_info_20220131_153809.txt
[2/7] Performing analysis...  [********]                                                                (20.4s @ 1.04GB)
# Printing native-library information to: /home/carlo/work/graal/substratevm/svmbuild/reports/native_library_info_20220131_153829.txt
   3,779 (77.81%) of  4,857 classes reachable
   4,762 (54.53%) of  8,733 fields reachable
  17,789 (48.09%) of 36,991 methods reachable
      52 classes,    65 fields, and   687 methods registered for reflection
      58 classes,    59 fields, and    51 methods registered for JNI access
[3/7] Building universe...                                                                               (1.0s @ 1.51GB)
[4/7] Parsing methods...      [*]                                                                        (1.7s @ 0.72GB)
[5/7] Inlining methods...     (skipped)
[6/7] Compiling methods...    [****]                                                                    (12.4s @ 3.31GB)
Found
[7/7] Creating image...
Fatal error: com.oracle.svm.core.util.VMError$HostedError: java.lang.AssertionError
        at com.oracle.svm.core.util.VMError.shouldNotReachHere(VMError.java:72)
        at com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:661)
        at com.oracle.svm.hosted.NativeImageGenerator.run(NativeImageGenerator.java:498)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.buildImage(NativeImageGeneratorRunner.java:423)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.build(NativeImageGeneratorRunner.java:598)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner.main(NativeImageGeneratorRunner.java:128)
        at com.oracle.svm.hosted.NativeImageGeneratorRunner$JDK9Plus.main(NativeImageGeneratorRunner.java:628)
Caused by: java.lang.AssertionError
        at com.oracle.objectfile.debugentry.DebugInfoBase.recursivelyAddSubRanges(DebugInfoBase.java:362)
        at com.oracle.objectfile.debugentry.DebugInfoBase.recursivelyAddSubRanges(DebugInfoBase.java:364)
        at com.oracle.objectfile.debugentry.DebugInfoBase.recursivelyAddSubRanges(DebugInfoBase.java:364)
        at com.oracle.objectfile.debugentry.DebugInfoBase.lambda$installDebugInfo$4(DebugInfoBase.java:258)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
        at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
        at com.oracle.objectfile.debugentry.DebugInfoBase.lambda$installDebugInfo$5(DebugInfoBase.java:258)
        at com.oracle.svm.hosted.image.NativeImageDebugInfoProvider$NativeImageDebugCodeInfo.debugContext(NativeImageDebugInfoProvider.java:850)
        at com.oracle.objectfile.debugentry.DebugInfoBase.lambda$installDebugInfo$6(DebugInfoBase.java:236)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.TreeMap$EntrySpliterator.forEachRemaining(TreeMap.java:3287)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
        at com.oracle.objectfile.debugentry.DebugInfoBase.installDebugInfo(DebugInfoBase.java:236)
        at com.oracle.objectfile.elf.ELFObjectFile.installDebugInfo(ELFObjectFile.java:1201)
        at com.oracle.svm.hosted.image.NativeImage.build(NativeImage.java:474)
        at com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:649)
        ... 5 more
------------------------------------------------------------------------------------------------------------------------
                        1.9s (4.2% of total time) in 26 GCs | Peak RSS: 5.67GB | CPU load: 8.98
------------------------------------------------------------------------------------------------------------------------
Produced artifacts:
 /home/carlo/work/graal/substratevm/svmbuild/hello.hello.build_artifacts.txt
========================================================================================================================
Failed generating 'hello.hello' after 43.9s.
Error: Image build request failed with exit status 1

[CRefice]

CC @adinn

[adinn]

Hi @CRefice Thaks for reporting this.

a failing assertion during debug info installation, presumably due to the lack of AOT inlining

Actually, no that's not the issue. The problem here is that debug info generator is expecting (well, actually, asserting) that any of the reported compiled method code subranges that has no caller belongs to the top level compiled method. It is indeed true that any subrange that consists of top level method code does report null for its caller. However, I have recently noticed that some injected snippets are appearing as top-level code ranges with no caller. I suspect that may be what is causing the problem here.

Note that it is not necessary to pass -O0 in order to observe this problem. This appears to be a change in the way the source/info node position information for snippets (at least, if not for other cases) is being recorded. I am currently investigating this issue and will let you know as soon as I find out what is happening.

Just as a point of interest though I need to mention that even if this issue is fixed the debug info test is unlikely to succeed when run with option -O0. The test checks various aspects of program execution in the debugger and that includes points at which execution stops and associated stack backtraces. The precise points and number of times where/when a break occurs and the stack frames visible at the break are very likely to change if you specify -O0and this will very likely cause the test to fail.

[olpaw]

Just as a point of interest though I need to mention that even if this issue is fixed the debug info test is unlikely to succeed when run with option -O0.

That's fine. No one can expect that your carefully crafted debuginfo tests to magically pass when being executed with a different optimization level.

Running into an assert during buildtime (triggered by using -O0 or by other means) needs to be fixed though.