Performance issues
A. Sundararajan
sundararajan.athijegannathan at oracle.com
Thu Feb 20 05:38:16 PST 2014
We are investigating.
Thanks for reporting the issue.
-Sundar
On Thursday 20 February 2014 06:30 PM, A. Sundararajan wrote:
> 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