[JS Scripting] All scripts stop working when upgrading to 3.4.0.M4

florian-h05 · November 9, 2022, 9:58pm

Some users are experiencing an issue where JS Scripting stops working when openHAB is upgraded to 3.4.0.M4.

Reference https://community.openhab.org/t/openhab-3-4-milestone-discussion/138093/85:

2022-11-07 09:32:15.784 [ERROR] [.internal.OpenhabGraalJSScriptEngine] - Could not inject global script
javax.script.ScriptException: org.graalvm.polyglot.PolyglotException: SyntaxError: arraycopy: last destination index 45 out of bounds for byte[44]
 at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.toScriptException(GraalJSScriptEngine.java:503) ~[?:?]
 at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:480) ~[?:?]
 at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:446) ~[?:?]
 at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:264) ~[java.scripting:?]
 at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:54) ~[?:?]
 at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.java:69) ~[?:?]
 at org.openhab.automation.jsscripting.internal.OpenhabGraalJSScriptEngine.beforeInvocation(OpenhabGraalJSScriptEngine.java:218) ~[?:?]
 at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.java:68) ~[?:?]
 at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:54) ~[?:?]
 at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.java:69) ~[?:?]
 at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.lambda$0(ScriptActionHandler.java:58) ~[?:?]
 at java.util.Optional.ifPresent(Optional.java:183) [?:?]
 at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.execute(ScriptActionHandler.java:55) [bundleFile:?]
 at org.openhab.core.automation.internal.RuleEngineImpl.executeActions(RuleEngineImpl.java:1181) [bundleFile:?]
 at org.openhab.core.automation.internal.RuleEngineImpl.runRule(RuleEngineImpl.java:989) [bundleFile:?]
 at org.openhab.core.automation.internal.TriggerHandlerCallbackImpl$TriggerData.run(TriggerHandlerCallbackImpl.java:89) [bundleFile:?]
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
 at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
 at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
 at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: org.graalvm.polyglot.PolyglotException: SyntaxError: arraycopy: last destination index 45 out of bounds for byte[44]
 at com.oracle.truffle.polyglot.PolyglotMapAndFunction.apply(PolyglotMapAndFunction.java:46) ~[?:?]
 at org.openhab.automation.jsscripting.internal.OpenhabGraalJSScriptEngine.lambda$7(OpenhabGraalJSScriptEngine.java:208) ~[?:?]
 at java.util.Optional.orElseGet(Optional.java:369) ~[?:?]
 at org.openhab.automation.jsscripting.internal.OpenhabGraalJSScriptEngine.lambda$5(OpenhabGraalJSScriptEngine.java:208) ~[?:?]
 at <js>.:program(<eval>:1) ~[?:?]
 at org.graalvm.polyglot.Context.eval(Context.java:399) ~[?:?]
 at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:478) ~[?:?]
 ... 20 more

The big problem is, that (at least for now) we can not reproduce this problem.

This thread tries to collect more information about the issue.

For all users that experience the same problem, please post your error message (in log fences!!) together with the following information:

Platform information:
- Hardware: CPUArchitecture/RAM/storage (e.g. Raspberry Pi 4B 2GB)
- OS: Output of uname -a
- Java Runtime Environment: Output of java --version
- openHAB version:

florian-h05 · November 9, 2022, 10:00pm

I am not experiencing this problem on my production system, which is a 64bit Debian VM on a Synology NAS with an Intel processor.

uname -a:

Linux smarthomevm 5.10.0-18-amd64 #1 SMP Debian 5.10.140-1 (2022-09-02) x86_64 GNU/Linux

java --version:

openjdk 11.0.16 2022-07-19
OpenJDK Runtime Environment (build 11.0.16+8-post-Debian-1deb11u1)
OpenJDK 64-Bit Server VM (build 11.0.16+8-post-Debian-1deb11u1, mixed mode, sharing)

I‘ve also tested my dev openHAB server (Synology Docker), also works fine:

openHAB Version: Build #3167
OS: Linux/4.4.180+ (amd64)
Java: Eclipse Temurin 11.0.17 (Temurin-11.0.17+8)

konfetti · November 9, 2022, 10:33pm

Thx florian-h05 for this new thread and sorry for taken over the other one

As written in the other thread I was on a raspi 4b with openhabian with default openJDK11 at the time the problem occurs:

    Platform information:
        Hardware: Raspberry Pi 4B 4GB, 32Gb SD card, 2Tb external HDD
        OS: Linux openhabian 5.15.76-v7l+ #1597 SMP Fri Nov 4 12:14:58 GMT 2022 armv7l GNU/Linux

        Java Runtime Environment: openjdk version "11.0.16" 2022-07-19
OpenJDK Runtime Environment (build 11.0.16+8-post-Raspbian-1deb11u1)
OpenJDK Server VM (build 11.0.16+8-post-Raspbian-1deb11u1, mixed mode)

        openHAB version:
openhabian@openhabian:/var/lib/openhab $ cat etc/version.properties
openHAB Distribution Version Information
----------------------------------------
build-no        : Build #3167
online-repo     : https://openhab.jfrog.io/openhab/libs-snapshot

Repository        Version
----------------------------------------
openhab-distro  : 3.4.0-SNAPSHOT
openhab-core    : 3.4.0-SNAPSHOT
openhab-addons  : 3.4.0-SNAPSHOT
karaf           : 4.3.7

After upgrading to M4 (or to latest Snapshot) no ECMA-11 rules are working. For me an change to

openjdk version "11.0.17" 2022-10-18 LTS
OpenJDK Runtime Environment Zulu11.60+19-CA (build 11.0.17+8-LTS)
OpenJDK Client VM Zulu11.60+19-CA (build 11.0.17+8-LTS, mixed mode)

solve the problem.

I will observe if it is now stable for me.

Br,
konfetti

mark_leonard_tuil · November 10, 2022, 12:01am

My results:

Platform information:
- Hardware: Raspberry Pi 4B 4GB
- OS:

Linux apollo 5.15.74-v7l+ #1594 SMP Fri Oct 21 16:36:11 BST 2022 armv7l GNU/Linux

Java Runtime Environment: I’m on docker. If i log into the container and get the java version. The result is

openjdk 11.0.16.1 2022-08-12
OpenJDK Runtime Environment Temurin-11.0.16.1+1 (build 11.0.16.1+1)
OpenJDK Server VM Temurin-11.0.16.1+1 (build 11.0.16.1+1, mixed mode)

openHAB version: 3.4.0.M4

I am using JS files. Below is an example of the error I get when loading one file. Happy to do more tests,

Things I tried were:

removing and installing JS scripting - no luck
removing JS scripting, stopping openhab, restarting openhab, installing JS scripting - no luck
went to the settings menu on openhab and went to the JS Scripting tab. Set it to not use internal variables (it was set to use them). Saved. Loaded the script - no luck
Reversed the setting to use internal variables, saved, loaded the script - no luck.

My error

2022-11-10 00:43:06.458 [INFO ] [rulesupport.loader.ScriptFileWatcher] - Loading script '/openhab/conf/automation/js/test2.js'
2022-11-10 00:43:06.642 [ERROR] [.internal.OpenhabGraalJSScriptEngine] - Could not inject global script
javax.script.ScriptException: org.graalvm.polyglot.PolyglotException: SyntaxError: arraycopy: last destination index 45 out of bounds for byte[44]
	at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.toScriptException(GraalJSScriptEngine.java:503) ~[?:?]
	at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:480) ~[?:?]
	at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:446) ~[?:?]
	at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:264) ~[java.scripting:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:54) ~[?:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.java:69) ~[?:?]
	at org.openhab.automation.jsscripting.internal.OpenhabGraalJSScriptEngine.beforeInvocation(OpenhabGraalJSScriptEngine.java:218) ~[?:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.java:78) ~[?:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:59) ~[?:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.java:79) ~[?:?]
	at org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl.loadScript(ScriptEngineManagerImpl.java:189) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.createAndLoad(ScriptFileWatcher.java:251) ~[?:?]
	at org.openhab.automation.jsscripting.internal.fs.watch.JSScriptFileWatcher.createAndLoad(JSScriptFileWatcher.java:57) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.importFile(ScriptFileWatcher.java:231) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.lambda$2(ScriptFileWatcher.java:223) ~[?:?]
	at java.util.Optional.ifPresent(Optional.java:183) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.importFileWhenReady(ScriptFileWatcher.java:221) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.processWatchEvent(ScriptFileWatcher.java:198) ~[?:?]
	at org.openhab.automation.jsscripting.internal.fs.watch.JSScriptFileWatcher.processWatchEvent(JSScriptFileWatcher.java:50) ~[?:?]
	at org.openhab.core.service.WatchQueueReader.lambda$5(WatchQueueReader.java:357) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: org.graalvm.polyglot.PolyglotException: SyntaxError: arraycopy: last destination index 45 out of bounds for byte[44]
	at com.oracle.truffle.polyglot.PolyglotMapAndFunction.apply(PolyglotMapAndFunction.java:46) ~[?:?]
	at org.openhab.automation.jsscripting.internal.OpenhabGraalJSScriptEngine.lambda$7(OpenhabGraalJSScriptEngine.java:208) ~[?:?]
	at java.util.Optional.orElseGet(Optional.java:369) ~[?:?]
	at org.openhab.automation.jsscripting.internal.OpenhabGraalJSScriptEngine.lambda$5(OpenhabGraalJSScriptEngine.java:208) ~[?:?]
	at <js>.:program(test2.js:1) ~[?:?]
	at org.graalvm.polyglot.Context.eval(Context.java:399) ~[?:?]
	at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:478) ~[?:?]
	... 24 more
2022-11-10 00:43:06.660 [ERROR] [b.automation.script.javascript.stack] - Failed to execute script:
org.graalvm.polyglot.PolyglotException: ReferenceError: "rules" is not defined
	at <js>.:program(test2.js:1) ~[?:?]
	at org.graalvm.polyglot.Context.eval(Context.java:399) ~[?:?]
	at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:478) ~[?:?]
	at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:420) ~[?:?]
	at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:249) ~[java.scripting:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:59) ~[?:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.java:79) ~[?:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:59) ~[?:?]
	at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.java:79) ~[?:?]
	at org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl.loadScript(ScriptEngineManagerImpl.java:189) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.createAndLoad(ScriptFileWatcher.java:251) ~[?:?]
	at org.openhab.automation.jsscripting.internal.fs.watch.JSScriptFileWatcher.createAndLoad(JSScriptFileWatcher.java:57) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.importFile(ScriptFileWatcher.java:231) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.lambda$2(ScriptFileWatcher.java:223) ~[?:?]
	at java.util.Optional.ifPresent(Optional.java:183) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.importFileWhenReady(ScriptFileWatcher.java:221) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.loader.ScriptFileWatcher.processWatchEvent(ScriptFileWatcher.java:198) ~[?:?]
	at org.openhab.automation.jsscripting.internal.fs.watch.JSScriptFileWatcher.processWatchEvent(JSScriptFileWatcher.java:50) ~[?:?]
	at org.openhab.core.service.WatchQueueReader.lambda$5(WatchQueueReader.java:357) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
2022-11-10 00:43:06.669 [ERROR] [ipt.internal.ScriptEngineManagerImpl] - Error during evaluation of script 'file:/openhab/conf/automation/js/test2.js': org.graalvm.polyglot.PolyglotException: ReferenceError: "rules" is not defined

I see nothing in my file test2.js that points to a cause. For the sake of being complete. The rule I am trying to load is:

rules.JSRule({
  name: "Test",
  description: "Turn off light as a test",
  triggers: [triggers.ItemCommandTrigger('Test')],
  execute: data => {
	console.log("Test")
  }
});

florian-h05 · November 10, 2022, 12:51pm

The error occurs when the JS Scripting add-on tries to inject the global script, which provides the polyfills for Nodes console etc.
I currently have no idea what the problem is (I haven‘t done deeper investigation for now), and as long as I can not reproduce, there is no real chance to debug.

I‘ll check whether it works on my dev system, but seems like the issue only occurs on some JDK versions.

tnemrap · November 10, 2022, 1:20pm

OS: Raspbian GNU/Linux 10 (buster)
openjdk version “11.0.16” 2022-07-19
OpenJDK Runtime Environment (build 11.0.16+8-post-Raspbian-1deb10u1)
OpenJDK Server VM (build 11.0.16+8-post-Raspbian-1deb10u1, mixed mode)

Does not work.

konfetti · November 10, 2022, 2:36pm

Let me know if there is the possibility to provide further logs (debug, trace …).

florian-h05 · November 10, 2022, 3:37pm

I have also checked on my dev system, I extra switched to the Java version on which the error occurs (I am using the RedHat build):

openjdk 11.0.16 2022-07-19 LTS
OpenJDK Runtime Environment (Red_Hat-11.0.16.0.8-1.el7openjdkportable) (build 11.0.16+8-LTS)
OpenJDK 64-Bit Server VM (Red_Hat-11.0.16.0.8-1.el7openjdkportable) (build 11.0.16+8-LTS, mixed mode)

openHAB Version Build #3168

But again, I am not able to reproduce.

@Kai @laursen @J-N-K @Lolodomo @digitaldan @jpg0 Can any of you reproduce the issue or has any idea what’s going on?

Thanks for the offer, but looking at the JS Scripting source code, it is clear where the error comes from: the injection of the globals script. Changing the log level does not help, since the exception is already logged.

rlkoshak · November 10, 2022, 4:31pm

I am also not experiencing this problem (I upgrade to the snapshots every few days) but it might prove helpful if those running in Docker would make a note of which architecture you are running, debian (the default) or alpine. It might be relevant, it might not.

mark_leonard_tuil · November 10, 2022, 4:45pm

For my part, my docker version is debian

J-N-K · November 11, 2022, 7:36pm

Can you share the test.js that is causing the issue?

mark_leonard_tuil · November 11, 2022, 9:40pm

Was the question directed at me? The test file is included above. It can’t be the cause. Anyway, all my JS files seem to fail.

konfetti · November 11, 2022, 10:39pm

It is not related to one special rule but if you need one

configuration: {}
triggers:
  - id: "1"
    configuration:
      cronExpression: 0/15 * * * * ? *
    type: timer.GenericCronTrigger
conditions: []
actions:
  - inputs: {}
    id: "2"
    configuration:
      type: application/javascript;version=ECMAScript-2021
      script: >
        /*
        ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
        */

        /* ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Global Vars ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ */

        /* ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ */
         

        var ruleName = "TestRule";


        var logger = log(ruleName);


        console.log("Start of rule");


        console.log("End of rule");
    type: script.ScriptAction

That is the simplest one I have (tried to ) executed.

I’m pretty sure it has nothing to do with the source code of the rules/script!

Br,
konfetti

digitaldan · November 12, 2022, 4:36am

Very odd, i am running the nightly docker image, openhab/openhab:3.4.0-snapshot on a older core-i3 intel nuc. Not seeing these issues either. All rules are run from files.

J-N-K · November 12, 2022, 6:33am

I can’t reproduce it on MacOS, neither with Java 11 nor with Java 17 (which I use).

ML1982 · November 12, 2022, 10:54am

@konfetti as I read in the other thread you did:

Stop OH
Clean cache & tmp
Install Zulu 11 32 Bit
Reboot
Wait 10 Minutes

could you provide me the commands for step 1, 2 and 3?
I tried to install Zulu 11 32 via:
sudo openhabian-config → 40 → 45

but i’ve still the problems with all my scripts

konfetti · November 12, 2022, 11:52am

Steps 1-3

 sudo systemctl stop openhab
 cd $OPENHAB_USERDATA
 sudo rm -rf tmp/*
 sudo rm -rf cache/*

Step 3 is as you have described via openhabian-config 40 & 45.

ML1982 · November 12, 2022, 12:58pm

cool. it works.

At first I tried it without Step 1-3, and it didn’t work

mark_leonard_tuil · November 12, 2022, 1:11pm

Out of curiosity, what happens if you reverse the process?

konfetti · November 12, 2022, 1:12pm

I reverted to the old java version and then the same problem restarts.