-------- Forwarded Message --------
Subject: Re: AOT'd SystemModules.modules() fails to load when too large
Date: Mon, 12 Dec 2016 10:49:18 +0300
From: Dmitry Chuyko <dmitry.chuyko@oracle.com>
To: Claes Redestad <claes.redestad@oracle.com>, Mandy Chung <mandy.chung@oracle.com>, Alan Bateman <Alan.Bateman@oracle.com>, Dean Long <dean.long@oracle.com>


On 12/12/2016 02:48 AM, Claes Redestad wrote:
> Hi guys,
>
> last week I had Dmitry visit Stockholm to work on integrating
> semi-automated AOT testing into aurora.se.oracle.com, and as it happens
> we took a look at why AOT fails to provide any speedup on Hello World -
> in fact there's even a slight regression on some systems when looking
> at real time (I realize the subject somewhat spoils a good story...).
>
> Now, one hammer I had laying around was to run a fastdebug AOT build
> with -XX:+TraceBytecodes enabled, since any time the AOT code switches
> to the interpreter and back is sure to be quite costly (orders of
> magnitude more than simply executing another bytecode)...
>
> ... and the experiment showed a minor surprise: the only method that's
> executed in the interpreter is SystemModules.modules(), and by my
> estimate we do around 10 000 transitions between AOT compiled code and
> interpreter in this method alone, which might add up to quite a few
> milliseconds.
>
> So, why does this happen for this particular method? Well, we quickly
> ruled out various silly things ("maybe it's not using jrt:/?"), and got
> it down to a few far-fetched ideas such as "maybe AOT doesn't cope with
> really big methods?" and "maybe it needs the class major version to be
> 53/the same as the one in the jmod to generate a correct
> fingerprint?".
>
> At least the first idea is easy to put to the test by generating a
> minimal image - which should generate a much smaller
> SystemModules.modules method - and see if the method is interpreted
> or not:
>
> bin/jlink --module-path .. --add-modules java.base,jdk.aot --output
> jdk.aot
>
> cd jdk.aot
>
> bin/jaotc -J-XX:+UnlockCommercialFeatures
> -J-XX:+UnlockExperimentalVMOptions -J-XX:-UseAOT -J-Xmx4g --info
> --module java.base
>
> bin/java -XX:+UseAOT -XX:AOTLibrary=./unnamed.so -XX:+TraceBytecodes
> -version
>
> java version "9-internal"
> Java(TM) SE Runtime Environment (fastdebug build
> 9-internal+0-2016-12-08-151426.clredest.aot)
> Java HotSpot(TM) 64-Bit Server VM (fastdebug build
> 9-internal+0-2016-12-08-151426.clredest.aot, mixed mode, aot)
> 0 bytecodes executed in 0.2s (0.000MHz)
> [BytecodeCounter::counter_value = 0]
>
> The only way I can interpret this is that if the modules() method is
> small enough, AOT deals with it effortlessly.
>
> I think we need to acknowledge that this is an issue with the
> interaction between AOT and the way jigsaw works (it's understandable
> that no-one in the AOT project caught this early since it's been under
> development in parallel to jigsaw for quite some time).
>
> One obvious way to fix it from our side is to refactor the modules()
> method into chunks, which of course might become messy since it's all
> generated code. Another - perhaps easier? - fix would be to add an
> exception into the AOT code to allow this one method to be huge.
>
> Dmitry, I assume this might be kind of important to the AOT project
> since it blocks the AOT project from showing any promise of speeding
> up small apps (which is kind of the whole point of the project), correct?
Yes, it's important at least for HelloWorld-sized programs.

Tried with pre-integration 2016-12-10-015803.vkozlov.aot_graal_final:

$ 2016-12-10-fastdebug/bin/java -XX:+TraceBytecodes -XX:+UseAOT -XX:AOTLibrary=./2016-12-10-fastdebug/libjava.base-coop.so test.HelloWorld | grep SystemModules | grep -v getstatic

[7394] static jobject jdk.internal.module.SystemModules.modules()


$ 2016-12-10-fastdebug/bin/java -XX:+UnlockDiagnosticVMOptions -Xlog:aot+class+fingerprint=trace -XX:+UseAOT -XX:AOTLibrary=./2016-12-10-fastdebug/libjava.base-coop.so test.HelloWorld
<empty output>


$ 2016-12-10-fastdebug/bin/java -XX:+UnlockDiagnosticVMOptions -XX:+UseAOTStrictLoading -XX:+PrintAOT -XX:+UseAOT -XX:AOTLibrary=./2016-12-10-fastdebug/libjava.base-coop.so test.HelloWorld | grep SystemModules
    260 5460 aot[ 1] jdk.internal.module.SystemModules.<clinit>()V

We also see that SystemModules.modules() is aot'ed as part of java.base.

-Dmitry
>
> Thanks!
>
> /Claes