Since build 447 unable to use nashorn-core

[kangarko]

Background:

There is a problem since Velocity build 447 preventing Rhino (javascript engine) to work. The problem started in build 447 after updating the dependencies: f2d6e14

This affects all plugins using JavaScript variables which are now unable to use the nashorn-core library.

How to fix:

This has already been fixed at Java's team, see openjdk/nashorn@5e78947

However ETA for nashorn-core release, so the relevant library has prepared a patch already:

apache/logging-log4j2#3125

Please consider shipping logging-log4j2 2.25.0-SNAPSHOT into velocity to solve this problem.

Stack trace:

2024-11-21T11:13:03.785832500Z VelocityControl - Task Executor #0 ERROR Cannot set JUL log level through log4j-api: ignoring call to Logger.setLevel(OFF)
[12:13:03 INFO] [disabled]: methodType class java.lang.Object [class java.lang.Object] (Object)Object
[12:13:03 ERROR]: java.lang.reflect.InvocationTargetException
[12:13:03 ERROR]: 	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:118)
[12:13:03 ERROR]: 	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
[12:13:03 ERROR]: 	at org.mineacademy.fo.platform.FoundationPlatform.<init>(FoundationPlatform.java:53)
[12:13:03 ERROR]: 	at org.mineacademy.fo.platform.VelocityPlatform.<init>(VelocityPlatform.java:42)
[12:13:03 ERROR]: 	at org.mineacademy.fo.platform.VelocityPlatform.inject(VelocityPlatform.java:39)
[12:13:03 ERROR]: 	at org.mineacademy.fo.platform.VelocityPlugin.onProxyInitialization(VelocityPlugin.java:221)
[12:13:03 ERROR]: 	at org.mineacademy.fo.platform.Lmbda$1.execute(Unknown Source)
[12:13:03 ERROR]: 	at com.velocitypowered.proxy.event.UntargetedEventHandler$VoidHandler.lambda$buildHandler$0(UntargetedEventHandler.java:56)
[12:13:03 ERROR]: 	at com.velocitypowered.proxy.event.VelocityEventManager.fire(VelocityEventManager.java:676)
[12:13:03 ERROR]: 	at com.velocitypowered.proxy.event.VelocityEventManager.lambda$fire$5(VelocityEventManager.java:541)
[12:13:03 ERROR]: 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
[12:13:03 ERROR]: 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
[12:13:03 ERROR]: 	at java.base/java.lang.Thread.run(Thread.java:1583)
[12:13:03 ERROR]: Caused by: java.lang.ExceptionInInitializerError
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.codegen.CompilerConstants.staticCall(CompilerConstants.java:566)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.runtime.JSType.<clinit>(JSType.java:85)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.MethodHandleFactory$StandardMethodHandleFunctionality.describe(MethodHandleFactory.java:347)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.MethodHandleFactory$StandardMethodHandleFunctionality.debug(MethodHandleFactory.java:376)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.MethodHandleFactory$StandardMethodHandleFunctionality.findStatic(MethodHandleFactory.java:543)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.MethodHandleFactory.<clinit>(MethodHandleFactory.java:114)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.runtime.linker.Bootstrap.<clinit>(Bootstrap.java:68)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.runtime.Context.<init>(Context.java:655)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.runtime.Context.<init>(Context.java:585)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.api.scripting.NashornScriptEngine.lambda$new$0(NashornScriptEngine.java:126)
[12:13:03 ERROR]: 	at java.base/java.security.AccessController.doPrivileged(AccessController.java:400)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.api.scripting.NashornScriptEngine.<init>(NashornScriptEngine.java:124)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.api.scripting.NashornScriptEngineFactory.getScriptEngine(NashornScriptEngineFactory.java:152)
[12:13:03 ERROR]: 	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
[12:13:03 ERROR]: 	... 12 more
[12:13:03 ERROR]: Caused by: java.lang.NullPointerException: Cannot invoke "java.lang.invoke.MethodHandle.type()" because "target" is null
[12:13:03 ERROR]: 	at java.base/java.lang.invoke.MethodHandles.insertArgumentsChecks(MethodHandles.java:5308)
[12:13:03 ERROR]: 	at java.base/java.lang.invoke.MethodHandles.insertArguments(MethodHandles.java:5277)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.MethodHandleFactory.addDebugPrintout(MethodHandleFactory.java:287)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.MethodHandleFactory$StandardMethodHandleFunctionality.debug(MethodHandleFactory.java:376)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.MethodHandleFactory$StandardMethodHandleFunctionality.findStatic(MethodHandleFactory.java:543)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.Lookup.findOwnMH(Lookup.java:212)
[12:13:03 ERROR]: 	at org.openjdk.nashorn.internal.lookup.Lookup.<clinit>(Lookup.java:54)
[12:13:03 ERROR]: 	... 26 more

Code:

(The "at org.mineacademy.fo.platform.FoundationPlatform.(FoundationPlatform.java:55) ~[?:?]" is highlighted)

Thanks.
Matej

[kangarko]

Update: This could be solved by bumping the log4j jul dep as mentioned at apache/logging-log4j2#3125 (comment)

[joshwenke]

Any update on this?

[electronicboy]

L4J broke nashorn due to some changes which they've added a mitigation for in their snapshots, but, that requires some looking into in terms of some other changes they've made which impacts velocities builds

nashorn has also dropped a fix in their snapshots for this issue

[kangarko]

I provided the required changes in my pull request, apart from me being unsure what to put as the annotation group ID it did work from my testing.

If stability is a concern, I propose rolling back to the previous logj4 version before this build where things were working normally, and then updating once a stable log4j drops.

Thanks!

[electronicboy]

1. I ideally do not want the graalVM generation stuff running, it's not an env we support
2. the ecosystem is using 2.24.1, no reason for us to not to, some library doing fragile hacks is not our problem
3. the library doing these fragile hacks have already released a fix, I'm not sure why we should harm our builds because you're not willing to fix this on your side

[kangarko]

1. The graalVM generation is coming in the next log4j, and will not be running when the server is started. I am afraid that's not a decision you will make unless you stop updating your logger library.

2. I am willing to fix it, and I fixed it in the pull request which you rejected. Afaik I am unable to solve it on my end and this is a global issue affecting all plugins using JavaScript variables. Please correct me if I am wrong. The new nashorn-core is unfortunately broken so we are again stuck waiting for an external fix.

[electronicboy]

the nature of "ideally" is a level of acceptance that it might not be worth disabling that task, but, I really doubt that l4j would require that you have to set some variables to build their project in general

"fix this on your side" does not mean forcing us to jump to snapshot dependencies mid cycle and breaking downstream projects, it means testing fixes on your side rather.

However, I will note that I did hide that Nashorn issue when building a snapshot of it myself the other week for testing, so, I can confirm that it's busted from the seems of it.

[kangarko]

Appreciated the swift response and thanks for the info.

I completely understand snapshots are suboptimal. I will continue to contact the author of these libraries to see if we can expedite a fix.

For anyone following this thread, one alternative is using GraalVM, which unfortunately comes with a performance overhead and lack of Java access, so it would effectively break those JavaScript accessing Java methods/fields and is unfeasible.