jaotc: unexpected long compile time for a 3012-byte generated class

Tianxiao Gu tianxiao.gu at gmail.com
Mon Jan 29 07:29:13 UTC 2018


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-ser
>> ver-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/3d00ff7781fd63da2af576c
>> cb7594db7cb39373b/compiler/src/org.graalvm.compiler.core.
>> test/src/org/graalvm/compiler/core/test/UnbalancedMonitorsTest.java
>> https://github.com/oracle/graal/blob/2401c47b18c88317f0d2476
>> e183cb7be65ce242d/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,o
>> rg.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.Edg
>> es.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,o
>> rg.graalvm.compiler.graph.Edges::getNodeListUnsafe  C0
>> > CompileCommand: exclude org/graalvm/compiler/graph/Edg
>> es.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;Lj
>> ava/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.ge
>> tNodeListUnsafe(Edges.java:71)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.graph.NodeClas
>> s$RawEdgesIterator.getInput(NodeClass.java:1041)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.graph.NodeClas
>> s$RawEdgesIterator.forward(NodeClass.java:981)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.graph.NodeClas
>> s$RawEdgesIterator.hasNext(NodeClass.java:974)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.schedul
>> e.SchedulePhase$Instance.scheduleEarliestIterative(ScheduleP
>> hase.java:743)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.schedul
>> e.SchedulePhase$Instance.run(SchedulePhase.java:167)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.schedul
>> e.SchedulePhase.run(SchedulePhase.java:126)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.Phase.r
>> un(Phase.java:47)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePha
>> se.apply(BasePhase.java:195)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.Phase.a
>> pply(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.BasePha
>> se.apply(BasePhase.java:195)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePha
>> se.apply(BasePhase.java:137)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.PhaseSu
>> ite.run(PhaseSuite.java:203)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePha
>> se.apply(BasePhase.java:195)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.phases.BasePha
>> se.apply(BasePhase.java:137)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.core.GraalComp
>> iler.emitFrontEnd(GraalCompiler.java:229)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.core.GraalComp
>> iler.compile(GraalCompiler.java:172)
>> >       at jdk.internal.vm.compiler/org.graalvm.compiler.core.GraalComp
>> iler.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(AOTCompilatio
>> nTask.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.Edg
>> es.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/Edg
>> es.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/graa
>> lvm/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 graal-dev mailing list