JSR233 Jython - Scripts loaded and executed to early

Hi,

i have installed jsr233 with jython. Works perfekt and very fast!

But i have a problem. During startup of obenhab the .jy scripts will be loaded and executed before any other configuration-files are loaded (like items and other rules). Then the py script fails to init, because i use a CommandEventTrigger Listener. The item of the listener could not be found at this moment, so the scipt will not work, even if openhab is completly started. If i touch the script after openhab is completly started, my script works.

How can i get this working after a restart?

Therre is anouter topic without answer: jsr223: Delayed loading after startup

Thank you and greetings
Dennis

2016-02-08 18:08:27.061 [INFO ] [o.c.j.i.e.scriptmanager.Script] - Loading Script rollaeden.py 2016-02-08 18:08:36.427 [INFO ] [o.c.j.i.e.scriptmanager.Script] - EngineName: jython 2016-02-08 18:08:39.443 [ERROR] [o.o.c.j.i.e.s.ScriptManager ] - script exception javax.script.ScriptException: org.openhab.core.items.ItemNotFoundException: org.openhab.core.items.ItemNotFoundException: Item 'RollaedenAlle' could not be found in the item registry in script at line number 117 at org.python.jsr223.PyScriptEngine.scriptException(PyScriptEngine.java:202) ~[jython.jar:na] at org.python.jsr223.PyScriptEngine.invokeFunction(PyScriptEngine.java:132) ~[jython.jar:na] at org.openhab.core.jsr223.internal.engine.scriptmanager.Script.loadScript(Script.java:93) ~[bundlefile:na] at org.openhab.core.jsr223.internal.engine.scriptmanager.Script.(Script.java:79) ~[bundlefile:na] at org.openhab.core.jsr223.internal.engine.scriptmanager.ScriptManager.loadScript(ScriptManager.java:90) [bundlefile:na] at org.openhab.core.jsr223.internal.engine.scriptmanager.ScriptManager.loadScripts(ScriptManager.java:79) [bundlefile:na] at org.openhab.core.jsr223.internal.engine.scriptmanager.ScriptManager.(ScriptManager.java:68) [bundlefile:na] at org.openhab.core.jsr223.internal.engine.Jsr223Engine.activate(Jsr223Engine.java:71) [bundlefile:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0] at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0] at org.eclipse.equinox.internal.ds.model.ServiceComponent.activate(ServiceComponent.java:235) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.model.ServiceComponentProp.activate(ServiceComponentProp.java:146) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.model.ServiceComponentProp.build(ServiceComponentProp.java:345) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.InstanceProcess.buildComponent(InstanceProcess.java:620) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.InstanceProcess.buildComponents(InstanceProcess.java:197) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.Resolver.buildNewlySatisfied(Resolver.java:473) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.Resolver.enableComponents(Resolver.java:217) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.SCRManager.performWork(SCRManager.java:816) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.SCRManager$QueuedJob.dispatch(SCRManager.java:783) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.ds.WorkThread.run(WorkThread.java:89) [org.eclipse.equinox.ds_1.4.1.v20120926-201320.jar:na] at org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor.run(Executor.java:70) [org.eclipse.equinox.util_1.0.400.v20120917-192807.jar:na] Caused by: org.python.core.PyException: null at org.python.core.Py.JavaError(Py.java:546) ~[jython.jar:na] at org.python.core.Py.JavaError(Py.java:537) ~[jython.jar:na] at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:188) ~[jython.jar:na] at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:204) ~[jython.jar:na] at org.python.core.PyObject.__call__(PyObject.java:478) ~[jython.jar:na] at org.python.core.PyObject.__call__(PyObject.java:482) ~[jython.jar:na] at org.python.core.PyMethod.__call__(PyMethod.java:141) ~[jython.jar:na] at org.python.pycode._pyx0.__init__$12(:104) ~[na:na] at org.python.pycode._pyx0.call_function() ~[na:na] at org.python.core.PyTableCode.call(PyTableCode.java:167) ~[jython.jar:na] at org.python.core.PyBaseCode.call(PyBaseCode.java:307) ~[jython.jar:na] at org.python.core.PyBaseCode.call(PyBaseCode.java:198) ~[jython.jar:na] at org.python.core.PyFunction.__call__(PyFunction.java:482) ~[jython.jar:na] at org.python.core.PyMethod.instancemethod___call__(PyMethod.java:237) ~[jython.jar:na] at org.python.core.PyMethod.__call__(PyMethod.java:228) ~[jython.jar:na] at org.python.core.PyMethod.__call__(PyMethod.java:223) ~[jython.jar:na] at org.python.core.Deriveds.dispatch__init__(Deriveds.java:19) ~[jython.jar:na] at org.python.core.PyObjectDerived.dispatch__init__(PyObjectDerived.java:1112) ~[jython.jar:na] at org.python.core.PyType.type___call__(PyType.java:1713) ~[jython.jar:na] at org.python.core.PyType.__call__(PyType.java:1696) ~[jython.jar:na] at org.python.core.PyObject.__call__(PyObject.java:461) ~[jython.jar:na] at org.python.core.PyObject.__call__(PyObject.java:465) ~[jython.jar:na] at org.python.pycode._pyx0.getRules$15(:117) ~[na:na] at org.python.pycode._pyx0.call_function() ~[na:na] at org.python.core.PyTableCode.call(PyTableCode.java:167) ~[jython.jar:na] at org.python.core.PyBaseCode.call(PyBaseCode.java:307) ~[jython.jar:na] at org.python.core.PyFunction.function___call__(PyFunction.java:471) ~[jython.jar:na] at org.python.core.PyFunction.__call__(PyFunction.java:466) ~[jython.jar:na] at org.python.core.PyFunction.__call__(PyFunction.java:456) ~[jython.jar:na] at org.python.core.PyFunction.__call__(PyFunction.java:451) ~[jython.jar:na] at org.python.jsr223.PyScriptEngine.invokeFunction(PyScriptEngine.java:126) ~[jython.jar:na] ... 21 common frames omitted Caused by: org.openhab.core.items.ItemNotFoundException: Item 'RollaedenAlle' could not be found in the item registry at org.openhab.core.internal.items.ItemRegistryImpl.getItem(ItemRegistryImpl.java:80) ~[na:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0] at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0] at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:186) ~[jython.jar:na] ... 49 common frames omitted

Try to “play around” with your openhab.cfg settings:

default values are:

folder:items=10,items
folder:sitemaps=10,sitemap
folder:rules=10,rules
folder:scripts=10,script
folder:persistence=10,persist

So in your case you could try:

folder:items=20,items
folder:sitemaps=26,sitemap
folder:rules=30,rules
folder:scripts=24,script
folder:persistence=22,persist

so that scripts are loaded later. Or if you need to load your scripts even after rules set the scripts to 32.

I have the same problem.
See Thread

The timing options script and rules doesn’t work when you use jsr223.

So all my scripts try to read items on startup before they are initialized…

[quote=“seppdog, post:3, topic:7338, full:true”]
The timing options script and rules doesn’t work when you use jsr223.[/quote]

Sorry, didn’t know …

Hi,

hm, ok. Did you find another workaround?

Is there already an issue?

Maybe a config parameter could solve the problem, so that den jsr233 addon wait x seconds after activating the addon before loading scripts.

Greetings
Dennis

I have many JSR223 Jython rules and I don’t have this problem. If you could provide enough information to reproduce the issue I could do some investigation. The initial description doesn’t make sense to me. When a command trigger event is given to a rule, the event argument to the execute function contains the item so I’m not understanding how an item lookup would fail. Are you trying to do the item lookup in the rule constructor when getRules is called?

Hi,

oh, of course. I used the the item lookup in the constructor to just once get the items (self.itemName) and not with every execution. Thanks. No it works. Thank you!

Greetings
Dennis

It seems that I have the problem when I use inits like:

def __init__(self):
        oh.sendCommand("Item", "OFF")

The inits are called before the initialization of the items I think.

Also, there is a problem when I save such files while opnehab is running.
Sometimes I get the following error message:

2016-02-12 22:01:00.787 [ERROR] [org.openhab.core.jsr223.internal.engine.scriptmanager.ScriptManager   ] - Script file misses mandotary function: getRules()
    java.lang.NoSuchMethodException: getRules
    	at org.python.jsr223.PyScriptEngine.invokeFunction(PyScriptEngine.java:122) ~[jython.jar:na]
    	at org.openhab.core.jsr223.internal.engine.scriptmanager.Script.loadScript(Script.java:93) ~[bundlefile:na]
    	at org.openhab.core.jsr223.internal.engine.scriptmanager.Script.<init>(Script.java:79) ~[bundlefile:na]
    	at org.openhab.core.jsr223.internal.engine.scriptmanager.ScriptManager.loadScript(ScriptManager.java:90) [bundlefile:na]
    	at org.openhab.core.jsr223.internal.engine.scriptmanager.ScriptManager.scriptsChanged(ScriptManager.java:185) [bundlefile:na]
    	at org.openhab.core.jsr223.internal.engine.scriptmanager.ScriptUpdateWatcher.run(ScriptUpdateWatcher.java:105) [bundlefile:na]
    	at java.lang.Thread.run(Unknown Source) [na:1.8.0_66]

When I get this error I have to save the file again and again until the error doesnt came up.

Yes, items shouldn’t be accessed in the rule constructors. In your example, the OFF command can be sent safely by using a StartupTrigger.

I’ve seen the other error occasionally. My guess is it caused when a file change event is processed before the file is completely written to the disk. If this is true, it would happen more often for larger files or for files being edited over a network connection since they would take longer to be fully written to the disk.