Performance degradation compared to Nashorn

[ronayadid]

Hello,

I'm migrating to GraalVM from Nashorn script engine.
My usage of the engine was running js scripts from within my spring boot app.
The scripts always have an identical structure: (IIFE - immediately invoked function expression)

(function(arg1) { // arg1 is a json
// here we have conditions regarding arg1 fields and in the end we return a value
...
                    })(arg1)

We also have a global script which contain global functions we want to support.

My initial implementation was through the Context object (which I thought was the recommended way):

Context context = createContext();
Value contextBindings = context.getBindings("js");
contextBindings.putMember("arg1", proxyObject);
context.eval(globalFunctions); // globalFunctions is Source object that is created once on startup.
return context.eval("js", expression);

This code works and return the expected results.

The problem is with the performance.
My test was to run a loop of 50,000 iterations and it took 26574 ms.
I ran with a profiler and I saw to my surprise that the line context.getBindings("js") takes the most CPU - more than 88%.

Then I ran the same test on my old Nashorn implementation and it took 8897 ms.

Why are the first performance test result so bad?
Why is getBindings call costs so much?
How can I improve my performance?

[jramirez-isc]

Hi @ronayadid
Yes, the recommended way is using the Context API.
Would you mind answering these questions to help to find the issue:

How are you measuring the degradation?
What tools are you using?
What data have you collected to demonstrate this issue?
Can you provide a reproducible test case?
Is this consistent?
What are the OS and architecture involved?

[ronayadid]

Hi @jramirez-isc

I'm measuring the degradation by running my code in a loop in a test.
I'm running the test in IntelliJ with java 11, on a MacBook Pro machine.
I used JProfiler for profiling.
In my test I'm counting the time it takes to finish 50000 iterations.
This happens consistently.
I have to say I first saw a smaller degradation while running multithreaded performance tests on my spring boot application. And then I wanted to find the cause so I wrote a test specifically for the suspected piece of code.

Here is the code I'm running:

@Test
    public void testGraalVMPerformance() throws IOException {
        String expression = "(function(arg1) {\n" +
                "                   if (\"value1\" == arg1.keyX) {\n" +
                "                        return \"SUCCESS\";\n" +
                "                    } else {\n" +
                "                        return \"FAILURE\";\n" +
                "                    }\n" +
                "})(arg1)";

        String json = "{ \"keyX\" : \"value1\"}";
        ProxyObject proxyObject = ProxyObject.fromMap(new ObjectMapper().readValue(json, Map.class));

        long start = System.currentTimeMillis();
        Value result = Value.asValue(null);

        for (int i = 0; i < 50000; i++) {

            Context context = Context
                    .newBuilder("js")
                    .allowHostAccess(HostAccess.ALL)
                    .allowHostClassLookup((s) -> true)
                    .build();
            Value contextBindings = context.getBindings("js");
            contextBindings.putMember("arg1", proxyObject);

            result = context.eval("js", expression);
            context.close();
        }

        System.out.println("GraalVM test duration is " + (System.currentTimeMillis() - start));
        System.out.println(result.asString());
    }


    @Test
    public void testNashornPerformance() throws IOException, ScriptException {
        String expression = "(function(arg1) {\n" +
                "                   if (\"value1\" == arg1.keyX) {\n" +
                "                        return \"SUCCESS\";\n" +
                "                    } else {\n" +
                "                        return \"FAILURE\";\n" +
                "                    }\n" +
                "})(arg1)";

        String json = "{ \"keyX\" : \"value1\"}";
        Object obj = new ObjectMapper().readValue(json, Object.class);

        ScriptEngine scriptEngine = new ScriptEngineManager().getEngineByName("nashorn");

        long start = System.currentTimeMillis();
        Object result = null;

        for (int i = 0; i < 50000; i++) {

            ScriptContext scriptContext = new SimpleScriptContext();
            Bindings engineScopeBindings = scriptEngine.createBindings();
            engineScopeBindings.put("arg1", obj);
            scriptContext.setBindings(engineScopeBindings, ScriptContext.ENGINE_SCOPE);

            result = scriptEngine.eval(expression, scriptContext);
        }

        System.out.println("Nashorn test duration is " + (System.currentTimeMillis() - start));
        System.out.println(result);
    }

Profiling CPU hot spots when running the GraalVM test:

[wirthi]

Hi @ronayadid

thanks for your code example. I am able to execute and benchmark it on my machine. I have yet to look into it in more detail, but two crucial improvements you can do immediately:

use shared Engine
Outside the loop, create an Engine object:

Engine eng = Engine.create();

and when creating a context, associate it with the Engine:

Context context = Context
    .newBuilder("js")
    .engine(eng)
    . ...

This allows you to profit from Code Caching across Contexts, i.e. not having to recompile the source code for every Context. See https://www.graalvm.org/reference-manual/embed-languages/#code-caching-across-multiple-contexts

use a Source instead of String
Especially if you have a literal source that is constant, use a Source instead. That helps caching in the Engine (note that it should work even on constant strings, but using a Source object is the safer choice):

Source src = Source.newBuilder("js", expression, "test.js").buildLiteral(); //outside the loop
...
result = context.eval(src); //inside the loop

re-use Context.Builder
You can create a Context.Builder object outside the loop and only .build() it to a Context inside the loop. Performance impact of this is probably minimal, but code feels better readable:

Context.Builder builder = Context
    .newBuilder("js")
    .engine(eng)
    .allowHostAccess(HostAccess.ALL)
    .allowHostClassLookup((s) -> true);
for (int i = 0; i < 50000; i++) {
    Context context = builder.build();

Overall, this vastly improves performance on GraalVM for me. Still behind Nashorn (we will investigate why this is the case) but the diff is much smaller.

Best,
Christian

[ronayadid]

Hi @wirthi

Thanks for your recommendations.
In my application code I did that from the start, and still saw the degradation compared to Nashorn.
In my test I tried the shared engine and the impact on the performance was minor.
The heaviest operation which impacts the performance the most (according to the profiling results) is the call to context.getBindings("js")

For now I implemented an object pool for re-use of contexts, and it improves the performance significantly.

I wonder what is the best practice for using GraalJS Context API inside an application.
Because to me it looks like the basic implementation of creating a context per request (even with all the optimisations) is just not good enough. It can't be good enough because using getBinding method is almost mandatory for every operation.

Thanks
Rona