jaotc: unexpected long compile time for a 3012-byte generated class
Doug Simon
doug.simon at oracle.com
Mon Jan 29 09:55:47 UTC 2018
I think I using a different C0.class than you based on the output from jaotc:
(yours) added M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
(mine) added M2([Ljava/lang/Number;[CLjava/lang/Comparable;[F[Ljava/lang/Character;[S)Z
I was using the one from https://github.com/oracle/graal/issues/290 but now see you're probably referring to the one at https://drive.google.com/drive/folders/1u9O3uPkvucX6PWQkMFER3NAUWIR_KglE. Sorry for the confusion.
Can you please open a separate github issue for this particular C0.class and attach it to the issue so that we avoid this kind of confusion in future.
-Doug
> On 29 Jan 2018, at 08:29, Tianxiao Gu <tianxiao.gu at gmail.com> wrote:
>
> Hi Doug,
>
> I can still reproduce it with OpenJDK head (http://hg.openjdk.java.net/jdk/hs/) and the nightly build from (https://adoptopenjdk.net/nightly.html?variant=openjdk10).
>
> Maybe you can use a larger InlineDuringParsingMaxDepth (e.g., 9 or 10) or disable -Xcomp. Give me some time I will try to create a Graal test case.
>
> tianxiaogu@~/Projects/hs >>> hg path
> default = http://hg.openjdk.java.net/jdk/hs/
> tianxiaogu@~/Projects/hs >>> hg id
> f43576cfb273+ tip
>
>
> tianxiaogu@~/Dropbox/OpenJDK/jaotc/LongCompileTime1 >>> ~/Projects/hs/build/macosx-x86_64-normal-server-release/images/jdk/bin/jaotc --output C0.so -J-Dgraal.InlineDuringParsingMaxDepth=8 --compile-commands commands.txt --verbose C0.class
>
> Compiling C0.so...
> 1 classes found (87 ms)
> Scanning C0
> added M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
> 7 methods total, 1 methods to compile (13 ms)
> Freeing memory [used: 2.2 MB , comm: 8.0 MB , freeRatio ~= 72.4%] (67 ms)
> Compiling with 4 threads
> .Error: Failed compilation: C0.M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V: java.lang.NullPointerException
> java.lang.NullPointerException
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.getInput(NodeClass.java:1042)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.forward(NodeClass.java:981)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.hasNext(NodeClass.java:974)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.schedule.SchedulePhase$Instance.scheduleEarliestIterative(SchedulePhase.java:743)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.schedule.SchedulePhase$Instance.run(SchedulePhase.java:167)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.schedule.SchedulePhase.run(SchedulePhase.java:126)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.Phase.run(Phase.java:47)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.Phase.apply(Phase.java:40)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.virtual.phases.ea.EffectsPhase.runAnalysis(EffectsPhase.java:87)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.virtual.phases.ea.PartialEscapePhase.run(PartialEscapePhase.java:80)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.virtual.phases.ea.PartialEscapePhase.run(PartialEscapePhase.java:42)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:137)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.PhaseSuite.run(PhaseSuite.java:203)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:137)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.core.GraalCompiler.emitFrontEnd(GraalCompiler.java:229)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.core.GraalCompiler.compile(GraalCompiler.java:172)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.core.GraalCompiler.compileGraph(GraalCompiler.java:158)
> at jdk.aot/jdk.tools.jaotc.AOTBackend.compileGraph(AOTBackend.java:141)
> at jdk.aot/jdk.tools.jaotc.AOTBackend.compileMethod(AOTBackend.java:103)
> at jdk.aot/jdk.tools.jaotc.AOTCompilationTask.run(AOTCompilationTask.java:121)
> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
> at java.base/java.lang.Thread.run(Thread.java:844)
>
> failed M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
>
> 0 methods compiled, 1 methods failed (275627 ms)
> Freeing memory [used: 368.0 MB, comm: 765.0 MB, freeRatio ~= 51.9%] (63 ms)
> Parsing compiled code (1 ms)
> Freeing memory [used: 7.3 MB , comm: 17.0 MB, freeRatio ~= 57.0%] (17 ms)
> Processing metadata (49 ms)
> Freeing memory [used: 4.9 MB , comm: 17.0 MB, freeRatio ~= 71.3%] (21 ms)
> Preparing stubs binary (1 ms)
> Preparing compiled binary (0 ms)
> .header: 65 bytes
> .config: 40 bytes
> .kls.offsets: 0 bytes
> .meth.offsets: 0 bytes
> .kls.dependencies: 0 bytes
> .stubs.offsets: 964 bytes
> .meth.metadata: 6792 bytes
> .text: 21344 bytes
> .code.segments: 165 bytes
> .meth.constdata: 29152 bytes
> .kls.got: 0 bytes
> .cnt.got: 0 bytes
> .meta.got: 0 bytes
> .meth.state: 320 bytes
> .oop.got: 0 bytes
> .meta.names: 1874 bytes
> Freeing memory [used: 4.9 MB , comm: 17.0 MB, freeRatio ~= 71.3%] (21 ms)
> Creating binary: C0.so.o (29 ms)
> Freeing memory [used: 4.9 MB , comm: 17.0 MB, freeRatio ~= 71.3%] (47 ms)
> Creating shared library: C0.so (70 ms)
> Final memory [used: 4.8 MB , comm: 17.0 MB, freeRatio ~= 72.1%]
> Total time: 277417 ms
>
>
> Nightly build: jdk-10+23-20, 26 January 2018, macOS x64
>
> https://github.com/AdoptOpenJDK/openjdk10-nightly/releases/download/jdk-10%2B23-20182601/OpenJDK10_x64_Mac_20182601.tar.gz
>
> tianxiaogu@~/Dropbox/OpenJDK/jaotc/LongCompileTime1 >>> ~/Downloads/jdk-10+23/bin/jaotc --output C0.so -J-Dgraal.InlineDuringParsingMaxDepth=8 --compile-commands commands.txt --verbose C0.class
> Compiling C0.so...
> 1 classes found (52 ms)
> Scanning C0
> added M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
> 7 methods total, 1 methods to compile (10 ms)
> Freeing memory [used: 2.2 MB , comm: 8.0 MB , freeRatio ~= 72.2%] (34 ms)
> Compiling with 4 threads
> .Error: Failed compilation: C0.M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V: java.lang.NullPointerException
> java.lang.NullPointerException
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.getInput(NodeClass.java:1042)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.forward(NodeClass.java:981)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.hasNext(NodeClass.java:974)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.schedule.SchedulePhase$Instance.scheduleEarliestIterative(SchedulePhase.java:743)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.schedule.SchedulePhase$Instance.run(SchedulePhase.java:167)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.schedule.SchedulePhase.run(SchedulePhase.java:126)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.Phase.run(Phase.java:47)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.Phase.apply(Phase.java:40)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.virtual.phases.ea.EffectsPhase.runAnalysis(EffectsPhase.java:87)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.virtual.phases.ea.PartialEscapePhase.run(PartialEscapePhase.java:80)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.virtual.phases.ea.PartialEscapePhase.run(PartialEscapePhase.java:42)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:137)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.PhaseSuite.run(PhaseSuite.java:203)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:137)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.core.GraalCompiler.emitFrontEnd(GraalCompiler.java:229)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.core.GraalCompiler.compile(GraalCompiler.java:172)
> at jdk.internal.vm.compiler at 10-internal/org.graalvm.compiler.core.GraalCompiler.compileGraph(GraalCompiler.java:158)
> at jdk.aot/jdk.tools.jaotc.AOTBackend.compileGraph(AOTBackend.java:140)
> at jdk.aot/jdk.tools.jaotc.AOTBackend.compileMethod(AOTBackend.java:102)
> at jdk.aot/jdk.tools.jaotc.AOTCompilationTask.run(AOTCompilationTask.java:121)
> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
> at java.base/java.lang.Thread.run(Thread.java:844)
>
> failed M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
>
> 0 methods compiled, 1 methods failed (140875 ms)
> Freeing memory [used: 380.0 MB, comm: 2.0 GB , freeRatio ~= 81.0%] (180 ms)
> Parsing compiled code (1 ms)
> Freeing memory [used: 5.0 MB , comm: 10.0 MB, freeRatio ~= 49.8%] (33 ms)
> Processing metadata (37 ms)
> Freeing memory [used: 4.8 MB , comm: 10.0 MB, freeRatio ~= 52.0%] (39 ms)
> Preparing stubs binary (2 ms)
> Preparing compiled binary (0 ms)
> .header: 67 bytes
> .config: 39 bytes
> .kls.offsets: 0 bytes
> .meth.offsets: 0 bytes
> .kls.dependencies: 0 bytes
> .stubs.offsets: 940 bytes
> .meth.metadata: 6616 bytes
> .text: 21080 bytes
> .code.segments: 163 bytes
> .meth.constdata: 29152 bytes
> .kls.got: 0 bytes
> .cnt.got: 0 bytes
> .meta.got: 0 bytes
> .meth.state: 312 bytes
> .oop.got: 0 bytes
> .meta.names: 1826 bytes
> Freeing memory [used: 4.8 MB , comm: 10.0 MB, freeRatio ~= 52.0%] (71 ms)
> Creating binary: C0.so.o (91 ms)
> Freeing memory [used: 4.8 MB , comm: 10.0 MB, freeRatio ~= 52.1%] (47 ms)
> Creating shared library: C0.so (75 ms)
> Final memory [used: 4.7 MB , comm: 10.0 MB, freeRatio ~= 53.4%]
> Total time: 142749 ms
>
>
> On Sun, Jan 28, 2018 at 10:58 AM, Tianxiao Gu <tianxiao.gu at gmail.com> wrote:
> Hi Doug,
>
> Thank you very much for your feedback. I will try to create a Graal unit test and also reproduce the crash on my Mac.
>
> 1. The OpenJDK head I used is built from the repo at http://hg.openjdk.java.net/jdk/jdk/.
> 2. My computer used for testing is Ubuntu 16.04. The output of `uname -a` is:
>
> Linux xtiger 4.10.0-42-generic #46~16.04.1-Ubuntu SMP Mon Dec 4 15:57:59 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
>
>
> On Sun, Jan 28, 2018 at 4:23 AM, Doug Simon <doug.simon at oracle.com> wrote:
> Hi Tianxiao,
>
> Thanks for the detailed bug report.
>
> By OpenJDK, which repo do you mean? I've tried to reproduce with the tip of http://hg.openjdk.java.net/jdk/hs on my Mac but with no luck so far:
>
> dsimon at kruger-4 ~/j/open> hg path
> default = http://hg.openjdk.java.net/jdk/hs
> default-push = ssh://dnsimon@hg.openjdk.java.net/jdk/hs
> dsimon at kruger-4 ~/j/open> hg id
> f43576cfb273 tip
> dsimon at kruger-4 ~/j/open> sh configure --disable-warnings-as-errors
> dsimon at kruger-4 ~/j/open> make CONF=macosx-x86_64-normal-server-release images
> dsimon at kruger-4 ~/j/open> shasum C0.class
> fc436e1bb82f9d6193177131b1130c44ba61dce2 C0.class
> dsimon at kruger-4 ~/j/open> cat commands.txt
> compileOnly C0.M2.*
> dsimon at kruger-4 ~/j/open> build/macosx-x86_64-normal-server-release/images/jdk/bin/jaotc --output C0.so --compile-commands commands.txt -J-Xcomp --verbose -J-Dgraal.InlineDuringParsingMaxDepth=8 -J-Xcomp C0.class
> Compiling C0.so...
> 1 classes found (1374 ms)
> Scanning C0
> added M2([Ljava/lang/Number;[CLjava/lang/Comparable;[F[Ljava/lang/Character;[S)Z
> 6 methods total, 1 methods to compile (159 ms)
> Freeing memory [used: 2,4 MB , comm: 8,0 MB , freeRatio ~= 70,5%] (552 ms)
> Compiling with 8 threads
> .
> 1 methods compiled, 0 methods failed (3988 ms)
> Freeing memory [used: 4,2 MB , comm: 8,0 MB , freeRatio ~= 47,1%] (32 ms)
> Parsing compiled code (22 ms)
> Freeing memory [used: 5,4 MB , comm: 10,0 MB, freeRatio ~= 45,7%] (35 ms)
> Processing metadata (164 ms)
> Freeing memory [used: 5,4 MB , comm: 14,0 MB, freeRatio ~= 61,7%] (36 ms)
> Preparing stubs binary (2 ms)
> Preparing compiled binary (6 ms)
> .header: 63 bytes
> .config: 40 bytes
> .kls.offsets: 48 bytes
> .meth.offsets: 28 bytes
> .kls.dependencies: 12 bytes
> .stubs.offsets: 964 bytes
> .meth.metadata: 7000 bytes
> .text: 21624 bytes
> .code.segments: 167 bytes
> .meth.constdata: 29152 bytes
> .kls.got: 32 bytes
> .cnt.got: 0 bytes
> .meta.got: 8 bytes
> .meth.state: 328 bytes
> .oop.got: 0 bytes
> .meta.names: 1962 bytes
> Freeing memory [used: 5,4 MB , comm: 14,0 MB, freeRatio ~= 61,8%] (47 ms)
> Creating binary: C0.so.o (151 ms)
> Freeing memory [used: 5,3 MB , comm: 14,0 MB, freeRatio ~= 61,8%] (41 ms)
> Creating shared library: C0.so (31 ms)
> Final memory [used: 5,2 MB , comm: 14,0 MB, freeRatio ~= 62,9%]
> Total time: 15784 ms
>
>
> In terms of errors on 9.0.4, that version of Graal is now quite old and there's a good chance the issue has been fixed since then.
>
> In terms of C2 crashing, that's something for the HotSpot compiler team to look at.
>
> For these kinds of issues, it's really helpful if you can make a Graal unit test out of it. That allows us to test it against recent Graal and also ensure we don't regress. How do you generate these test classes? If it's with the ASM library, then you can see how it is used by other Graal unit tests:
>
> https://github.com/oracle/graal/blob/3d00ff7781fd63da2af576ccb7594db7cb39373b/compiler/src/org.graalvm.compiler.core.test/src/org/graalvm/compiler/core/test/UnbalancedMonitorsTest.java
> https://github.com/oracle/graal/blob/2401c47b18c88317f0d2476e183cb7be65ce242d/compiler/src/org.graalvm.compiler.core.test/src/org/graalvm/compiler/core/test/SubWordReturnTest.java
>
> You may also be able to express the problematic pattern in normal Java code as I could for https://github.com/oracle/graal/issues/288.
>
> -Doug
>
> > On 27 Jan 2018, at 10:16, Tianxiao Gu <tianxiao.gu at gmail.com> wrote:
> >
> > The OpenJDK head still crashes with this program. Now I can manage to reproduce the crash in about 1 min on my computer. The crash stack trace is different.
> >
> > Using the following options to start jaotc.
> >
> > 1. Add options -J-Dgraal.InlineDuringParsingMaxDepth=8 and -J-Xcomp.
> > 2. Add options --compile-commands commands.txt to jaotc, where the contents of commands.txt is
> > compileOnly C0.M2.*
> >
> > If we use CompileCommand to exclude org.graalvm.compiler.graph.Edges::getNodeListUnsafe, we get a Java stack trace.
> >
> > 3. Add option -J-XX:CompileCommand=exclude,org.graalvm.compiler.graph.Edges::getNodeListUnsafe
> >
> >
> > Summary:
> >
> > HEAD + Include: VM crashed
> > HEAD + Exclude: Java Exception
> > JDK 9.04 + Include: VM crashed
> > JDK 9.04 + Exclude: VM crashed
> >
> > I have fired a similar bug report with another program at https://github.com/oracle/graal/issues/290
> >
> > So far, we still have no idea whether this is a problem of C2 or Graal.
> >
> > === C2 (HEAD) crashes ===
> >
> > $ time ../../../openjdk/jdk/build/linux-x86_64-normal-server-release/jdk/bin/jaotc --output C0.so --verbose -J-Dgraal.InlineDuringParsingMaxDepth=8 --compile-commands commands.txt -J-Xcomp C0
> > Compiling C0.so...
> > 1 classes found (721 ms)
> > Scanning C0
> > added M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
> > 7 methods total, 1 methods to compile (173 ms)
> > Freeing memory [used: 3.7 MB , comm: 10.0 MB, freeRatio ~= 62.6%] (555 ms)
> > Compiling with 8 threads
> > .#
> > # A fatal error has been detected by the Java Runtime Environment:
> > #
> > # SIGSEGV (0xb) at pc=0x00007f3c74f57135, pid=19884, tid=19921
> > #
> > # JRE version: OpenJDK Runtime Environment (10.0) (build 10-internal+0-adhoc.t.jdk)
> > # Java VM: OpenJDK 64-Bit Server VM (10-internal+0-adhoc.t.jdk, compiled mode, tiered, jvmci, compressed oops, g1 gc, linux-amd64)
> > # Problematic frame:
> > # J 10840 c2 org.graalvm.compiler.graph.Edges.getNodeListUnsafe(Lorg/graalvm/compiler/graph/Node;J)Lorg/graalvm/compiler/graph/NodeList; jdk.internal.vm.compiler (12 bytes) @ 0x00007f3c74f57135 [0x00007f3c74f57120+0x0000000000000015]
> > #
> > # Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c %d %P" (or dumping to /home/t/Projects/JVMTesting/old-bugs/0123-old-bugs/jaotc-jdk-20180122171043/core.19884)
> > #
> > # An error report file with more information is saved as:
> > # /home/t/Projects/JVMTesting/old-bugs/0123-old-bugs/jaotc-jdk-20180122171043/hs_err_pid19884.log
> > Could not load hsdis-amd64.so; library not loadable; PrintAssembly is disabled
> > #
> > # If you would like to submit a bug report, please visit:
> > # http://bugreport.java.com/bugreport/crash.jsp
> > #
> > Aborted (core dumped)
> > real 1m14.411s
> > user 1m17.352s
> > sys 0m0.604s
> >
> > === Exclude getNodeListUnsafe ===
> >
> > $ time ../../../openjdk/jdk/build/linux-x86_64-normal-server-release/jdk/bin/jaotc --output C0.so --verbose -J-Dgraal.InlineDuringParsingMaxDepth=8 --compile-commands commands.txt -J-Xcomp -J-XX:CompileCommand=exclude,org.graalvm.compiler.graph.Edges::getNodeListUnsafe C0
> > CompileCommand: exclude org/graalvm/compiler/graph/Edges.getNodeListUnsafe
> > Compiling C0.so...
> > 1 classes found (704 ms)
> > Scanning C0
> > added M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
> > 7 methods total, 1 methods to compile (130 ms)
> > Freeing memory [used: 4.6 MB , comm: 10.0 MB, freeRatio ~= 54.2%] (792 ms)
> > Compiling with 8 threads
> > .Error: Failed compilation: C0.M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V: java.lang.NullPointerException
> > java.lang.NullPointerException
> > at jdk.internal.vm.compiler/org.graalvm.compiler.graph.Edges.getNodeListUnsafe(Edges.java:71)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.getInput(NodeClass.java:1041)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.forward(NodeClass.java:981)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.graph.NodeClass$RawEdgesIterator.hasNext(NodeClass.java:974)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.schedule.SchedulePhase$Instance.scheduleEarliestIterative(SchedulePhase.java:743)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.schedule.SchedulePhase$Instance.run(SchedulePhase.java:167)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.schedule.SchedulePhase.run(SchedulePhase.java:126)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.Phase.run(Phase.java:47)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.Phase.apply(Phase.java:40)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.virtual.phases.ea.EffectsPhase.runAnalysis(EffectsPhase.java:87)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.virtual.phases.ea.PartialEscapePhase.run(PartialEscapePhase.java:80)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.virtual.phases.ea.PartialEscapePhase.run(PartialEscapePhase.java:42)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:137)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.PhaseSuite.run(PhaseSuite.java:203)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:195)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:137)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.core.GraalCompiler.emitFrontEnd(GraalCompiler.java:229)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.core.GraalCompiler.compile(GraalCompiler.java:172)
> > at jdk.internal.vm.compiler/org.graalvm.compiler.core.GraalCompiler.compileGraph(GraalCompiler.java:158)
> > at jdk.aot/jdk.tools.jaotc.AOTBackend.compileGraph(AOTBackend.java:141)
> > at jdk.aot/jdk.tools.jaotc.AOTBackend.compileMethod(AOTBackend.java:103)
> > at jdk.aot/jdk.tools.jaotc.AOTCompilationTask.run(AOTCompilationTask.java:121)
> > at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1131)
> > at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:631)
> > at java.base/java.lang.Thread.run(Thread.java:844)
> > failed M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
> > 0 methods compiled, 1 methods failed (80228 ms)
> > Freeing memory [used: 430.5 MB, comm: 627.0 MB, freeRatio ~= 31.3%] (22 ms)
> > Parsing compiled code (3 ms)
> > Freeing memory [used: 9.8 MB , comm: 24.0 MB, freeRatio ~= 59.0%] (20 ms)
> > Processing metadata (146 ms)
> > Freeing memory [used: 6.1 MB , comm: 24.0 MB, freeRatio ~= 74.7%] (20 ms)
> > Preparing stubs binary (3 ms)
> > Preparing compiled binary (1 ms)
> > .header: 57 bytes
> > .config: 40 bytes
> > .kls.offsets: 0 bytes
> > .meth.offsets: 0 bytes
> > .kls.dependencies: 0 bytes
> > .stubs.offsets: 964 bytes
> > .meth.metadata: 6792 bytes
> > .text: 21344 bytes
> > .code.segments: 165 bytes
> > .meth.constdata: 29152 bytes
> > .kls.got: 0 bytes
> > .cnt.got: 0 bytes
> > .meta.got: 0 bytes
> > .meth.state: 320 bytes
> > .oop.got: 0 bytes
> > .meta.names: 1874 bytes
> > Freeing memory [used: 6.1 MB , comm: 24.0 MB, freeRatio ~= 74.7%] (20 ms)
> > Creating binary: C0 (74 ms)
> > Freeing memory [used: 6.1 MB , comm: 24.0 MB, freeRatio ~= 74.7%] (20 ms)
> > Creating shared library: C0.so (13 ms)
> > Final memory [used: 5.9 MB , comm: 24.0 MB, freeRatio ~= 75.3%]
> > Total time: 90239 ms
> > real 1m32.837s
> > user 1m36.420s
> > sys 0m0.792s
> >
> >
> > ================================================================================
> >
> > The crash is more easily to be reproduced in Oracle JDK 9.0.4+11 (without -J-Xcomp)
> >
> > $ time ../../../jdk-9.0.4/bin/jaotc --output C0.so --verbose -J-Dgraal.InlineDuringParsingMaxDepth=8 --compile-commands commands.txt C0
> > Compiling C0...
> > 1 classes found (451 ms)
> > Scanning C0
> > added M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
> > 7 methods total, 1 methods to compile (95 ms)
> > Freeing memory [used: 2.5 MB , comm: 8.0 MB , freeRatio ~= 68.7%] (803 ms)
> > Compiling with 8 threads
> > .#
> > # A fatal error has been detected by the Java Runtime Environment:
> > #
> > # SIGSEGV (0xb) at pc=0x00007f43717c8d35, pid=20015, tid=20049
> > #
> > # JRE version: Java(TM) SE Runtime Environment (9.0+11) (build 9.0.4+11)
> > # Java VM: Java HotSpot(TM) 64-Bit Server VM (9.0.4+11, compiled mode, tiered, jvmci, compressed oops, g1 gc, linux-amd64)
> > # Problematic frame:
> > # J 9702 c2 org.graalvm.compiler.graph.Edges.getNodeListUnsafe(Lorg/graalvm/compiler/graph/Node;J)Lorg/graalvm/compiler/graph/NodeList; jdk.internal.vm.compiler at 9.0.4 (12 bytes) @ 0x00007f43717c8d35 [0x00007f43717c8d20+0x0000000000000015]
> > #
> > # Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c %d %P" (or dumping to /home/t/Projects/JVMTesting/old-bugs/0123-old-bugs/jaotc-jdk-20180122171043/core.20015)
> > #
> > # An error report file with more information is saved as:
> > # /home/t/Projects/JVMTesting/old-bugs/0123-old-bugs/jaotc-jdk-20180122171043/hs_err_pid20015.log
> > Could not load hsdis-amd64.so; library not loadable; PrintAssembly is disabled
> > #
> > # If you would like to submit a bug report, please visit:
> > # http://bugreport.java.com/bugreport/crash.jsp
> > #
> > Aborted (core dumped)
> > real 1m17.911s
> > user 1m25.256s
> > sys 0m0.896s
> >
> >
> > === Exclude getNodeListUnsafe ===
> >
> > time ../../../jdk-9.0.4/bin/jaotc --output C0.so --verbose -J-Dgraal.InlineDuringParsingMaxDepth=8 --compile-commands commands.txt -J-XX:CompileCommand=exclude,org.graalvm.compiler.graph.Edges::getNodeListUnsafe C0
> > CompileCommand: exclude org/graalvm/compiler/graph/Edges.getNodeListUnsafe
> > Compiling C0...
> > 1 classes found (17 ms)
> > Scanning C0
> > added M2([C[SLjava/lang/Number;Ljava/lang/Number;Ljava/lang/Short;Ljava/lang/Float;SLjava/lang/Character;[F)V
> > 7 methods total, 1 methods to compile (4 ms)
> > Freeing memory [used: 2.1 MB , comm: 8.0 MB , freeRatio ~= 73.6%] (20 ms)
> > Compiling with 8 threads
> > .#
> > # A fatal error has been detected by the Java Runtime Environment:
> > #
> > # SIGSEGV (0xb) at pc=0x00007ff051b6ab29, pid=20922, tid=20956
> > #
> > # JRE version: Java(TM) SE Runtime Environment (9.0+11) (build 9.0.4+11)
> > # Java VM: Java HotSpot(TM) 64-Bit Server VM (9.0.4+11, mixed mode, aot, tiered, jvmci, compressed oops, g1 gc, linux-amd64)
> > # Problematic frame:
> > # j org.graalvm.compiler.graph.Edges.getNodeListUnsafe(Lorg/graalvm/compiler/graph/Node;J)Lorg/graalvm/compiler/graph/NodeList;+5 jdk.internal.vm.compiler at 9.0.4
> > #
> > # Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c %d %P" (or dumping to /home/t/Projects/JVMTesting/old-bugs/0123-old-bugs/jaotc-jdk-20180122171043/core.20922)
> > #
> > # An error report file with more information is saved as:
> > # /home/t/Projects/JVMTesting/old-bugs/0123-old-bugs/jaotc-jdk-20180122171043/hs_err_pid20922.log
> > Compiled method (c1) 65364 1005 1 sun.misc.Unsafe::getObject (9 bytes)
> > total in heap [0x00007ff05965cb90,0x00007ff05965cee0] = 848
> > relocation [0x00007ff05965cd00,0x00007ff05965cd28] = 40
> > main code [0x00007ff05965cd40,0x00007ff05965ce20] = 224
> > stub code [0x00007ff05965ce20,0x00007ff05965ceb0] = 144
> > scopes data [0x00007ff05965ceb0,0x00007ff05965ceb8] = 8
> > scopes pcs [0x00007ff05965ceb8,0x00007ff05965ced8] = 32
> > dependencies [0x00007ff05965ced8,0x00007ff05965cee0] = 8
> > Could not load hsdis-amd64.so; library not loadable; PrintAssembly is disabled
> > #
> > # If you would like to submit a bug report, please visit:
> > # http://bugreport.java.com/bugreport/crash.jsp
> > #
> > Aborted (core dumped)
> > real 1m5.467s
> > user 1m21.900s
> > sys 0m0.444s
> >
> >
> >
> >
> > On Wed, Jan 24, 2018 at 12:04 PM, Tianxiao Gu <tianxiao.gu at gmail.com> wrote:
> > Thanks, Doug.
> >
> > I agree with you. The fatal error indicates that the C2 compiler may generate problematic code for a method (see below) of graal, when graal itself has been driven to a crazy state by the input C0.class.
> > I will file an issue with another class that does not end with a fatal error of the runtime but still leads to a long compile time.
> >
> > Stack: [0x00007f29a22c2000,0x00007f29
> > a23c3000], sp=0x00007f29a23c06d0, free space=1017k
> > Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code)
> > J 3623% c2
> > org.graalvm.compiler.phases.schedule.SchedulePhase$Instance.scheduleEarliestIterative(Lorg/graalvm/compiler/core/common/cfg/BlockMap;Lorg/graalvm/compiler/graph/NodeMap;Lorg/graalvm/compiler/graph/NodeBitMap;Lorg/graalvm/compiler/nodes/StructuredGraph;Z)V jdk.internal.vm.compiler (999 bytes) @ 0x00007f2a04f371a2 [0x00007f2a04f368e0+0x00000000
> > 000008c2]
> > j
> >
> >
> > On Wed, Jan 24, 2018 at 3:02 AM, Doug Simon <doug.simon at oracle.com> wrote:
> > Hi Tianxiao,
> >
> > As far as I'm aware, Graal compiled code does not run during jaotc so I don't think the crash is Graal related. It's in a C2 compiled method.
> >
> > That said, the long compile time is almost certainly some issue in Graal. Looking at the class file, it seems like some inlining maybe be going crazy on the infinitely recursive C0.M0() method and I can confirm this with:
> >
> > jaotc -J-Dgraal.TraceInlineDuringParsing=true C0.class
> >
> > Can you please file an issue at https://github.com/oracle/graal/issues and we will investigate further.
> >
> > -Doug
> >
> > > On 24 Jan 2018, at 09:00, Tianxiao Gu <tianxiao.gu at gmail.com> wrote:
> > >
> > > Hi All,
> > >
> > > I found some abnormal behavior of jaotc. It takes 23 minutes for jaotc (head) to compile a 3012-byte generated class file (C0.class)
> > > and jaotc ends with a fatal error. I have managed to reproduce this issue on my machine for 4 times.
> > >
> > > Related files are hosted on Google Drive:
> > >
> > > https://drive.google.com/open?id=1u9O3uPkvucX6PWQkMFER3NAUWIR_KglE
> > >
> > > Reproducing Steps:
> > >
> > > jaotc --output C0.so C0.class
> > >
> > > Environment:
> > >
> > > `java --version`
> > >
> > > openjdk 10-internal 2018-03-20
> > > OpenJDK Runtime Environment (build 10-internal+0-adhoc.t.jdk)
> > > OpenJDK 64-Bit Server VM (build 10-internal+0-adhoc.t.jdk, mixed mode)
> > >
> > > `lscpu`
> > >
> > > Architecture: x86_64
> > > CPU op-mode(s): 32-bit, 64-bit
> > > Byte Order: Little Endian
> > > CPU(s): 8
> > > On-line CPU(s) list: 0-7
> > > Thread(s) per core: 2
> > > Core(s) per socket: 4
> > > Socket(s): 1
> > > NUMA node(s): 1
> > > Vendor ID: GenuineIntel
> > > CPU family: 6
> > > Model: 158
> > > Model name: Intel(R) Core(TM) i7-7700 CPU @ 3.60GHz
> > > Stepping: 9
> > > CPU MHz: 900.000
> > > CPU max MHz: 4200.0000
> > > CPU min MHz: 800.0000
> > > BogoMIPS: 7200.00
> > > Virtualization: VT-x
> > > L1d cache: 32K
> > > L1i cache: 32K
> > > L2 cache: 256K
> > > L3 cache: 8192K
> > > NUMA node0 CPU(s): 0-7
> > > Flags: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch epb intel_pt tpr_shadow vnmi flexpriority ept vpid fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm mpx rdseed adx smap clflushopt xsaveopt xsavec xgetbv1 xsaves dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp
> > >
> > > `uname -a`
> > >
> > > Linux xtiger 4.10.0-42-generic #46~16.04.1-Ubuntu SMP Mon Dec 4 15:57:59 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
> >
> >
> >
>
>
>
More information about the hotspot-compiler-dev
mailing list