search

openhab / openhab-js

openHAB JavaScript Library for JavaScript Scripting Automation
https://www.openhab.org/addons/automation/jsscripting/
Eclipse Public License 2.0
38 stars 31 forks source link

Parsing RFC DateTime string doesn't work with 4.5.1 add-on but works with npm installed library #288

Closed rkoshak closed 6 months ago

rkoshak commented 10 months ago

Expected Behavior

Passing the state of a DateTime Item to time.toZDT() gets parsed into a time.ZonedDateTime.

Current Behavior

When using the library built into the add-on (4.5.1 according to utils.OPENHAB_JS_VERSION) the following exception occurs:

20│org.graalvm.polyglot.PolyglotException: Error: "2023-08-09T16:22:13.585-06:00[SYSTEM]" is an unsupported type for conversion to time.ZonedDateTime                                            │is
e │        at <js>.toZDT(/openhab/conf/automation/js/node_modules/openhab/time.js:266) ~[?:?]                                                                                                    │
20│        at <js>.createTimer(/openhab/conf/automation/js/node_modules/openhab_rules_tools/helpers.js:16) ~[?:?]                                                                                │is
e │        at <js>.loop(/openhab/conf/automation/js/node_modules/openhab_rules_tools/loopingTimer.js:29) ~[?:?]                                                                                  │
20│        at <js>.alerting(<eval>:241) ~[?:?]                                                                                                                                                   │
20│        at <js>.procEvent(<eval>:506) ~[?:?]                                                                                                                                                  │
20│        at <js>.:program(<eval>:910) ~[?:?]                                                                                                                                                   │
20│        at org.graalvm.polyglot.Context.eval(Context.java:399) ~[?:?]                                                                                                                         │
20│        at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:458) ~[?:?]                                                                                   │
20│        at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:426) ~[?:?]                                                                                   │
20│        at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:262) ~[java.scripting:?]                                                                                          │
20│        at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:53) ~[?:│
00│        at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAut│40
20│ble.java:78) ~[?:?]                                                                                                                                                                           │
20│        at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:53) ~[?:│
20│        at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAut│
20│ble.java:78) ~[?:?]                                                                                                                                                                           │
20│        at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.lambda$0(ScriptActionHandler.java:71) ~[?:?]                                                        │
20│        at java.util.Optional.ifPresent(Optional.java:178) ~[?:?]                                                                                                                             │
20│        at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.execute(ScriptActionHandler.java:68) ~[?:?]                                                         │
20│        at org.openhab.core.automation.internal.RuleEngineImpl.executeActions(RuleEngineImpl.java:1188) ~[?:?]                                                                                │
20│        at org.openhab.core.automation.internal.RuleEngineImpl.runRule(RuleEngineImpl.java:997) ~[?:?]                                                                                        │
20│        at org.openhab.core.automation.internal.TriggerHandlerCallbackImpl$TriggerData.run(TriggerHandlerCallbackImpl.java:87) ~[?:?]                                                         │
20│        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]                                                                                                     │
20│        at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]                                                                                                                    │
20│        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]                                                              │
20│        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]                                                                                             │
20│        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]                                                                                             │
20│        at java.lang.Thread.run(Thread.java:833) ~[?:?]                                                                                                                                       │

However, installing the 4.5.1 through npm and switching the add-on to not use the built in library it works just fine.

Admittedly these are being called from the openhab_rules_tools library (which you can see from the stack trace) but that shouldn't matter, should it?

Maybe the problem is that openhab and @joda-js are still there in the node-modules? Should that matter? (I need to run the test if the error occurs if @joda-js isn't present but don't have time today, I'll come back tomorrow).

Possible Solution

I'm not even sure if this belongs here or as an issue on the add-on.

Steps to Reproduce (for Bugs)

  1. Set the add-on to use the built in library
  2. create a script with time.toZDT(items.SomeDateTimeItem.state) and run it
  3. notice the error in the log
  4. change the add-on to not use the built in library
  5. restart OH (should I have to restart to pick up that change? it seems to be required)
  6. run the script again and notice the error does not occur and the line runs correctly.

Context

This is impacting users of my rule templates. I've had more than one report this problem with Time Based State Machine and Threshold Alert.

Your Environment

florian-h05 commented 10 months ago

I cannot reproduce this on my clean dev system.

Admittedly these are being called from the openhab_rules_tools library (which you can see from the stack trace) but that shouldn't matter, should it?

This should matter. openhab_rules_tools imports those using const { actions, time, utils } = require('openhab');, and in case you have the openhab npm module on the file system, this one is loaded, regardless of the settings of the JS Scripting add-on (the settings only affect the injection of the library). You said you installed the library through npm, in fact you probably upgraded from an old version to a newer one which fixed the issue.

florian-h05 commented 10 months ago

However I found a bug, that time.toZDT(items.SomeDateTimeItem) does not work, but it is expected to.

rkoshak commented 10 months ago

openhab_rules_tools imports those using const { actions, time, utils } = require('openhab');, and in case you have the openhab npm module on the file system, this one is loaded, regardless of the settings of the JS Scripting add-on (the settings only affect the injection of the library). You said you installed the library through npm, in fact you probably upgraded from an old version to a newer one which fixed the issue.

Just to be clear. When both openhab-js and openhab-rules-tools is installed via npm, with openhab-js 4.5.1 and "do not use built in library" no error is generated.

When I remove openhab-js from node_modules and change the add-on settings to "use built in library" the error is generated.

I do a restart of OH in between.

So openhab_rules_tools picking up npm library shouldn't be happening. And even if it did, should that mean no error?

It's odd that you cannot reproduce it as it's not just me who is seeing this. I've had several report similar problems on my rule templates.

However I found a bug, that time.toZDT(items.SomeDateTimeItem) does not work, but it is expected to.

That certainly could be coming into play here, but that doesn't explain how the error appears and disappears even though the same openhab-js version is in use. I'd like to understand what could possibly be driving this a it will help me support my rule template users and library users if I can figure out why there is this disconnect.

I'll run a few more tests later today and report back if it makes sense. Maybe I wasn't as careful as I thought and I did forget to remove the library.

florian-h05 commented 10 months ago

I have re-tested with exactly the the Item state from your error message above and it works fine when "Use built-in library" is enabled.

I have also tested passing a DateTime Item directly with my fix from #290 in place:

// Test 1
var t = time.toZDT('2023-08-09T16:22:13.585-06:00[SYSTEM]')

// Test 2
var i = items.test_datetime
i.postUpdate(t)
t = time.toZDT(i)

So openhab_rules_tools picking up npm library shouldn't be happening. And even if it did, should that mean no error?

To explain this, I have to go a bit into the detail.

The JS Scripting add-on comes with two version of openhab-js included, both are webpacked:

  1. A version that is loaded when require is used and openhab is not installed on the file system as npm module.
  2. A version that is built in a special way - this version is used for the cached injection when "Use built-in library" is enabled

"Do not use built-in library" option basically opts out of the cached version to allow loading openhab from the file system (means npm installed) - in none is there, the included version (1) is used.

rkoshak commented 10 months ago

Very weird. I'm fixing some bugs in my rule templates but retesting this is next on my list.

To explain this, I have to go a bit into the detail.

Where I'm still confused is if there is no openhab-js on the file system at all, shouldn't openhab_rules_tools use the only library available which is built into the add-on? And given that, if there is an error, shouldn't that error always occur whether it's loaded from openhab_rules_tools or in a rule directly using require?

Similarly, if the version of openhab-js on the file system is the same version as in the add-on (as reported by utils..OPENHAB_JS_VERSION), and the add-on setting says not to use the built in library, if there is an error in openhab_rules_tools, shouldn't that same error occur for the same code in the rule itself.

The root behavior I'm seeing is that time.toZDT() cannot convert an Item or Item State with the library built into the add-on. Asking my users to install the exact same version of openhab-js via npm and changing the add-on setting "fixes" the problem.

rkoshak commented 10 months ago

I haven't had a chance to run more tests yet but I had yet another user encounter the problem. This time with a ZonedDateTime, not a DateTime Item. See https://community.openhab.org/t/openhab-rule-tools-timermgr-exception-with-zoneddatetime/148766/2

Interestingly they were able to make it work by adding

var { time } = require('openhab');

to the top of the script action. I wonder if there is something weird going on with the way the libraries are injected?

rkoshak commented 10 months ago

I've been able to gather a bit more data.

The problem is when I pass a js-joda ZonedDateTime to time.toZDT(). However, the problem only occurs when using the built in library, not when using the installed openhab-js library (when testing with the not installed openhab-js library I uninstall openhab through npm and manually remove @jods-js since it doesn't get uninstalled automatically for some reason, worth an issue?). Same version of openhab-js in both cases.

The problem only occurs when time.toZDT() is called from openhab_rules_tools.

Given the following code run using the built in library:

var {TimerMgr} = require('openhab_rules_tools');

console.info('Running scratchpad.');
console.info('openhab-js version: ' + utils.OPENHAB_JS_VERSION);
console.info('OHRT version: ' + helpers.OHRT_VERSION);

time.toZDT(time.toZDT());
TimerMgr().check('test', time.toZDT());

produces:

  │2023-08-24 10:15:52.430 [INFO ] [nhab.automation.script.ui.scratchpad] - Running scratchpad.                                                                                                  │
  │2023-08-24 10:15:52.431 [INFO ] [nhab.automation.script.ui.scratchpad] - openhab-js version: 4.5.1                                                                                            │
  │2023-08-24 10:15:52.431 [INFO ] [nhab.automation.script.ui.scratchpad] - OHRT version: 2.0.3                                                                                                  │
  │2023-08-24 10:15:52.432 [INFO ] [nhab.automation.script.ui.scratchpad] - false                                                                                                                │
  │2023-08-24 10:15:52.435 [ERROR] [b.automation.script.javascript.stack] - Failed to execute script:                                                                                            │
  │org.graalvm.polyglot.PolyglotException: Error: "2023-08-24T10:15:52.433-06:00[SYSTEM]" is an unsupported type for conversion to time.ZonedDateTime                                            │
  │        at <js>.toZDT(/node_modules/openhab.js:2) ~[?:?]                                                                                                                                      │
  │        at <js>.check(/openhab/conf/automation/js/node_modules/openhab_rules_tools/timerMgr.js:46) ~[?:?]                                                                                     │
  │        at <js>.:program(<eval>:21) ~[?:?]                                                                                                                                                    │
  │        at org.graalvm.polyglot.Context.eval(Context.java:399) ~[?:?]                                                                                                                         │
  │        at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:458) ~[?:?]                                                                                   │
  │        at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:426) ~[?:?]                                                                                   │
  │        at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:262) ~[java.scripting:?]                                                                                          │
  │        at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:53) ~[?:│
  │        at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAut│
  │ble.java:78) ~[?:?]                                                                                                                                                                           │
  │        at org.openhab.automation.jsscripting.internal.scriptengine.DelegatingScriptEngineWithInvocableAndAutocloseable.eval(DelegatingScriptEngineWithInvocableAndAutocloseable.java:53) ~[?:│
  │        at org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable.eval(InvocationInterceptingScriptEngineWithInvocableAndAut│
20│ble.java:78) ~[?:?]                                                                                                                                                                           │2.
43│        at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.lambda$0(ScriptActionHandler.java:71) ~[?:?]                                                        │
00│        at java.util.Optional.ifPresent(Optional.java:178) ~[?:?]                                                                                                                             │21
20│        at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.execute(ScriptActionHandler.java:68) ~[?:?]                                                         │
20│        at org.openhab.core.automation.internal.RuleEngineImpl.executeActions(RuleEngineImpl.java:1188) ~[?:?]                                                                                │
20│        at org.openhab.core.automation.internal.RuleEngineImpl.runNow(RuleEngineImpl.java:1039) ~[?:?]                                                                                        │
20│        at org.openhab.core.automation.rest.internal.RuleResource.runNow(RuleResource.java:382) ~[?:?]                                                                                        │
20│        at org.openhab.core.automation.rest.internal.RuleResource.runNow(RuleResource.java:399) ~[?:?]                                                                                        │
20│        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]                                                                                                        │
20│        at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]                                                                                      │
20│        at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]                                                                              │
20│        at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]                                                                                                                            │
20│        at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:179) ~[bundleFile:3.4.5]                                                                     │
20│        at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96) ~[bundleFile:3.4.5]                                                                                 │
20│        at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:201) ~[bundleFile:3.4.5]                                                                                                │
20│        at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:104) ~[bundleFile:3.4.5]                                                                                                │
20│        at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) ~[bundleFile:3.4.5]                                                                  │
20│        at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) ~[bundleFile:3.4.5]                                                          │
20│        at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) ~[bundleFile:3.4.5]                                                                         │
20│        at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) ~[bundleFile:3.4.5]                                                                   │
20│        at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:265) ~[bundleFile:3.4.5]                                                                 │
20│        at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) ~[bundleFile:3.4.5]                                                               │
20│        at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) ~[bundleFile:3.4.5]                                                                          │  
... more stack trace but I don't think they are relevant, can add them if needed

The same code, run with openhab-js installed on the file system and not using the built in library does not produce any errors at all.

So there is something about time.toZDT() which is different between the built in add-on and the file system library when called from a third party library.

I've updated my rule templates to pass toString() of the ZonedDateTime instead of the raw Object which solves my immediate problem with my template users. But I'd like to understand why the behavior is different so I can fix it in openhab_rules_tools, here, the add-on, or at least understand why it works this way.

Hopefully this gives you enough to reproduce it? I know it's not just on my system because I've had several of my rule template users run into the problem.

The following is where the problem lies I think, at least code wise.

  // Pass through if already a time.ZonedDateTime
  if (when instanceof time.ZonedDateTime) {
    return when;
  }

Why would instanceof fail here? I can't add logging to inspect the Object because it only errors when using the embedded library.

florian-h05 commented 10 months ago

when testing with the not installed openhab-js library I uninstall openhab through npm

Out of interest: Can you please keep openhab from npm installed and set the add-on to use the internal version? Does the error occur then?

and manually remove @jods-js since it doesn't get uninstalled automatically for some reason, worth an issue?

If npm rm openhab does not remove js-joda, this probably is a npm issue or by design. I don’t know.

Reading through your stacktrace (the interesting part is at <js>., the Java part can be omitted completely), I can see that your library calls time.toZDT, which throws the error at node_modules/openhab.js. That is the webpacked, but not cached version of the library which is used by require if there is no openhab npm module on the file system.

I have the same suspect for the root cause of the problem, you should be able to add logging there. Just add your logging, then npm run webpack, copy dist/openhab.js to the node_modules folder of your openHAB machine and reload the script/disable and then enable the script.

rkoshak commented 10 months ago

Out of interest: Can you please keep openhab from npm installed and set the add-on to use the internal version? Does the error occur then?

With the library installed on the file system but the add-on configured to use the internal version the error still occurs. However, the line number and path to the file for time.toZDT changed from the above. It looks like it's picking up the library from the file system but for some reason still has the same error.

  │2023-09-05 09:18:19.494 [ERROR] [b.automation.script.javascript.stack] - Failed to execute script:                                                                                            │
  │org.graalvm.polyglot.PolyglotException: Error: "2023-09-05T09:18:19.492-06:00[SYSTEM]" is an unsupported type for conversion to time.ZonedDateTime                                            │
  │        at <js>.toZDT(/openhab/conf/automation/js/node_modules/openhab/time.js:266) ~[?:?]                                                                                                    │
  │        at <js>.check(/openhab/conf/automation/js/node_modules/openhab_rules_tools/timerMgr.js:46) ~[?:?]                                                                                     │
  │        at <js>.:program(<eval>:19) ~[?:?]                                                                                                                                                    │
  │        at org.graalvm.polyglot.Context.eval(Context.java:399) ~[?:?]

When I switch to not use the webpacked library there is no error.

So it seems the error always occurs when the add-on is configured to use the embedded library even though it appears that OHRT is pulling the library from the file system.

I'll come back with the results of adding some logging later today when I get a chance to do it.

I've updated my rule templates temporarily to call toString() to avoid this error for now so the pressure is off from my perspective. I'd still like to know what's going on though. It's really odd.

florian-h05 commented 6 months ago

@rkoshak I have fixed that in #312. The problem was quite complicated, it was caused because some instanceof checks were not reliably working in the webpacked version for injection caching, because webpack is throwing away constructor names. I have just built the addon with the new library version, and verified with your script that my fix works.

I will now create a PR to get this into 4.1.0.

BTW: I've sent you a LinkedIn request, can you please accept it?

rkoshak commented 6 months ago

I'm very rarely on LinkedIn. I should probably shut my account down. In the mean time I'll go accept it.