Performance issues
A. Sundararajan
sundararajan.athijegannathan at oracle.com
Thu Feb 20 05:00:24 PST 2014
Thanks Michel.
Thanks
-Sundar
On Thursday 20 February 2014 05:43 PM, Michel Krämer wrote:
> Dear Sundar,
>
> Here's the minimal example:
> http://storage.spamihilator.com/public.php?service=files&t=23b6d2e601bca81d461c26c050c0669c&download
>
>
> Just unzip the file and run the following command:
>
> java -Xmx1024M -cp . MinimalExample
>
> It runs the complete test suite. Some tests fail, but that's OK. Here
> are my timings:
>
> Rhino (JDK7):
>
> Total time: 394.80 secs
> Time construct: 0.38 secs
> Time parse: 25.07 secs
> Time run: 368.71 secs
> 747 of 758 tests successful.
>
> Nashorn:
>
> Total time: 1168.16 secs
> Time construct: 3.25 secs
> Time parse: 309.84 secs
> Time run: 853.91 secs
> 747 of 758 tests successful.
>
> The tests are slower than before because there's only one thread. In
> citeproc-java multiple threads are used instead. However, the
> performance difference is still quite noticeable. Nashorn is almost 3
> times slower. It takes a lot more time to parse the JavaScript and
> also execution time is longer.
>
> Hope this helps!
>
> Michel
>
>
> Am 20.02.2014 09:30, schrieb A. Sundararajan:
>> I was trying to do proper comparison and get to the actual difference
>> between the two implementations being compared. Only then we could
>> narrow down and suggest/investigate options.
>>
>> Btw, you can trace callsite misses by -tcs (or --trace-callsites) option
>> of 'jjs' tool. The same option can also be specified by the System
>> property "nashorn.args". For example:
>>
>> jjs -tcs myscript.js
>> java -Dnashorn.args=-tcs -jar MyJar.jar
>>
>> All command line options supported can be seen from
>>
>> jjs -xhelp
>>
>> Looking forward to your minimal example.
>>
>> Thanks
>> -Sundar
>>
>>
>> On Thursday 20 February 2014 01:52 PM, Michel Krämer wrote:
>>> OK. I understand that the code base is too large to debug. I thought
>>> you could just tell me some magic parameter to trace down callsite
>>> misses or whatever *LOL* but it seems to be more complicated.
>>>
>>> I'll try to compile a minimal example executing the javascript code,
>>> in order to rule out everything related to the way Nashorn is called.
>>> I'll get back to you.
>>>
>>> Thanks!
>>> Michel
>>>
>>>
>>> Am 20.02.2014 09:15, schrieb A. Sundararajan:
>>>> Since I can't clean/run on jdk7 - nor don't understand the code base
>>>> much, I suggest you do the following (when I try to figure out ways to
>>>> clean /build/run at my end).
>>>>
>>>> * You can use javax.script.Invocable interface's methods to invoke
>>>> specific functions rather than doing 'eval' of function/method calls.
>>>>
>>>> * You can also call specific object methods by invokeMethod method.
>>>>
>>>> * To have proper comparison, we should do Json as string and eval in
>>>> both cases or have Scriptable-like access + call method in nashorn. If
>>>> the former is not possible, I suggest go through
>>>> https://wiki.openjdk.java.net/display/Nashorn/Nashorn+jsr223+engine+notes
>>>>
>>>>
>>>>
>>>> * Because of string json and eval-for-method, there are lot more evals
>>>> with nashorn/javax.script. Yes - that is the same with
>>>> rhino+jdk7+javax.script. But unfortunately I couldn't run that mode at
>>>> my end (yet).
>>>>
>>>> * It is possible to access construct object and put properties in
>>>> it by
>>>> ScriptObjectMirror/Bindings/JSObject interface on every script object
>>>>
>>>> Thanks
>>>> -Sundar
>>>>
>>>>
>>>> On Thursday 20 February 2014 01:40 PM, Michel Krämer wrote:
>>>>> Hi!
>>>>>
>>>>> Replacing RhinoJsonBuilder by StringJsonBuilder will not work. The
>>>>> way
>>>>> Rhino is run either directly or through the Script API is just too
>>>>> different.
>>>>>
>>>>> I checked the line the first error occured in (build.gradle:230). It
>>>>> seems you can just remove everything from line 210 to the end of the
>>>>> file. It should still run and the error might probably be gone.
>>>>>
>>>>> There are other possibilities to run the test suite, but there more
>>>>> complicated. Let's try this one first.
>>>>>
>>>>> Cheers,
>>>>> Michel
>>>>>
>>>>>
>>>>> Am 20.02.2014 08:32, schrieb A. Sundararajan:
>>>>>> Hi Michel,
>>>>>>
>>>>>> Nope. Doesn't seem to help. BTW, I did clean last time too -
>>>>>> didn't do
>>>>>> git clean. But this time I did that as well.
>>>>>>
>>>>>> I thought I'll do this and check
>>>>>>
>>>>>> diff --git
>>>>>> a/src/main/java/de/undercouch/citeproc/script/RhinoScriptRunner.java
>>>>>> index d2524d2..21a5281 100644
>>>>>> ---
>>>>>> a/src/main/java/de/undercouch/citeproc/script/RhinoScriptRunner.java
>>>>>> +++
>>>>>> b/src/main/java/de/undercouch/citeproc/script/RhinoScriptRunner.java
>>>>>> @@ -31,6 +31,7 @@ import org.mozilla.javascript.Wrapper;
>>>>>>
>>>>>> import de.undercouch.citeproc.helper.CSLUtils;
>>>>>> import de.undercouch.citeproc.helper.json.JsonBuilder;
>>>>>> +import de.undercouch.citeproc.helper.json.StringJsonBuilder;
>>>>>>
>>>>>> /**
>>>>>> * Executes JavaScript scripts using Mozilla Rhino
>>>>>> @@ -204,7 +205,8 @@ public class RhinoScriptRunner extends
>>>>>> AbstractScriptRunner
>>>>>>
>>>>>> @Override
>>>>>> public JsonBuilder createJsonBuilder() {
>>>>>> - return new RhinoJsonBuilder(scope, this);
>>>>>> + return new StringJsonBuilder(this);
>>>>>> + // return new RhinoJsonBuilder(scope, this);
>>>>>> }
>>>>>>
>>>>>>
>>>>>> Basically making sure both nashorn and rhino use the same json
>>>>>> mechanism
>>>>>> (rhino json builder uses Scriptable - just wanted to see how far
>>>>>> that
>>>>>> difference contributes).
>>>>>>
>>>>>>
>>>>>> When I did clean and re-build - this time with jdk8,
>>>>>>
>>>>>> I got this:
>>>>>>
>>>>>> Using script runner: Mozilla Rhino 1.7 release 4 2012 06 18
>>>>>> :runTestSuite FAILED
>>>>>>
>>>>>> FAILURE: Build failed with an exception.
>>>>>>
>>>>>> * Where:
>>>>>> Build file '/home/sundar/src/citeproc-java/build.gradle' line: 128
>>>>>>
>>>>>> * What went wrong:
>>>>>> Execution failed for task ':runTestSuite'.
>>>>>> > java.util.concurrent.ExecutionException:
>>>>>> java.lang.IllegalArgumentException: Could not update items
>>>>>>
>>>>>> * Try:
>>>>>> Run with --stacktrace option to get the stack trace. Run with
>>>>>> --info or
>>>>>> --debug option to get more log output.
>>>>>>
>>>>>> BUILD FAILED
>>>>>>
>>>>>> Total time: 3 mins 35.962 secs
>>>>>>
>>>>>> If there is anyway to avoid gradle dependency and run it straight -
>>>>>> say
>>>>>> by 'ant' or some such, it would be very useful.
>>>>>>
>>>>>> Thanks
>>>>>> -Sundar
>>>>>>
>>>>>> On Thursday 20 February 2014 12:00 PM, Michel Krämer wrote:
>>>>>>> Dear Sundar,
>>>>>>>
>>>>>>> Thanks for your help. I see that you familiarized yourself with the
>>>>>>> code already. I appreciate that very much!
>>>>>>>
>>>>>>> You're right, when you run it in 'rhino' mode it will use code
>>>>>>> optimized for Rhino. However, you're also right, it should use
>>>>>>> JDK7's
>>>>>>> embedded Rhino when you run it in 'jre' mode under JDK7.
>>>>>>>
>>>>>>> I've never seen this error message before. citeproc-java itself
>>>>>>> does
>>>>>>> not use any logging mechanism, but I know that Gradle does. So, the
>>>>>>> error must have something to do with Gradle or the particular
>>>>>>> Gradle
>>>>>>> version you're running. Is there another Gradle version already
>>>>>>> installed on your system? Please make sure to run the gradlew
>>>>>>> script
>>>>>>> in the project's root directory. It automatically downloads the
>>>>>>> right
>>>>>>> Gradle version. Also make sure to run `./gradlew clean' or even
>>>>>>> `git
>>>>>>> clean -fdx', just in case.
>>>>>>>
>>>>>>> I hope this helps. Please tell me if the problem persists.
>>>>>>>
>>>>>>> Thanks,
>>>>>>> Michel
>>>>>>>
>>>>>>>
>>>>>>> Am 20.02.2014 04:36, schrieb A. Sundararajan:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> Thanks for writing to us.
>>>>>>>>
>>>>>>>> Two things:
>>>>>>>>
>>>>>>>> 1) 'rhino' mode uses Rhino's API directly (Context ..). For
>>>>>>>> nashorn, it
>>>>>>>> uses 'javax.script' engine API. I thought may be on jdk7, I could
>>>>>>>> run
>>>>>>>> 'jre' mode and try jdk7's embedded rhino based javax.script
>>>>>>>> engine.
>>>>>>>> After clean and re-run test with jdk7 results in
>>>>>>>>
>>>>>>>>
>>>>>>>> FAILURE: Build failed with an exception.
>>>>>>>>
>>>>>>>> * Where:
>>>>>>>> Build file '/home/sundar/src/citeproc-java/build.gradle' line: 230
>>>>>>>>
>>>>>>>> * What went wrong:
>>>>>>>> A problem occurred evaluating root project 'citeproc-java'.
>>>>>>>> >
>>>>>>>> org.slf4j.spi.LocationAwareLogger.log(Lorg/slf4j/Marker;Ljava/lang/String;ILjava/lang/String;[Ljava/lang/Object;Ljava/lang/Throwable;)V
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> * Try:
>>>>>>>> Run with --stacktrace option to get the stack trace. Run with
>>>>>>>> --info or
>>>>>>>> --debug option to get more log output.
>>>>>>>>
>>>>>>>> BUILD FAILED
>>>>>>>>
>>>>>>>> With jdk8, 'jre' and 'rhino' mode run fine
>>>>>>>>
>>>>>>>> 2) Json handling for rhino uses RhinoJsonBuilder which uses
>>>>>>>> Scriptable
>>>>>>>> of Rhino. For nashorn, it uses 'string json builder' - which
>>>>>>>> presumably
>>>>>>>> involves more string handling?
>>>>>>>>
>>>>>>>> If you can tell me how to run with jdk7, then perhaps we can have
>>>>>>>> proper
>>>>>>>> comparison. 'jre' mode on jdk7 with rhino javax.script engine and
>>>>>>>> 'jre'
>>>>>>>> mode on jdk8 with nashorn javax.script engine.
>>>>>>>>
>>>>>>>> Thanks
>>>>>>>> -Sundar
>>>>>>>>
>>>>>>>>
>>>>>>>> On Wednesday 19 February 2014 09:09 PM, Michel Krämer wrote:
>>>>>>>>> Hi folks,
>>>>>>>>>
>>>>>>>>> I'm experiencing very drastic performance issues with Nashorn
>>>>>>>>> (JDK 8
>>>>>>>>> b129) compared to Rhino. My script takes almost 13 minutes
>>>>>>>>> instead of
>>>>>>>>> 16 seconds! I hope you guys can tell me what's going on here.
>>>>>>>>>
>>>>>>>>> I've recently tested citeproc-java
>>>>>>>>> (https://github.com/michel-kraemer/citeproc-java) under JDK8 in
>>>>>>>>> order
>>>>>>>>> to make sure it keeps running flawlessly when the next Java
>>>>>>>>> version
>>>>>>>>> comes out. citeproc-java uses citeproc-js under the hood which
>>>>>>>>> is a
>>>>>>>>> rather large JavaScript library consisting of one file of
>>>>>>>>> about 540
>>>>>>>>> KB, 13.500 lines of code
>>>>>>>>> (https://bitbucket.org/fbennett/citeproc-js/wiki/Home).
>>>>>>>>>
>>>>>>>>> Previously I used Rhino to execute the JavaScript and it worked
>>>>>>>>> quite
>>>>>>>>> well. There is a test suite consisting of 758 tests. Running this
>>>>>>>>> suite takes about 16 seconds (JavaScript compiled to byte code)
>>>>>>>>> or 46
>>>>>>>>> secs (interpreted JavaScript). However, if I try to run the same
>>>>>>>>> test
>>>>>>>>> suite with Oracle Nashorn it takes 12.5 minutes! (see timings
>>>>>>>>> below)
>>>>>>>>>
>>>>>>>>> This is a very drastic performance drop and I was very
>>>>>>>>> surprised to
>>>>>>>>> see this. Is there some way to debug Nashorn in order to find out
>>>>>>>>> what
>>>>>>>>> is actually going on here?
>>>>>>>>>
>>>>>>>>> Timings on my computer (i5-3570K, 3.4 GHz, 4 cores, 16 GB RAM):
>>>>>>>>>
>>>>>>>>> Rhino 1.7R4 (JavaScript compiled to byte code):
>>>>>>>>> 16.176 secs
>>>>>>>>>
>>>>>>>>> Rhino 1.7R3 (bundled w/ JDK 7, interpreted JavaScript):
>>>>>>>>> 45.970 secs
>>>>>>>>>
>>>>>>>>> Nashorn (JDK 8 b129):
>>>>>>>>> 754.266 secs
>>>>>>>>>
>>>>>>>>> Steps to reproduce (no prerequisites other than JDK8):
>>>>>>>>>
>>>>>>>>> git clone https://github.com/michel-kraemer/citeproc-java.git
>>>>>>>>> cd citeproc-java
>>>>>>>>> ./gradlew runTestSuite -PscriptRunnerType=rhino
>>>>>>>>> ./gradlew runTestSuite -PscriptRunnerType=jre
>>>>>>>>>
>>>>>>>>> Cheers,
>>>>>>>>> Michel
>>>>>>>>
>>>>>>>>
>>>>>>
>>>>>>
>>>>
>>>>
>>
>>
More information about the nashorn-dev
mailing list