Simplified Jython rule definition (similar to Rules DSL) using a universal decorator

5iver · April 16, 2019, 6:48am

Did you put it after the function definition?

@rule("StatePublish")
@when ("Time cron 0 0 0/1 * * ?")
def statepublish(event):   
    for member in ir.getItem("Stats").members:
        membername = ''.join(re.findall("^\S*", str(member)))
        memberstate = str(ir.getItem(membername).state)
        actions.get("mqtt","mqtt:broker:f79d2a84").publishMQTT("allItemsout/"

statepublish(None)

JGKK · April 16, 2019, 6:53am

that did it thanks

lukics · May 20, 2019, 3:25pm

Would it be possible to extend the decoration to the class level.
something like:

@rule("test time rule", tags=["Tag 1", "Tag 2"])
@when("Channel homematic:HM-PB-6-WM55:3014F711A061A7D5698CE994:NEQ1001667:1#BUTTON triggered SHORT_PRESSED")
@when("Channel homematic:HM-PB-6-WM55:3014F711A061A7D5698CE994:NEQ1001667:1#BUTTON triggered DOUBLE_PRESSED")
class MyRule(MyOtherClass, YetAntherClass):  
    def execute(self, module, input):
        events.postUpdate("TestString2", "some data")

5iver · May 20, 2019, 3:38pm

The rule decorator does work on classes. I believe this would be possible for the when decorator too. But TBH, I don’t think I’ll ever get to it, since I do not have or see the need. Other developers are welcome to contribute though!

What are you trying to do that can’t use a function for the action? Or by using the class in a function?

scottk · May 20, 2019, 3:40pm

Here is a simple example of using the decorators with an instance of a class:

from org.slf4j import Logger, LoggerFactory

from openhab import osgi
from openhab.rules import rule
from openhab.triggers import when
import openhab.rules
reload(openhab.rules)
import openhab.triggers
reload(openhab.triggers)
from openhab.rules import rule
from openhab.triggers import when


ruleEngine = osgi.get_service("org.eclipse.smarthome.automation.RuleManager")

class GroupLister:
    def __init__(self, instName):
        self.__name__ = instName
        self.logger = LoggerFactory.getLogger("org.eclipse.smarthome.model.script.Rules.%s" %
                                              self.__class__.__name__)
        self.logger.info("Instantiating instance of class %s" %
                         self.__class__.__name__)

    def __call__(self, event):
        self.logger.info("'%s' action (Jython cron rule)" % self.__name__)

        self.logger.info("All Group items:")
        for gItem in sorted(item for item in ir.getItemsOfType("Group"),
                            key = lambda item: item.name):
            self.logger.info("==> %s" % gItem)
            map(lambda mbr: self.logger.info("  |-- %s" % mbr),
                sorted(gMbr for gMbr in gItem.members,
                       key = lambda mItem: mItem.name))

        ruleEngine.setEnabled(self.UID, False) # one-shot rule


logger = LoggerFactory.getLogger("org.eclipse.smarthome.model.script.jsr223")

# requires rule and when imports
ruleInst1 = rule("Group Test Rule")(
            when("Time cron 10 0/1 * * * ?")
                (GroupLister("ruleInst1")))

logger.info("ruleInst1 attributes & methods: %s" % dir(ruleInst1))

Note that I coded that up some time ago, so the imports may no longer be valid.

lukics · May 20, 2019, 5:18pm

After fixing the imports I get at line

2019-05-20 19:12:10.071 [ERROR] [jsr223.jython.Group Test Rule       ] - Traceback (most recent call last):
  File "/openhab/conf/automation/lib/python/core/log.py", line 43, in wrapper
    return fn(*args, **kwargs)
  File "<script>", line 35, in __call__
AttributeError: GroupLister instance has no attribute 'UID'

I have another question:
In the example, the

__call__

hook is used, which method is actually called. This would make impossible to define other methods.

5iver · May 20, 2019, 5:32pm

I found this again while looking for @scottk’s previous discussion of the one shot rules . If you define a scriptUnloaded function, it will be called when the script is unloaded. There is a scriptLoaded function too. ScriptEngineManager calls these when loading/unloading scripts. You might be able to utilize this for cancelling your timer.

scottk · May 20, 2019, 6:00pm

You must be running a post-ESH migration snapshot. I haven’t run the example script on anything but an older OH2 snapshot.

I suspect the means of accessing the rule’s UID has changed.

The intent of this design is to allow multiple, unique instances of a single class to be used in multiple rules.

5iver · May 20, 2019, 6:17pm

This one is all on me . Looks like I didn’t do a pull before pushing the openhab->core rename and that last two commits which added the UID were lost . I’ll put it back in today after pushing the new directory structure that includes the other languages.

lukics · May 20, 2019, 7:29pm

the __call __ intercepts any method call, which method is actually called here.

scottk · May 20, 2019, 7:40pm

Correct, but my idea is that there will be some class instantiation parameters that will differ from instance to instance. The __call__ method allows the instance to be invoked as though it was a function, which is required by the rule decorator, since a class instance object is not a class.

FredericMa · May 21, 2019, 6:14pm

Hi,

I’m planning on upgrading my production system to the latest snapshot and Jython libraries.
I made a small test setup with snapshot 1597 (of today) and the Jython libraries downloaded 19:43 today, so it also includes the last commits. Note: I’m on Windows.
I don’t see any errors but it looks like (some) script are not loaded.
I’m missing the output of the 000_startup_delay.py script which I do see in my current production environment. I also placed the hello_world.py script in automation\jsr223\python\personal but I also don’t see any output from it.
When I touch the 000_startup_delay.py script (add a newline for example) and save it, it loads correctly but only the 000_startup_delay.py script.
This is the output after touching the startup delay script:

2019-05-21 20:03:23.596 [INFO ] [rt.internal.loader.ScriptFileWatcher] - Loading script 'python/core/000_startup_delay.py'
2019-05-21 20:03:27.052 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py
2019-05-21 20:03:27.080 [INFO ] [tomation.jsr223.jython.startup_delay] - Checking for initialized context
2019-05-21 20:03:27.085 [INFO ] [tomation.jsr223.jython.startup_delay] - Context initialized... waiting 30s before allowing scripts to load
2019-05-21 20:03:57.087 [INFO ] [tomation.jsr223.jython.startup_delay] - Complete
2019-05-21 20:03:57.088 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - Script loaded: python/core/000_startup_delay.py

No other files are loaded.
The EXTRA_JAVA_OPTS are configured in setenv.bat like this:

set EXTRA_JAVA_OPTS=-XX:+UseG1GC ^
  -Djava.awt.headless=true ^
  -Xbootclasspath/a:C:\Temp\OpenHAB_Jython\conf\automation\jython\jython-standalone-2.7.0.jar ^
  -Dpython.home=C:\Temp\OpenHAB_Jython\conf\automation\jython ^
  -Dpython.path=C:\Temp\OpenHAB_Jython\conf\automation\lib\python ^
  -Dfile.encoding=UTF-8

Any ideas?
Thanks!

Greetings,
Frederic

5iver · May 21, 2019, 7:57pm

If you use any of the component scripts, then grab the latest… one of the imports was missing.

Just to confirm… you mean after an OH restart?

The startup delay script only helps after an OH restart, as it prevents other scripts from loading until it has completed loading. Make sure you have your logging level set to DEBUG, as that’s the level most of the logs are set to… log:set DEBUG jsr223. Did you rename the configuration.py.example file? If you haven’t looked lately,the setup has evolved slightly.

FredericMa · May 21, 2019, 8:13pm

Thanks for your quick reply!

At the moment I only try to run the hello_world script. I just downloaded the repo again with your last commit but I have the same result.

Yes indeed.

Yes I did, I figured it out since I got an error that it failed to import configuration.

Just a thought, I’m running an empty OpenHAB with only 3 dummy items. No rules etc.
Could that be an issue?

This is the complete startup log with jsr223 and automation logging set to DEBUG:

2019-05-21 22:12:22.480 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.50.149
2019-05-21 22:12:22.653 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 172.22.64.33
2019-05-21 22:12:26.256 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.50.149
2019-05-21 22:12:26.399 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 172.22.64.33
2019-05-21 22:12:30.598 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.items'
2019-05-21 22:12:32.428 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2019-05-21 22:12:33.246 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://10.0.75.1:8080
2019-05-21 22:12:33.247 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://10.0.75.1:8443
2019-05-21 22:12:33.620 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2019-05-21 22:12:33.732 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2019-05-21 22:12:33.806 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2019-05-21 22:12:33.813 [DEBUG] [org.openhab.core.automation         ] - BundleEvent STARTING - org.openhab.core.automation
2019-05-21 22:12:33.830 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleProvider, org.openhab.core.automation.ManagedRuleProvider}={service.id=364, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.ManagedRuleProvider, component.id=206} - org.openhab.core.automation
2019-05-21 22:12:33.837 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventFactory}={service.id=365, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.RuleEventFactory, component.id=208} - org.openhab.core.automation
2019-05-21 22:12:33.845 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=366, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.factory.CoreModuleHandlerFactory, component.id=211} - org.openhab.core.automation
2019-05-21 22:12:33.850 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=367, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.handler.TimerModuleHandlerFactory, component.id=212} - org.openhab.core.automation
2019-05-21 22:12:33.860 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=368, service.bundleid=209, service.scope=bundle, parser.type=parser.module.type, component.name=org.openhab.core.automation.internal.parser.gson.ModuleTypeGSONParser, format=json, component.id=214} - org.openhab.core.automation
2019-05-21 22:12:33.863 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=369, service.bundleid=209, service.scope=bundle, parser.type=parser.rule, component.name=org.openhab.core.automation.internal.parser.gson.RuleGSONParser, format=json, component.id=215} - org.openhab.core.automation
2019-05-21 22:12:33.865 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=370, service.bundleid=209, service.scope=bundle, parser.type=parser.template, component.name=org.openhab.core.automation.internal.parser.gson.TemplateGSONParser, format=json, component.id=216} - org.openhab.core.automation
2019-05-21 22:12:33.947 [DEBUG] [.AutomationResourceBundlesEventQueue] - Process bundle event 2, for automation bundle 'org.openhab.core.automation' 
2019-05-21 22:12:33.948 [DEBUG] [.AutomationResourceBundlesEventQueue] - Process bundle event 32, for automation bundle 'org.openhab.core.automation.module.script.rulesupport' 
2019-05-21 22:12:33.950 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.osgi.util.tracker.BundleTrackerCustomizer}={service.id=371, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.rule), Provider.target=(provider.type=bundle), component.name=org.openhab.core.automation.internal.provider.AutomationResourceBundlesTracker, component.id=217} - org.openhab.core.automation
2019-05-21 22:12:33.956 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider, org.eclipse.smarthome.core.common.registry.Provider}={service.id=372, provider.type=bundle, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.template), component.name=org.openhab.core.automation.internal.provider.TemplateResourceBundleProvider, component.id=219} - org.openhab.core.automation
2019-05-21 22:12:33.965 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=373, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.module.type), component.name=org.openhab.core.automation.internal.provider.file.ModuleTypeFileProviderWatcher, component.id=220} - org.openhab.core.automation
2019-05-21 22:12:33.974 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider}={service.id=374, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.template), component.name=org.openhab.core.automation.internal.provider.file.TemplateFileProviderWatcher, component.id=221} - org.openhab.core.automation
2019-05-21 22:12:33.986 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=376, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.provider.AnnotatedActionModuleTypeProvider, component.id=213} - org.openhab.core.automation
2019-05-21 22:12:33.991 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.eclipse.smarthome.core.common.registry.Provider}={service.id=377, provider.type=bundle, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.module.type), component.name=org.openhab.core.automation.internal.provider.ModuleTypeResourceBundleProvider, component.id=218} - org.openhab.core.automation
2019-05-21 22:12:33.993 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.provider.i18n.ModuleTypeI18nService}={service.id=375, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.provider.i18n.ModuleTypeI18nServiceImpl, component.id=222} - org.openhab.core.automation
2019-05-21 22:12:34.003 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.TemplateRegistry, org.openhab.core.automation.internal.template.RuleTemplateRegistry}={service.id=378, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.template.RuleTemplateRegistry, component.id=223} - org.openhab.core.automation
2019-05-21 22:12:34.032 [DEBUG] [.provider.RuleResourceBundleImporter] - Parse rules from bundle 'org.openhab.core.automation' 
2019-05-21 22:12:34.034 [DEBUG] [.provider.RuleResourceBundleImporter] - Parse rules from bundle 'org.openhab.core.automation.module.script.rulesupport' 
2019-05-21 22:12:34.090 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added CoreModuleHandlerFactory
2019-05-21 22:12:34.091 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added TimerModuleHandlerFactory
2019-05-21 22:12:34.093 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added AnnotatedActionModuleTypeProvider
2019-05-21 22:12:34.095 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleManager, org.eclipse.smarthome.core.common.registry.RegistryChangeListener}={service.id=381, service.bundleid=209, service.scope=bundle, rule.reinitialization.delay=500, component.name=org.openhab.core.automation.internal.RuleEngineImpl, component.id=207} - org.openhab.core.automation
2019-05-21 22:12:34.096 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleRegistry}={service.id=380, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.RuleRegistryImpl, component.id=209} - org.openhab.core.automation
2019-05-21 22:12:34.103 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=383, service.bundleid=209, service.scope=singleton} - org.openhab.core.automation
2019-05-21 22:12:34.106 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider}={service.id=384, service.bundleid=209, service.scope=singleton} - org.openhab.core.automation
2019-05-21 22:12:34.109 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.console.extensions.ConsoleCommandExtension}={service.id=382, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.commands.AutomationCommandsPluggable, component.id=210} - org.openhab.core.automation
2019-05-21 22:12:34.110 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeRegistry}={service.id=379, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.type.ModuleTypeRegistryImpl, component.id=224} - org.openhab.core.automation
2019-05-21 22:12:34.114 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added AnnotatedThingActionModuleTypeProvider
2019-05-21 22:12:34.115 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=385, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.thingsupport.AnnotatedThingActionModuleTypeProvider, component.id=225} - org.openhab.core.automation
2019-05-21 22:12:34.116 [DEBUG] [org.openhab.core.automation         ] - BundleEvent STARTED - org.openhab.core.automation
2019-05-21 22:12:34.117 [DEBUG] [openhab.core.automation.module.media] - BundleEvent STARTING - org.openhab.core.automation.module.media
2019-05-21 22:12:34.141 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=386, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaActionTypeProvider, component.id=226} - org.openhab.core.automation.module.media
2019-05-21 22:12:34.146 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added MediaModuleHandlerFactory
2019-05-21 22:12:34.147 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=387, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaModuleHandlerFactory, component.id=227} - org.openhab.core.automation.module.media
2019-05-21 22:12:34.151 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=388, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaScriptScopeProvider, component.id=228} - org.openhab.core.automation.module.media
2019-05-21 22:12:34.151 [DEBUG] [openhab.core.automation.module.media] - BundleEvent STARTED - org.openhab.core.automation.module.media
2019-05-21 22:12:34.152 [DEBUG] [penhab.core.automation.module.script] - BundleEvent STARTING - org.openhab.core.automation.module.script
2019-05-21 22:12:34.158 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineFactory}={service.id=389, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.GenericScriptEngineFactory, component.id=229} - org.openhab.core.automation.module.script
2019-05-21 22:12:34.163 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineFactory}={service.id=390, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.NashornScriptEngineFactory, component.id=230} - org.openhab.core.automation.module.script
2019-05-21 22:12:34.179 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added GenericScriptEngineFactory
2019-05-21 22:12:34.182 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_131): supports ECMAScript (ECMA - 262 Edition 5.1) with file extensions [js], names [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], and mimetypes [application/javascript, application/ecmascript, text/javascript, text/ecmascript]
2019-05-21 22:12:34.183 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added NashornScriptEngineFactory
2019-05-21 22:12:34.183 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_131): supports ECMAScript (ECMA - 262 Edition 5.1) with file extensions [js], names [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], and mimetypes [application/javascript, application/ecmascript, text/javascript, text/ecmascript]
2019-05-21 22:12:34.185 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Removed GenericScriptEngineFactory
2019-05-21 22:12:34.186 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Removed NashornScriptEngineFactory
2019-05-21 22:12:34.187 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineManager}={service.id=392, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl, component.id=231} - org.openhab.core.automation.module.script
2019-05-21 22:12:34.187 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.internal.ScriptExtensionManager}={service.id=391, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.ScriptExtensionManager, component.id=232} - org.openhab.core.automation.module.script
2019-05-21 22:12:34.198 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=393, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.defaultscope.DefaultScriptScopeProvider, component.id=233} - org.openhab.core.automation.module.script
2019-05-21 22:12:34.200 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added GenericScriptEngineFactory
2019-05-21 22:12:34.201 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_131): supports ECMAScript (ECMA - 262 Edition 5.1) with file extensions [js], names [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], and mimetypes [application/javascript, application/ecmascript, text/javascript, text/ecmascript]
2019-05-21 22:12:34.202 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added NashornScriptEngineFactory
2019-05-21 22:12:34.203 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_131): supports ECMAScript (ECMA - 262 Edition 5.1) with file extensions [js], names [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], and mimetypes [application/javascript, application/ecmascript, text/javascript, text/ecmascript]
2019-05-21 22:12:34.205 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptModuleHandlerFactory
2019-05-21 22:12:34.205 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=394, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.factory.ScriptModuleHandlerFactory, component.id=234} - org.openhab.core.automation.module.script
2019-05-21 22:12:34.211 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=395, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.provider.ScriptModuleTypeProvider, component.id=235} - org.openhab.core.automation.module.script
2019-05-21 22:12:34.212 [DEBUG] [penhab.core.automation.module.script] - BundleEvent STARTED - org.openhab.core.automation.module.script
2019-05-21 22:12:34.213 [DEBUG] [automation.module.script.rulesupport] - BundleEvent STARTING - org.openhab.core.automation.module.script.rulesupport
2019-05-21 22:12:34.246 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptedCustomModuleHandlerFactory
2019-05-21 22:12:34.247 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleHandlerFactory, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=396, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleHandlerFactory, component.id=237} - org.openhab.core.automation.module.script.rulesupport
2019-05-21 22:12:34.249 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleTypeProvider, org.openhab.core.automation.type.ModuleTypeProvider}={service.id=397, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleTypeProvider, component.id=238} - org.openhab.core.automation.module.script.rulesupport
2019-05-21 22:12:34.252 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptedPrivateModuleHandlerFactory
2019-05-21 22:12:34.253 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedPrivateModuleHandlerFactory, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=398, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedPrivateModuleHandlerFactory, component.id=239} - org.openhab.core.automation.module.script.rulesupport
2019-05-21 22:12:34.291 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md]}
2019-05-21 22:12:34.294 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md]}
2019-05-21 22:12:34.296 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md]}
2019-05-21 22:12:34.297 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js]}
2019-05-21 22:12:34.299 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js]}
2019-05-21 22:12:34.301 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py]}
2019-05-21 22:12:34.306 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py]}
2019-05-21 22:12:34.307 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.309 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.311 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.313 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.317 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.320 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.321 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.324 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.329 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonTransform.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-21 22:12:34.331 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonTransform.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/personal/hello_world.py]}
2019-05-21 22:12:34.344 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=400, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.RuleSupportScriptExtension, component.id=236} - org.openhab.core.automation.module.script.rulesupport
2019-05-21 22:12:34.346 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.shared.ScriptedRuleProvider, org.openhab.core.automation.RuleProvider}={service.id=399, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.shared.ScriptedRuleProvider, component.id=241} - org.openhab.core.automation.module.script.rulesupport
2019-05-21 22:12:34.347 [DEBUG] [automation.module.script.rulesupport] - BundleEvent STARTED - org.openhab.core.automation.module.script.rulesupport
2019-05-21 22:12:34.349 [DEBUG] [org.openhab.core.automation.rest    ] - BundleEvent STARTING - org.openhab.core.automation.rest
2019-05-21 22:12:34.364 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=401, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.ModuleTypeResource, component.id=242} - org.openhab.core.automation.rest
2019-05-21 22:12:34.372 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=402, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.RuleResource, component.id=243} - org.openhab.core.automation.rest
2019-05-21 22:12:34.382 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=403, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.TemplateResource, component.id=244} - org.openhab.core.automation.rest
2019-05-21 22:12:34.385 [DEBUG] [org.openhab.core.automation.rest    ] - BundleEvent STARTED - org.openhab.core.automation.rest

5iver · May 21, 2019, 9:21pm

It looks like your Jython is not in the classpath. Maybe check the permissions? You should see a log entry like this…

2019-05-21 08:00:59.075 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.2): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]

What’s confusing me is that you said when you touched/saved the startup delay script it ran. I don’t see how that is possible. Do you see a log entry like that anywhere in your log for Jython?

Not an issue. There used to be a problem with having zero Items, but I recently corrected that.

FredericMa · May 22, 2019, 8:05am

Probably I messed up the logs during my tests. I also did a test where a removed the classpath to see the difference. It looks like I uploaded that log file…

This is the correct log and here you see the log message you are referring to but also in this case the files are not loaded:

2019-05-22 09:59:23.507 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 172.25.16.46
2019-05-22 09:59:23.535 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.50.224
2019-05-22 09:59:23.576 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 10.4.41.53
2019-05-22 09:59:23.743 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 172.22.64.33
2019-05-22 09:59:30.574 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.items'
2019-05-22 09:59:32.616 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2019-05-22 09:59:33.257 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://10.0.75.1:8080
2019-05-22 09:59:33.259 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://10.0.75.1:8443
2019-05-22 09:59:33.666 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2019-05-22 09:59:33.798 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2019-05-22 09:59:33.957 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2019-05-22 09:59:33.965 [DEBUG] [org.openhab.core.automation         ] - BundleEvent STARTING - org.openhab.core.automation
2019-05-22 09:59:33.971 [DEBUG] [org.openhab.core.automation         ] - BundleEvent STARTED - org.openhab.core.automation
2019-05-22 09:59:33.983 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleProvider, org.openhab.core.automation.ManagedRuleProvider}={service.id=364, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.ManagedRuleProvider, component.id=206} - org.openhab.core.automation
2019-05-22 09:59:33.994 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventFactory}={service.id=365, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.RuleEventFactory, component.id=208} - org.openhab.core.automation
2019-05-22 09:59:33.998 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=366, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.factory.CoreModuleHandlerFactory, component.id=211} - org.openhab.core.automation
2019-05-22 09:59:34.008 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=367, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.handler.TimerModuleHandlerFactory, component.id=212} - org.openhab.core.automation
2019-05-22 09:59:34.051 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=368, service.bundleid=209, service.scope=bundle, parser.type=parser.module.type, component.name=org.openhab.core.automation.internal.parser.gson.ModuleTypeGSONParser, format=json, component.id=214} - org.openhab.core.automation
2019-05-22 09:59:34.058 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=369, service.bundleid=209, service.scope=bundle, parser.type=parser.rule, component.name=org.openhab.core.automation.internal.parser.gson.RuleGSONParser, format=json, component.id=215} - org.openhab.core.automation
2019-05-22 09:59:34.061 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=370, service.bundleid=209, service.scope=bundle, parser.type=parser.template, component.name=org.openhab.core.automation.internal.parser.gson.TemplateGSONParser, format=json, component.id=216} - org.openhab.core.automation
2019-05-22 09:59:34.066 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.osgi.util.tracker.BundleTrackerCustomizer}={service.id=371, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.rule), Provider.target=(provider.type=bundle), component.name=org.openhab.core.automation.internal.provider.AutomationResourceBundlesTracker, component.id=217} - org.openhab.core.automation
2019-05-22 09:59:34.177 [DEBUG] [.AutomationResourceBundlesEventQueue] - Process bundle event 2, for automation bundle 'org.openhab.core.automation' 
2019-05-22 09:59:34.179 [DEBUG] [.AutomationResourceBundlesEventQueue] - Process bundle event 32, for automation bundle 'org.openhab.core.automation.module.script.rulesupport' 
2019-05-22 09:59:34.187 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider, org.eclipse.smarthome.core.common.registry.Provider}={service.id=372, provider.type=bundle, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.template), component.name=org.openhab.core.automation.internal.provider.TemplateResourceBundleProvider, component.id=219} - org.openhab.core.automation
2019-05-22 09:59:34.189 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=373, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.module.type), component.name=org.openhab.core.automation.internal.provider.file.ModuleTypeFileProviderWatcher, component.id=220} - org.openhab.core.automation
2019-05-22 09:59:34.197 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider}={service.id=374, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.template), component.name=org.openhab.core.automation.internal.provider.file.TemplateFileProviderWatcher, component.id=221} - org.openhab.core.automation
2019-05-22 09:59:34.209 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=376, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.provider.AnnotatedActionModuleTypeProvider, component.id=213} - org.openhab.core.automation
2019-05-22 09:59:34.280 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.eclipse.smarthome.core.common.registry.Provider}={service.id=377, provider.type=bundle, service.bundleid=209, service.scope=bundle, Parser.target=(parser.type=parser.module.type), component.name=org.openhab.core.automation.internal.provider.ModuleTypeResourceBundleProvider, component.id=218} - org.openhab.core.automation
2019-05-22 09:59:34.283 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.provider.i18n.ModuleTypeI18nService}={service.id=375, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.provider.i18n.ModuleTypeI18nServiceImpl, component.id=222} - org.openhab.core.automation
2019-05-22 09:59:34.286 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.TemplateRegistry, org.openhab.core.automation.internal.template.RuleTemplateRegistry}={service.id=378, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.template.RuleTemplateRegistry, component.id=223} - org.openhab.core.automation
2019-05-22 09:59:34.292 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleManager, org.eclipse.smarthome.core.common.registry.RegistryChangeListener}={service.id=381, service.bundleid=209, service.scope=bundle, rule.reinitialization.delay=500, component.name=org.openhab.core.automation.internal.RuleEngineImpl, component.id=207} - org.openhab.core.automation
2019-05-22 09:59:34.319 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added CoreModuleHandlerFactory
2019-05-22 09:59:34.363 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added TimerModuleHandlerFactory
2019-05-22 09:59:34.364 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added AnnotatedActionModuleTypeProvider
2019-05-22 09:59:34.365 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleRegistry}={service.id=380, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.RuleRegistryImpl, component.id=209} - org.openhab.core.automation
2019-05-22 09:59:34.384 [DEBUG] [.provider.RuleResourceBundleImporter] - Parse rules from bundle 'org.openhab.core.automation' 
2019-05-22 09:59:34.388 [DEBUG] [.provider.RuleResourceBundleImporter] - Parse rules from bundle 'org.openhab.core.automation.module.script.rulesupport' 
2019-05-22 09:59:34.395 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=383, service.bundleid=209, service.scope=singleton} - org.openhab.core.automation
2019-05-22 09:59:34.409 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider}={service.id=384, service.bundleid=209, service.scope=singleton} - org.openhab.core.automation
2019-05-22 09:59:34.414 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.console.extensions.ConsoleCommandExtension}={service.id=382, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.commands.AutomationCommandsPluggable, component.id=210} - org.openhab.core.automation
2019-05-22 09:59:34.416 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeRegistry}={service.id=379, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.internal.type.ModuleTypeRegistryImpl, component.id=224} - org.openhab.core.automation
2019-05-22 09:59:34.421 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added AnnotatedThingActionModuleTypeProvider
2019-05-22 09:59:34.426 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=385, service.bundleid=209, service.scope=bundle, component.name=org.openhab.core.automation.thingsupport.AnnotatedThingActionModuleTypeProvider, component.id=225} - org.openhab.core.automation
2019-05-22 09:59:34.440 [DEBUG] [openhab.core.automation.module.media] - BundleEvent STARTING - org.openhab.core.automation.module.media
2019-05-22 09:59:34.440 [DEBUG] [openhab.core.automation.module.media] - BundleEvent STARTED - org.openhab.core.automation.module.media
2019-05-22 09:59:34.496 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=386, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaActionTypeProvider, component.id=226} - org.openhab.core.automation.module.media
2019-05-22 09:59:34.500 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added MediaModuleHandlerFactory
2019-05-22 09:59:34.500 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=387, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaModuleHandlerFactory, component.id=227} - org.openhab.core.automation.module.media
2019-05-22 09:59:34.503 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=388, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaScriptScopeProvider, component.id=228} - org.openhab.core.automation.module.media
2019-05-22 09:59:34.506 [DEBUG] [penhab.core.automation.module.script] - BundleEvent STARTING - org.openhab.core.automation.module.script
2019-05-22 09:59:34.507 [DEBUG] [penhab.core.automation.module.script] - BundleEvent STARTED - org.openhab.core.automation.module.script
2019-05-22 09:59:34.511 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineFactory}={service.id=389, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.GenericScriptEngineFactory, component.id=229} - org.openhab.core.automation.module.script
2019-05-22 09:59:34.513 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineFactory}={service.id=390, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.NashornScriptEngineFactory, component.id=230} - org.openhab.core.automation.module.script
2019-05-22 09:59:34.518 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.internal.ScriptExtensionManager}={service.id=391, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.ScriptExtensionManager, component.id=232} - org.openhab.core.automation.module.script
2019-05-22 09:59:34.519 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineManager}={service.id=392, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl, component.id=231} - org.openhab.core.automation.module.script
2019-05-22 09:59:34.549 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added GenericScriptEngineFactory
2019-05-22 09:59:34.551 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_131): supports ECMAScript (ECMA - 262 Edition 5.1) with file extensions [js], names [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], and mimetypes [application/javascript, application/ecmascript, text/javascript, text/ecmascript]
2019-05-22 09:59:34.554 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.0): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]
2019-05-22 09:59:34.555 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added NashornScriptEngineFactory
2019-05-22 09:59:34.556 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_131): supports ECMAScript (ECMA - 262 Edition 5.1) with file extensions [js], names [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], and mimetypes [application/javascript, application/ecmascript, text/javascript, text/ecmascript]
2019-05-22 09:59:34.557 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.0): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]
2019-05-22 09:59:34.559 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Removed GenericScriptEngineFactory
2019-05-22 09:59:34.560 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Removed NashornScriptEngineFactory
2019-05-22 09:59:34.564 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=393, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.defaultscope.DefaultScriptScopeProvider, component.id=233} - org.openhab.core.automation.module.script
2019-05-22 09:59:34.574 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added GenericScriptEngineFactory
2019-05-22 09:59:34.575 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_131): supports ECMAScript (ECMA - 262 Edition 5.1) with file extensions [js], names [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], and mimetypes [application/javascript, application/ecmascript, text/javascript, text/ecmascript]
2019-05-22 09:59:34.576 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.0): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]
2019-05-22 09:59:34.577 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added NashornScriptEngineFactory
2019-05-22 09:59:34.577 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_131): supports ECMAScript (ECMA - 262 Edition 5.1) with file extensions [js], names [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], and mimetypes [application/javascript, application/ecmascript, text/javascript, text/ecmascript]
2019-05-22 09:59:34.578 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.0): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]
2019-05-22 09:59:34.579 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptModuleHandlerFactory
2019-05-22 09:59:34.580 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=394, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.factory.ScriptModuleHandlerFactory, component.id=234} - org.openhab.core.automation.module.script
2019-05-22 09:59:34.629 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=395, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.provider.ScriptModuleTypeProvider, component.id=235} - org.openhab.core.automation.module.script
2019-05-22 09:59:34.631 [DEBUG] [automation.module.script.rulesupport] - BundleEvent STARTING - org.openhab.core.automation.module.script.rulesupport
2019-05-22 09:59:34.632 [DEBUG] [automation.module.script.rulesupport] - BundleEvent STARTED - org.openhab.core.automation.module.script.rulesupport
2019-05-22 09:59:34.641 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptedCustomModuleHandlerFactory
2019-05-22 09:59:34.642 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleHandlerFactory, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=396, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleHandlerFactory, component.id=237} - org.openhab.core.automation.module.script.rulesupport
2019-05-22 09:59:34.644 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleTypeProvider, org.openhab.core.automation.type.ModuleTypeProvider}={service.id=397, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleTypeProvider, component.id=238} - org.openhab.core.automation.module.script.rulesupport
2019-05-22 09:59:34.649 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptedPrivateModuleHandlerFactory
2019-05-22 09:59:34.650 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedPrivateModuleHandlerFactory, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=398, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedPrivateModuleHandlerFactory, component.id=239} - org.openhab.core.automation.module.script.rulesupport
2019-05-22 09:59:34.750 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md]}
2019-05-22 09:59:34.754 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md]}
2019-05-22 09:59:34.756 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md]}
2019-05-22 09:59:34.757 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js]}
2019-05-22 09:59:34.760 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js]}
2019-05-22 09:59:34.761 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py]}
2019-05-22 09:59:34.766 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py]}
2019-05-22 09:59:34.769 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.772 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.776 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.781 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.782 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.784 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.790 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.793 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.796 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonTransform.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py]}
2019-05-22 09:59:34.798 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - in queue: {groovy=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/core/000_startup_delay.groovy], md=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/community/README.md, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/groovy/community/README.md], js=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/javascript/core/000_startup_delay.js], py=[file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_DirectoryTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonExtensionProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_StartupTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonThingProvider.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/200_JythonTransform.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/components/100_OsgiEventTrigger.py, file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/personal/hello_world.py]}
2019-05-22 09:59:34.802 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=400, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.RuleSupportScriptExtension, component.id=236} - org.openhab.core.automation.module.script.rulesupport
2019-05-22 09:59:34.811 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.shared.ScriptedRuleProvider, org.openhab.core.automation.RuleProvider}={service.id=399, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.shared.ScriptedRuleProvider, component.id=241} - org.openhab.core.automation.module.script.rulesupport
2019-05-22 09:59:34.813 [DEBUG] [org.openhab.core.automation.rest    ] - BundleEvent STARTING - org.openhab.core.automation.rest
2019-05-22 09:59:34.814 [DEBUG] [org.openhab.core.automation.rest    ] - BundleEvent STARTED - org.openhab.core.automation.rest
2019-05-22 09:59:34.828 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=401, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.ModuleTypeResource, component.id=242} - org.openhab.core.automation.rest
2019-05-22 09:59:34.843 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=402, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.RuleResource, component.id=243} - org.openhab.core.automation.rest
2019-05-22 09:59:34.850 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=403, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.TemplateResource, component.id=244} - org.openhab.core.automation.rest

When I add a newline to the hello_world.py and save, the script is loaded and starts printing every 10 seconds like it should:

2019-05-22 10:03:16.670 [INFO ] [rt.internal.loader.ScriptFileWatcher] - Loading script 'python/personal/hello_world.py'
2019-05-22 10:03:21.304 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/personal/hello_world.py
2019-05-22 10:03:24.952 [DEBUG] [jsr223.jython.core.triggers         ] - when: target=[Time cron 0/10 * * * * ?], target_type=Time, trigger_target=cron, trigger_type=0/10 * * * * ?, old_state=None, new_state=None
2019-05-22 10:03:26.733 [DEBUG] [jsr223.jython.core.triggers         ] - when: Created cron_trigger: [Cron-helloWorldCronDecorators-130c7f9e7c6811e999521183bc7018a0]
2019-05-22 10:03:26.738 [DEBUG] [jsr223.jython.core.rules            ] - Added rule [Jython Hello World (cron decorators)]
2019-05-22 10:03:26.810 [DEBUG] [le.handler.GenericCronTriggerHandler] - Scheduled cron job '0/10 * * * * ?' for trigger 'Cron-helloWorldCronDecorators-130c7f9e7c6811e999521183bc7018a0'.
2019-05-22 10:03:26.814 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - Script loaded: python/personal/hello_world.py
2019-05-22 10:03:30.803 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger 'Cron-helloWorldCronDecorators-130c7f9e7c6811e999521183bc7018a0' of rule '3b1f580d-3254-4b4a-8470-d7fbb21d0f1b' is triggered.
2019-05-22 10:03:30.807 [INFO ] [Jython Hello World (cron decorators)] - Hello World!
2019-05-22 10:03:30.808 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '3b1f580d-3254-4b4a-8470-d7fbb21d0f1b' is executed.
2019-05-22 10:03:40.805 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger 'Cron-helloWorldCronDecorators-130c7f9e7c6811e999521183bc7018a0' of rule '3b1f580d-3254-4b4a-8470-d7fbb21d0f1b' is triggered.
2019-05-22 10:03:40.807 [INFO ] [Jython Hello World (cron decorators)] - Hello World!
2019-05-22 10:03:40.807 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '3b1f580d-3254-4b4a-8470-d7fbb21d0f1b' is executed.

Sorry for the confusion, it was my fault…

5iver · May 22, 2019, 10:11am

No worries! It’s a long shot, but what version of Java are you using? I’ll try a test on Windows too. Do you see logs for the startup delay script, and what happens if you touch that file?

FredericMa · May 22, 2019, 11:44am

At the moment I’m using jdk1.8.0_131. I also made a test with Zulu 1.8.0_163 but I get the same results.

Then I get the following logs:

2019-05-22 13:13:51.705 [INFO ] [rt.internal.loader.ScriptFileWatcher] - Loading script 'python/core/000_startup_delay.py'
2019-05-22 13:13:56.311 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/C:/Temp/OPENHA~2/conf/automation/jsr223/python/core/000_startup_delay.py
2019-05-22 13:13:56.388 [INFO ] [tomation.jsr223.jython.startup_delay] - Checking for initialized context
2019-05-22 13:13:56.391 [INFO ] [tomation.jsr223.jython.startup_delay] - Context initialized... waiting 30s before allowing scripts to load
2019-05-22 13:14:26.392 [INFO ] [tomation.jsr223.jython.startup_delay] - Complete
2019-05-22 13:14:26.393 [DEBUG] [rt.internal.loader.ScriptFileWatcher] - Script loaded: python/core/000_startup_delay.py

So it only loads the startup delay and nothing else…

5iver · May 22, 2019, 12:03pm

But nothing at startup? The log shows the files queued… is there just nothing after that. My Windws partition barfed about a year ago and I need to reinstall, so it’ll take me a couple hours to test .

TomLXXVI · May 22, 2019, 12:29pm

I followed the quick start guide on GitHub for writing rules in Jython using the rule and trigger decorators.

I use openHAB 2.4.0 (Release Build) with openHABian running on a Raspberry Pi.
I installed Jython 2.7.1 (standalone jar).
For code writing I use Visual Studio Code.

I created a script “myrules.py” under …/automation/jsr223/personal with just one rule as a first test. The rule needs to be fired (triggered) when a certain light switch (KNX) is turned on. The only thing that happens in the “rule-function” so far is writing to the log file that the light was turned on.

from core.rules import rule
from core.triggers import when

@rule("Test Rule: Check light", description="", tags=[])
@when("Item SwLK02 received command ON")
def rule_action(event):
    rule_action.log.info("Licht in bureau brandt.")

All goes well, except that I have noticed in the log viewer that somehow the same rule definition got linked to two different rule-ID’s (rule ‘f70c6765-173e-4739-b476-0f788bf2134e’ and rule ‘2af63fb0-84b1-43d2-b77c-415af4eadf93’) and as such is fired twice when I push the light switch only once.

When I go through the log file, I notice that while writing code in Visual Studio Code the script is loaded repeatedly [see cleaned up excerpt from log file: excerpt.pdf (11.9 KB)]. Each time the script is loaded again, I can see that the “old” rule is removed. However, there was one reload of the script it seems like the “system” forgot to remove the old rule (rule ‘2af63fb0-84b1-43d2-b77c-415af4eadf93’) and so ended up with two exact the same rules in the registry that both fire when I push the light switch only once.

How can this be prevented? Should I write my script in another location and then copy and paste it to …/automation/jsr223/personal?