Nashorn execution performance cracking

[MrLi2018]

Background: I only set the CPU duration when executing scripts using nashorn, but I found that the value was long whenever the thread was nearing the end of the thread when executing with the thread pool.
phenomenon:
Listen to the following code:
` synchronized (monitor) {
long waitTime = getCheckInterval(runtime);

                    if (waitTime == 0) {
                        waitTime = 1;
                    }
                    long start=System.currentTimeMillis();
                    monitor.wait(waitTime);
                    LOGGER.info(" cost {}",System.currentTimeMillis()-start);
                }

result:15:31:48.702 [pool-2-thread-8] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 16
15:31:48.702 [pool-2-thread-7] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 16
15:31:48.702 [pool-2-thread-8] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 0
15:31:48.702 [pool-2-thread-2] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 0
15:31:48.702 [pool-2-thread-4] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 0
15:31:48.702 [pool-2-thread-3] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 0
15:31:50.473 [pool-2-thread-6] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 2006
15:31:50.473 [pool-2-thread-5] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 2006
15:31:50.474 [pool-2-thread-6] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 1
15:31:50.474 [pool-2-thread-5] [INFO] [delight.nashornsandbox.internal.ThreadMonitorTest.run(ThreadMonitorTest.java:139)] - cost 1`

Why Fluctuations Occur?

[obourgain]

hello, please do not ping people just one hour after posting your issue

[MrLi2018]

sorry!

[mxro]

Hello @MrLi2018, thank you for posting this issue.

That is very intersting - so running the same script has a lot of variation in execution times. Maybe some further things to confirm/try:

1. Try running the script with the new precompiled script feature and see if the variation persists:

NashornSandbox sandbox = NashornSandboxes.create();
CompiledScript script = sandbox.compile("1 + 1");
int result1 = (int) sandbox.eval(script);
int result2 = (int) sandbox.eval(script);

2. Try running without an executor script or try different types of thread pools

sandbox.setExecutor(Executors.newSingleThreadExecutor());

3. Ensure there are no other processes running on the JVM/machine.

4. Try running the original script or the script generated by the sandbox using vanialla Nashorn. You can see the script generated using log4j.logger.delight.nashornsandbox.NashornSandbox=DEBUG

Hope this helps!

[MrLi2018]

Hello, I don't understand what you mean. I've tried different thread pools, but I found that the results are the same. The execution time of individual scripts is always near the execution time of the CPU I set. This result will occur even if a very simple script runs many times

…

------------------ 原始邮件 ------------------ 发件人: "javadelight/delight-nashorn-sandbox" ***@***.***>; 发送时间: 2021年10月25日(星期一) 凌晨4:46 ***@***.***>; ***@***.******@***.***>; 主题: Re: [javadelight/delight-nashorn-sandbox] Nashorn execution performance cracking (Issue #121) Hello @MrLi2018, thank you for posting this issue. That is very intersting - so running the same script has a lot of variation in execution times. Maybe some further things to confirm/try: Try running the script with the new precompiled script feature and see if the variation persists: NashornSandbox sandbox = NashornSandboxes.create(); CompiledScript script = sandbox.compile("1 + 1"); int result1 = (int) sandbox.eval(script); int result2 = (int) sandbox.eval(script); Try running without an executor script or try different types of thread pools sandbox.setExecutor(Executors.newSingleThreadExecutor()); Ensure there are no other processes running on the JVM/machine. Try running the original script or the script generated by the sandbox using vanialla Nashorn. You can see the script generated using log4j.logger.delight.nashornsandbox.NashornSandbox=DEBUG Hope this helps! — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe. Triage notifications on the go with GitHub Mobile for iOS or Android.

[MrLi2018]

OK,sorry！

…

------------------ 原始邮件 ------------------ 发件人: "javadelight/delight-nashorn-sandbox" ***@***.***>; 发送时间: 2021年10月18日(星期一) 下午4:29 ***@***.***>; ***@***.******@***.***>; 主题: Re: [javadelight/delight-nashorn-sandbox] Nashorn execution performance cracking (Issue #121) hello, please do not ping people just one hour after posting your issue — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or unsubscribe. Triage notifications on the go with GitHub Mobile for iOS or Android.

[mxro]

Thank you for your reply. Happy to try and help get to the bottom of this!

The execution time of individual scripts is always near the execution time of the CPU I set.

Are you saying that no matter the compleixty of the script, the execution time is always near the limit? That has not been my experience and there are a number of unit tests in this repo that I think show otherwise. Maybe you could construct a test case demonstrating this? The consumed CPU time should scale up with the complexity of the script.

This result will occur even if a very simple script runs many times

And here are you saying that the CPU time accumulates across script executions. Had a quick look into the code, and I think for every eval that should reset. But maybe I'm missing something. If you can spot the issue in the code or a test case, please let me know!