[SOLVED] First stab at Jython

Bruce_Osborne · October 24, 2019, 11:32pm

It looks like that papillon light timer is constantly running on 5 minute interval even when not needed.

2019-10-24 19:09:38.603 [DEBUG] [jsr223.jython.core.metadata         ] - get_key_value: Item [papillon_light], namespace [area_triggers_and_actions], args [('modes', 'Evening')]

2019-10-24 19:09:38.604 [DEBUG] [jsr223.jython.core.metadata         ] - get_metadata: Item [papillon_light], namespace [area_triggers_and_actions]

2019-10-24 19:09:38.606 [DEBUG] [ea_triggers_and_actions.area_actions] - [papillon_light]: switch is already set to [OFF], so not sending command

2019-10-24 19:09:38.608 [DEBUG] [.community.area_triggers_and_actions] - papillon_light: [300] second light_action OFF timer has completed

2019-10-24 19:09:38.615 [DEBUG] [.community.area_triggers_and_actions] - papillon_light: [300] second recurring light_action OFF timer has started

2019-10-24 19:14:38.621 [DEBUG] [jsr223.jython.core.metadata         ] - get_key_value: Item [papillon_light], namespace [area_triggers_and_actions], args [('modes', 'Evening')]

2019-10-24 19:14:38.623 [DEBUG] [jsr223.jython.core.metadata         ] - get_metadata: Item [papillon_light], namespace [area_triggers_and_actions]

2019-10-24 19:14:38.625 [DEBUG] [ea_triggers_and_actions.area_actions] - [papillon_light]: switch is already set to [OFF], so not sending command

2019-10-24 19:14:38.627 [DEBUG] [.community.area_triggers_and_actions] - papillon_light: [300] second light_action OFF timer has completed

2019-10-24 19:14:38.640 [DEBUG] [.community.area_triggers_and_actions] - papillon_light: [300] second recurring light_action OFF timer has started

2019-10-24 19:24:38.655 [DEBUG] [ea_triggers_and_actions.area_actions] - [papillon_light]: switch is already set to [OFF], so not sending command

2019-10-24 19:24:38.657 [DEBUG] [.community.area_triggers_and_actions] - papillon_light: [300] second light_action OFF timer has completed

2019-10-24 19:24:38.663 [DEBUG] [.community.area_triggers_and_actions] - papillon_light: [300] second recurring light_action OFF timer has started

5iver · October 25, 2019, 3:15am

Strange… it says it’s recurring. Did you set that in the metadata?

Run this in a test script, so that we can see all of your metadata…

# list all area_triggers_and_actions metadata
from core.log import logging, LOG_PREFIX
log = logging.getLogger("{}.TEST".format(LOG_PREFIX))

from core.metadata import get_metadata

for item in itemRegistry.getAll():
    metadata = get_metadata(item.name, "area_triggers_and_actions")
    if metadata is not None:
        log.warn("{}\n{}\n".format(item, metadata.configuration))

area_triggers = itemRegistry.getItem("gArea_Trigger")
for item in area_triggers.members:
    log.warn("area_triggers: {}".format(item))

area_actions = itemRegistry.getItem("gArea_Action")
for item in area_actions.members:
    log.warn("area_actions: {}".format(item))

Bruce_Osborne · October 25, 2019, 9:41am

output:

2019-10-25 05:40:19.657 [WARN ] [jsr223.jython.TEST                  ] - christmas_lights (Type=GroupItem, Members=4, State=NULL, Label=Christmas Lights, Category=outdoorlight, Groups=[christmas])

{modes: {'Evening': {'brightness': 98}, 'Night': {'brightness': 0}, 'Morning': {'brightness': 98}, 'Day': {'brightness': 0}}}

2019-10-25 05:40:19.662 [WARN ] [jsr223.jython.TEST                  ] - papillon_light (Type=SwitchItem, State=OFF, Label=Papillon Light, Category=light, Groups=[papillon_yard, gPapillon_Action])

{actions: {'light_action': {'OFF': {'delay': 300}}}, modes: {'Evening': {'brightness': 98}, 'Night': {'brightness': 98}, 'Morning': {'brightness': 98}, 'Day': {'brightness': 0}}}

2019-10-25 05:40:19.666 [WARN ] [jsr223.jython.TEST                  ] - area_triggers: gPapillon_Trigger (Type=GroupItem, BaseType=SwitchItem, Members=1, State=OFF, Label=Papillon Trigger, Category=presence, Groups=[gArea_Trigger])

2019-10-25 05:40:19.667 [WARN ] [jsr223.jython.TEST                  ] - area_triggers: gBasement_Trigger (Type=GroupItem, BaseType=SwitchItem, Members=0, State=NULL, Label=Basement Trigger, Category=presence, Groups=[gArea_Trigger])

2019-10-25 05:40:19.668 [WARN ] [jsr223.jython.TEST                  ] - area_triggers: gOutside_Trigger (Type=GroupItem, BaseType=SwitchItem, Members=1, State=ON, Label=Outside Trigger, Category=presence, Groups=[gArea_Trigger])

2019-10-25 05:40:19.669 [WARN ] [jsr223.jython.TEST                  ] - area_actions: gPapillon_Action (Type=GroupItem, Members=1, State=NULL, Label=Papillon Action, Category=presence, Groups=[gArea_Action])

2019-10-25 05:40:19.670 [WARN ] [jsr223.jython.TEST                  ] - area_actions: gBasement_Action (Type=GroupItem, Members=0, State=NULL, Label=Basement Action, Category=presence, Groups=[gArea_Action])

2019-10-25 05:40:19.671 [WARN ] [jsr223.jython.TEST                  ] - area_actions: gOutside_Action (Type=GroupItem, Members=3, State=NULL, Label=Outside Action, Category=presence, Groups=[gArea_Action])

2019-10-25 05:40:20.673 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/personal/logData.py'

2019-10-25 05:40:22.267 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/personal/logData.py

2019-10-25 05:40:23.134 [WARN ] [jsr223.jython.TEST                  ] - christmas_lights (Type=GroupItem, Members=4, State=NULL, Label=Christmas Lights, Category=outdoorlight, Groups=[christmas])

{modes: {'Evening': {'brightness': 98}, 'Night': {'brightness': 0}, 'Morning': {'brightness': 98}, 'Day': {'brightness': 0}}}

2019-10-25 05:40:23.142 [WARN ] [jsr223.jython.TEST                  ] - papillon_light (Type=SwitchItem, State=OFF, Label=Papillon Light, Category=light, Groups=[papillon_yard, gPapillon_Action])

{actions: {'light_action': {'OFF': {'delay': 300}}}, modes: {'Evening': {'brightness': 98}, 'Night': {'brightness': 98}, 'Morning': {'brightness': 98}, 'Day': {'brightness': 0}}}

2019-10-25 05:40:23.148 [WARN ] [jsr223.jython.TEST                  ] - area_triggers: gPapillon_Trigger (Type=GroupItem, BaseType=SwitchItem, Members=1, State=OFF, Label=Papillon Trigger, Category=presence, Groups=[gArea_Trigger])

2019-10-25 05:40:23.150 [WARN ] [jsr223.jython.TEST                  ] - area_triggers: gBasement_Trigger (Type=GroupItem, BaseType=SwitchItem, Members=0, State=NULL, Label=Basement Trigger, Category=presence, Groups=[gArea_Trigger])

2019-10-25 05:40:23.152 [WARN ] [jsr223.jython.TEST                  ] - area_triggers: gOutside_Trigger (Type=GroupItem, BaseType=SwitchItem, Members=1, State=ON, Label=Outside Trigger, Category=presence, Groups=[gArea_Trigger])

2019-10-25 05:40:23.153 [WARN ] [jsr223.jython.TEST                  ] - area_actions: gPapillon_Action (Type=GroupItem, Members=1, State=NULL, Label=Papillon Action, Category=presence, Groups=[gArea_Action])

2019-10-25 05:40:23.154 [WARN ] [jsr223.jython.TEST                  ] - area_actions: gBasement_Action (Type=GroupItem, Members=0, State=NULL, Label=Basement Action, Category=presence, Groups=[gArea_Action])

2019-10-25 05:40:23.157 [WARN ] [jsr223.jython.TEST                  ] - area_actions: gOutside_Action (Type=GroupItem, Members=3, State=NULL, Label=Outside Action, Category=presence, Groups=[gArea_Action])

Bruce_Osborne · October 25, 2019, 10:04am

Still nothing notable in DEBUG mode.

2019-10-24 21:30:00.394 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger 'Time_cron_0_30_21_7f85c5b0f52111e9a3944da28a0d7975_7f85ecc0f52111e98af64da28a0d7975' of rule 'e2f41d7d-6558-42de-90ef-69acb98e2647' is triggered.
2019-10-24 21:30:00.399 [DEBUG] [jsr223.jython.Update Mode           ] - Mode changed from [Evening] to [Night]
2019-10-24 21:30:00.401 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule 'e2f41d7d-6558-42de-90ef-69acb98e2647' is executed.

5iver · October 25, 2019, 3:05pm

I figured out one of the issues. Since you are not using a lux sensor, the mode change rule is not being created. I suggest to either setup the astro binding as described here. Using lux levels could change your entire setup, since you will no longer need your modes to trigger on Channel changes (sunset and sunrise). The ‘Mode or lux change’ rule will adjust the lights based on the outside light level. Or change this…

if area_triggers_and_actions_dict.get("lux_item_name") and itemRegistry.getItems(area_triggers_and_actions_dict["lux_item_name"]):
    @rule("Mode or lux change")
    @when("Item {} changed".format(area_triggers_and_actions_dict["lux_item_name"]))
    @when("Item Mode changed")
    @when("System started")
    def mode_or_lux_change(event):

… to this…

@rule("Mode or lux change")
@when("Item Mode changed")
@when("System started")
def mode_or_lux_change(event):

You’ll need to get all the tabs aligned after moving the first line. This should fix the Papillon Light, so that it will turn on and off. I’m still not sure why the timer is coming up as recurring. I have the same thing setup and it works properly.

Bruce_Osborne · October 25, 2019, 3:10pm

Thanks, Scott.

How do lux levels apply to binary switch triggers?? That seems like a complex workaround to me.

I may try this weekend or just use the Time of Day parts & EXPIRE automation with either Rules DSL or the NGRE UI if appropriate. I need to start moving some of this into production.

5iver · October 25, 2019, 3:31pm

The "Mode or lux change’ rule triggers on lux or mode change. It then executes the actions for all active areas. If it was a lux change, it gets more granular and only executes the actions for active areas where the current and previous lux levels crossed over the low_lux_trigger for that mode.

Imagine a room with a motion sensor and a light, a lux sensor reads the outside light level, and metadata has been set with low_lux_triggers for each mode. You enter the room, making the area active, but it is bright outside, so the light does not come on. A storm rolls in and the lux drops below the low_lux_trigger for the current mode. The light will now turn on. The storm blows out, and the light turns back off. Now instead of a storm, imagine sunrise and sunset.

I forgot one thing in my last post. If you use the lux Item, you’ll need to adjust your metadata, so let me know if that is the direction you want to go.

The issue is that the "Mode or lux change’ rule is not loading because you do not have a lux Item configured. If you make the changes in my previous post, everything will be working.

Bruce_Osborne · October 25, 2019, 3:36pm

Think it will fix the timer issue?

5iver · October 25, 2019, 3:45pm

No… I’m looking into it right now and will figure it out.

5iver · October 25, 2019, 8:37pm

Bruce, I’ve checked this from every angle I can think of and I cannot reproduce the recurring timer issue. First, restart OH and check to see if the recurring timer comes back. If not, it could have been just a remnant from some early anomalies in the config. If it does come back, what do you get when you put this in a test script?

from core.log import logging, LOG_PREFIX, log_traceback
log = logging.getLogger("{}.TEST".format(LOG_PREFIX))

from core.metadata import get_key_value

item_name = "papillon_light"

function_metadata = get_key_value(item_name, "area_triggers_and_actions", "actions", "light_action")
log.warn(function_metadata)
limited = function_metadata.get("limited")
log.warn(limited)
timer_metadata = function_metadata.get("OFF", {})
log.warn(timer_metadata)
if not limited or timer_metadata:
    timer_delay = timer_metadata.get("delay")
    log.warn(timer_delay)
    recurring = timer_metadata.get("recurring")
    log.warn(recurring)

Bruce_Osborne · October 25, 2019, 11:31pm

It appears I had installation issues for area triggers & actions. I am working on correcting that.

EDIT: I think fixing the installation issues and adding the astro radiation item has settled things down.

EDIT2: The timer is still repeating

5iver · October 26, 2019, 1:42am

Please send your logs during OH startup and that test script.

Bruce_Osborne · October 26, 2019, 9:49am

test script output:

2019-10-26 05:48:14.509 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/personal/test2.py'

2019-10-26 05:48:16.316 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/personal/test2.py

2019-10-26 05:48:17.435 [WARN ] [jsr223.jython.TEST                  ] - {'OFF': {'delay': 300}}

2019-10-26 05:48:17.438 [WARN ] [jsr223.jython.TEST                  ] - None

2019-10-26 05:48:17.441 [WARN ] [jsr223.jython.TEST                  ] - {'delay': 300}

2019-10-26 05:48:17.443 [WARN ] [jsr223.jython.TEST                  ] - 300

2019-10-26 05:48:17.446 [WARN ] [jsr223.jython.TEST                  ] - None

2019-10-26 05:48:18.453 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/personal/test2.py'

2019-10-26 05:48:20.147 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/personal/test2.py

2019-10-26 05:48:21.230 [WARN ] [jsr223.jython.TEST                  ] - {'OFF': {'delay': 300}}

2019-10-26 05:48:21.232 [WARN ] [jsr223.jython.TEST                  ] - None

2019-10-26 05:48:21.234 [WARN ] [jsr223.jython.TEST                  ] - {'delay': 300}

2019-10-26 05:48:21.235 [WARN ] [jsr223.jython.TEST                  ] - 300

2019-10-26 05:48:21.237 [WARN ] [jsr223.jython.TEST                  ] - None

Bruce_Osborne · October 26, 2019, 9:56am

Startup: Note that Mode always comes up as Night until the next change event.


2019-10-26 05:50:31.794 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'America/New_York'.
2019-10-26 05:50:31.809 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to 'snipped'.
2019-10-26 05:50:31.812 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'en_US'.
2019-10-26 05:50:36.062 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'tree_sensor.items'
2019-10-26 05:50:36.111 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'plug.items'
2019-10-26 05:50:36.152 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'tree.items'
2019-10-26 05:50:36.196 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'astro.items'
2019-10-26 05:50:36.244 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'common.items'
2019-10-26 05:50:36.265 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'automation.items'
2019-10-26 05:50:36.310 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'papillon.items'
2019-10-26 05:50:36.332 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'groups.items'
2019-10-26 05:50:36.973 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.sitemap'
2019-10-26 05:50:39.526 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2019-10-26 05:50:40.583 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.131.110:8080
2019-10-26 05:50:40.585 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.131.110:8443
2019-10-26 05:50:41.160 [DEBUG] [org.openhab.core.automation         ] - BundleEvent STARTING - org.openhab.core.automation
2019-10-26 05:50:41.224 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleProvider, org.openhab.core.automation.ManagedRuleProvider}={service.id=331, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.ManagedRuleProvider, component.id=186} - org.openhab.core.automation
2019-10-26 05:50:41.243 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventFactory}={service.id=332, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.RuleEventFactory, component.id=188} - org.openhab.core.automation
2019-10-26 05:50:41.269 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=333, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.factory.CoreModuleHandlerFactory, component.id=191} - org.openhab.core.automation
2019-10-26 05:50:41.275 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=334, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.handler.TimerModuleHandlerFactory, component.id=192} - org.openhab.core.automation
2019-10-26 05:50:41.354 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=335, service.bundleid=210, service.scope=bundle, parser.type=parser.module.type, component.name=org.openhab.core.automation.internal.parser.gson.ModuleTypeGSONParser, format=json, component.id=194} - org.openhab.core.automation
2019-10-26 05:50:41.359 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=336, service.bundleid=210, service.scope=bundle, parser.type=parser.rule, component.name=org.openhab.core.automation.internal.parser.gson.RuleGSONParser, format=json, component.id=195} - org.openhab.core.automation
2019-10-26 05:50:41.401 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.parser.Parser}={service.id=337, service.bundleid=210, service.scope=bundle, parser.type=parser.template, component.name=org.openhab.core.automation.internal.parser.gson.TemplateGSONParser, format=json, component.id=196} - org.openhab.core.automation
2019-10-26 05:50:41.525 [INFO ] [enhab.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:local
2019-10-26 05:50:41.617 [INFO ] [o.internal.handler.AstroThingHandler] - Scheduled Positional job astro:sun:local every 300 seconds
2019-10-26 05:50:41.760 [INFO ] [enhab.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:local
2019-10-26 05:50:41.805 [INFO ] [o.internal.handler.AstroThingHandler] - Scheduled Positional job astro:sun:local every 300 seconds
2019-10-26 05:50:41.817 [DEBUG] [.AutomationResourceBundlesEventQueue] - Process bundle event 2, for automation bundle 'org.openhab.core.automation' 
2019-10-26 05:50:41.851 [DEBUG] [.AutomationResourceBundlesEventQueue] - Process bundle event 32, for automation bundle 'org.openhab.core.automation.module.script.rulesupport' 
2019-10-26 05:50:41.864 [DEBUG] [vider.AbstractResourceBundleProvider] - Parse rules from bundle 'org.openhab.core.automation' 
2019-10-26 05:50:41.866 [DEBUG] [vider.AbstractResourceBundleProvider] - Parse rules from bundle 'org.openhab.core.automation.module.script.rulesupport' 
2019-10-26 05:50:41.868 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.osgi.util.tracker.BundleTrackerCustomizer}={service.id=338, service.bundleid=210, 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=197} - org.openhab.core.automation
2019-10-26 05:50:41.895 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider, org.eclipse.smarthome.core.common.registry.Provider}={service.id=339, provider.type=bundle, service.bundleid=210, service.scope=bundle, Parser.target=(parser.type=parser.template), component.name=org.openhab.core.automation.internal.provider.TemplateResourceBundleProvider, component.id=199} - org.openhab.core.automation
2019-10-26 05:50:41.929 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=340, service.bundleid=210, service.scope=bundle, Parser.target=(parser.type=parser.module.type), component.name=org.openhab.core.automation.internal.provider.file.ModuleTypeFileProviderWatcher, component.id=200} - org.openhab.core.automation
2019-10-26 05:50:41.949 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider}={service.id=341, service.bundleid=210, service.scope=bundle, Parser.target=(parser.type=parser.template), component.name=org.openhab.core.automation.internal.provider.file.TemplateFileProviderWatcher, component.id=201} - org.openhab.core.automation
2019-10-26 05:50:41.976 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=343, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.module.provider.AnnotatedActionModuleTypeProvider, component.id=193} - org.openhab.core.automation
2019-10-26 05:50:41.992 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.eclipse.smarthome.core.common.registry.Provider}={service.id=344, provider.type=bundle, service.bundleid=210, service.scope=bundle, Parser.target=(parser.type=parser.module.type), component.name=org.openhab.core.automation.internal.provider.ModuleTypeResourceBundleProvider, component.id=198} - org.openhab.core.automation
2019-10-26 05:50:41.995 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.provider.i18n.ModuleTypeI18nService}={service.id=342, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.provider.i18n.ModuleTypeI18nServiceImpl, component.id=202} - org.openhab.core.automation
2019-10-26 05:50:42.002 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.TemplateRegistry, org.openhab.core.automation.internal.template.RuleTemplateRegistry}={service.id=345, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.template.RuleTemplateRegistry, component.id=203} - org.openhab.core.automation
2019-10-26 05:50:42.067 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added CoreModuleHandlerFactory
2019-10-26 05:50:42.069 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added TimerModuleHandlerFactory
2019-10-26 05:50:42.071 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added AnnotatedActionModuleTypeProvider
2019-10-26 05:50:42.074 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleManager, org.eclipse.smarthome.core.common.registry.RegistryChangeListener}={service.id=348, service.bundleid=210, service.scope=bundle, rule.reinitialization.delay=500, component.name=org.openhab.core.automation.internal.RuleEngineImpl, component.id=187} - org.openhab.core.automation
2019-10-26 05:50:42.075 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.RuleRegistry}={service.id=347, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.RuleRegistryImpl, component.id=189} - org.openhab.core.automation
2019-10-26 05:50:42.094 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=350, service.bundleid=210, service.scope=singleton} - org.openhab.core.automation
2019-10-26 05:50:42.100 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider}={service.id=351, service.bundleid=210, service.scope=singleton} - org.openhab.core.automation
2019-10-26 05:50:42.106 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent UNREGISTERING - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=350, service.bundleid=210, service.scope=singleton} - org.openhab.core.automation
2019-10-26 05:50:42.110 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent UNREGISTERING - {org.openhab.core.automation.template.RuleTemplateProvider}={service.id=351, service.bundleid=210, service.scope=singleton} - org.openhab.core.automation
2019-10-26 05:50:42.115 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=352, service.bundleid=210, service.scope=singleton} - org.openhab.core.automation
2019-10-26 05:50:42.118 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.template.RuleTemplateProvider}={service.id=353, service.bundleid=210, service.scope=singleton} - org.openhab.core.automation
2019-10-26 05:50:42.121 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.console.extensions.ConsoleCommandExtension}={service.id=349, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.commands.AutomationCommandsPluggable, component.id=190} - org.openhab.core.automation
2019-10-26 05:50:42.122 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeRegistry}={service.id=346, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.internal.type.ModuleTypeRegistryImpl, component.id=204} - org.openhab.core.automation
2019-10-26 05:50:42.130 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added AnnotatedThingActionModuleTypeProvider
2019-10-26 05:50:42.174 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=354, service.bundleid=210, service.scope=bundle, component.name=org.openhab.core.automation.thingsupport.AnnotatedThingActionModuleTypeProvider, component.id=205} - org.openhab.core.automation
2019-10-26 05:50:42.176 [DEBUG] [org.openhab.core.automation         ] - BundleEvent STARTED - org.openhab.core.automation
2019-10-26 05:50:42.177 [DEBUG] [openhab.core.automation.module.media] - BundleEvent STARTING - org.openhab.core.automation.module.media
2019-10-26 05:50:42.203 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=355, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaActionTypeProvider, component.id=206} - org.openhab.core.automation.module.media
2019-10-26 05:50:42.210 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added MediaModuleHandlerFactory
2019-10-26 05:50:42.211 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=356, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaModuleHandlerFactory, component.id=207} - org.openhab.core.automation.module.media
2019-10-26 05:50:42.218 [DEBUG] [openhab.core.automation.module.media] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=357, service.bundleid=211, service.scope=bundle, component.name=org.openhab.core.automation.module.media.internal.MediaScriptScopeProvider, component.id=208} - org.openhab.core.automation.module.media
2019-10-26 05:50:42.219 [DEBUG] [openhab.core.automation.module.media] - BundleEvent STARTED - org.openhab.core.automation.module.media
2019-10-26 05:50:42.222 [DEBUG] [penhab.core.automation.module.script] - BundleEvent STARTING - org.openhab.core.automation.module.script
2019-10-26 05:50:42.236 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineFactory}={service.id=358, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.GenericScriptEngineFactory, component.id=209} - org.openhab.core.automation.module.script
2019-10-26 05:50:42.240 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineFactory}={service.id=359, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.NashornScriptEngineFactory, component.id=210} - org.openhab.core.automation.module.script
2019-10-26 05:50:42.257 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added GenericScriptEngineFactory
2019-10-26 05:50:42.262 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_232-b18): 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-10-26 05:50:42.265 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.1): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]
2019-10-26 05:50:42.267 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added NashornScriptEngineFactory
2019-10-26 05:50:42.269 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_232-b18): 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-10-26 05:50:42.271 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.1): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]
2019-10-26 05:50:42.273 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Removed GenericScriptEngineFactory
2019-10-26 05:50:42.275 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Removed NashornScriptEngineFactory
2019-10-26 05:50:42.276 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptEngineManager}={service.id=361, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.ScriptEngineManagerImpl, component.id=211} - org.openhab.core.automation.module.script
2019-10-26 05:50:42.278 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.internal.ScriptExtensionManager}={service.id=360, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.ScriptExtensionManager, component.id=212} - org.openhab.core.automation.module.script
2019-10-26 05:50:42.294 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=362, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.defaultscope.DefaultScriptScopeProvider, component.id=213} - org.openhab.core.automation.module.script
2019-10-26 05:50:42.299 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added GenericScriptEngineFactory
2019-10-26 05:50:42.301 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_232-b18): 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-10-26 05:50:42.302 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.1): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]
2019-10-26 05:50:42.304 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added NashornScriptEngineFactory
2019-10-26 05:50:42.305 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for Oracle Nashorn (1.8.0_232-b18): 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-10-26 05:50:42.307 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - ScriptEngineFactory details for jython (2.7.1): supports python (2.7) with file extensions [py], names [python, jython], and mimetypes [text/python, application/python, text/x-python, application/x-python]
2019-10-26 05:50:42.310 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptModuleHandlerFactory
2019-10-26 05:50:42.311 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=363, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.factory.ScriptModuleHandlerFactory, component.id=214} - org.openhab.core.automation.module.script
2019-10-26 05:50:42.320 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.openhab.core.automation.type.ModuleTypeProvider}={service.id=364, service.bundleid=212, service.scope=bundle, component.name=org.openhab.core.automation.module.script.internal.provider.ScriptModuleTypeProvider, component.id=215} - org.openhab.core.automation.module.script
2019-10-26 05:50:42.321 [DEBUG] [penhab.core.automation.module.script] - BundleEvent STARTED - org.openhab.core.automation.module.script
2019-10-26 05:50:42.324 [DEBUG] [automation.module.script.rulesupport] - BundleEvent STARTING - org.openhab.core.automation.module.script.rulesupport
2019-10-26 05:50:42.339 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptedCustomModuleHandlerFactory
2019-10-26 05:50:42.341 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleHandlerFactory, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=365, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleHandlerFactory, component.id=217} - org.openhab.core.automation.module.script.rulesupport
2019-10-26 05:50:42.346 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleTypeProvider, org.openhab.core.automation.type.ModuleTypeProvider}={service.id=366, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedCustomModuleTypeProvider, component.id=218} - org.openhab.core.automation.module.script.rulesupport
2019-10-26 05:50:42.350 [DEBUG] [e.automation.internal.RuleEngineImpl] - ModuleHandlerFactory added ScriptedPrivateModuleHandlerFactory
2019-10-26 05:50:42.352 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.internal.ScriptedPrivateModuleHandlerFactory, org.openhab.core.automation.handler.ModuleHandlerFactory}={service.id=367, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.ScriptedPrivateModuleHandlerFactory, component.id=219} - org.openhab.core.automation.module.script.rulesupport
2019-10-26 05:50:42.392 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.ScriptExtensionProvider}={service.id=369, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.internal.RuleSupportScriptExtension, component.id=216} - org.openhab.core.automation.module.script.rulesupport
2019-10-26 05:50:42.403 [DEBUG] [automation.module.script.rulesupport] - ServiceEvent REGISTERED - {org.openhab.core.automation.module.script.rulesupport.shared.ScriptedRuleProvider, org.openhab.core.automation.RuleProvider}={service.id=368, service.bundleid=213, service.scope=bundle, component.name=org.openhab.core.automation.module.script.rulesupport.shared.ScriptedRuleProvider, component.id=221} - org.openhab.core.automation.module.script.rulesupport
2019-10-26 05:50:42.405 [DEBUG] [automation.module.script.rulesupport] - BundleEvent STARTED - org.openhab.core.automation.module.script.rulesupport
2019-10-26 05:50:42.408 [DEBUG] [org.openhab.core.automation.rest    ] - BundleEvent STARTING - org.openhab.core.automation.rest
2019-10-26 05:50:42.419 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=370, service.bundleid=214, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.ModuleTypeResource, component.id=222} - org.openhab.core.automation.rest
2019-10-26 05:50:42.428 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=371, service.bundleid=214, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.RuleResource, component.id=223} - org.openhab.core.automation.rest
2019-10-26 05:50:42.435 [DEBUG] [org.openhab.core.automation.rest    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.rest.RESTResource}={service.id=372, service.bundleid=214, service.scope=bundle, component.name=org.openhab.core.automation.rest.internal.TemplateResource, component.id=224} - org.openhab.core.automation.rest
2019-10-26 05:50:42.436 [DEBUG] [org.openhab.core.automation.rest    ] - BundleEvent STARTED - org.openhab.core.automation.rest
2019-10-26 05:50:43.518 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2019-10-26 05:50:43.681 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2019-10-26 05:50:43.779 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2019-10-26 05:50:43.878 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2019-10-26 05:50:45.464 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2019-10-26 05:50:45.686 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyS0'
2019-10-26 05:50:45.845 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2019-10-26 05:50:45.877 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2019-10-26 05:50:45.878 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2019-10-26 05:51:07.422 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/000_startup_delay.py'
2019-10-26 05:51:11.980 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/000_startup_delay.py
2019-10-26 05:51:12.032 [INFO ] [jsr223.jython.core.startup_delay    ] - Checking for initialized context
2019-10-26 05:51:12.041 [INFO ] [jsr223.jython.core.startup_delay    ] - Context initialized... waiting 30s before allowing scripts to load
2019-10-26 05:51:42.043 [INFO ] [jsr223.jython.core.startup_delay    ] - Complete
2019-10-26 05:51:42.045 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/100_DirectoryTrigger.py'
2019-10-26 05:51:43.785 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/100_DirectoryTrigger.py
2019-10-26 05:51:45.244 [INFO ] [23.jython.core.DirectoryEventTrigger] - TriggerHandler added [jsr223.DirectoryTrigger]
2019-10-26 05:51:45.249 [INFO ] [23.jython.core.DirectoryEventTrigger] - TriggerType added [jsr223.DirectoryTrigger]
2019-10-26 05:51:45.251 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/100_OsgiEventTrigger.py'
2019-10-26 05:51:46.561 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/100_OsgiEventTrigger.py
2019-10-26 05:51:47.752 [INFO ] [jsr223.jython.core.OsgiEventTrigger ] - TriggerHandler added [jsr223.OsgiEventTrigger]
2019-10-26 05:51:47.755 [INFO ] [jsr223.jython.core.OsgiEventTrigger ] - TriggerType added [jsr223.OsgiEventTrigger]
2019-10-26 05:51:47.758 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/100_StartupTrigger.py'
2019-10-26 05:51:48.938 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/100_StartupTrigger.py
2019-10-26 05:51:49.466 [INFO ] [jsr223.jython.core.StartupTrigger   ] - TriggerHandler added [jsr223.StartupTrigger]
2019-10-26 05:51:49.469 [INFO ] [jsr223.jython.core.StartupTrigger   ] - TriggerType added [jsr223.StartupTrigger]
2019-10-26 05:51:49.470 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonBindingInfoProvider.py'
2019-10-26 05:51:50.403 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonBindingInfoProvider.py
2019-10-26 05:51:51.184 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.binding.BindingInfoProvider}={service.id=433, service.bundleid=212, service.scope=singleton} - org.openhab.core.automation.module.script
2019-10-26 05:51:51.203 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonExtensionProvider.py'
2019-10-26 05:51:52.632 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonExtensionProvider.py
2019-10-26 05:51:53.368 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonItemChannelLinkProvider.py'
2019-10-26 05:51:54.992 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonItemChannelLinkProvider.py
2019-10-26 05:51:55.033 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.link.ItemChannelLinkProvider}={service.id=434, service.bundleid=212, service.scope=singleton} - org.openhab.core.automation.module.script
2019-10-26 05:51:55.043 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonItemProvider.py'
2019-10-26 05:51:56.203 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonItemProvider.py
2019-10-26 05:51:56.231 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.items.ItemProvider}={service.id=435, service.bundleid=212, service.scope=singleton} - org.openhab.core.automation.module.script
2019-10-26 05:51:56.237 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonThingProvider.py'
2019-10-26 05:51:57.172 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonThingProvider.py
2019-10-26 05:51:57.193 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.ThingProvider}={service.id=436, service.bundleid=212, service.scope=singleton} - org.openhab.core.automation.module.script
2019-10-26 05:51:57.198 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonThingTypeProvider.py'
2019-10-26 05:51:58.216 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonThingTypeProvider.py
2019-10-26 05:51:58.269 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingTypeProvider}={service.id=437, service.bundleid=212, service.scope=singleton} - org.openhab.core.automation.module.script
2019-10-26 05:51:58.278 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/core/components/200_JythonTransform.py'
2019-10-26 05:51:59.974 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/core/components/200_JythonTransform.py
2019-10-26 05:52:00.042 [DEBUG] [penhab.core.automation.module.script] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.transform.TransformationService}={service.id=438, service.bundleid=212, service.scope=singleton, smarthome.transform=JYTHON} - org.openhab.core.automation.module.script
2019-10-26 05:52:00.049 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/community/area_triggers_and_actions/area_triggers.py'
2019-10-26 05:52:01.705 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/community/area_triggers_and_actions/area_triggers.py
2019-10-26 05:52:06.530 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventSubscriber}={service.id=439, service.bundleid=210, service.scope=singleton, event.topics=smarthome/items/gPapillon_Trigger/*} - org.openhab.core.automation
2019-10-26 05:52:06.533 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventSubscriber}={service.id=440, service.bundleid=210, service.scope=singleton, event.topics=smarthome/items/gBasement_Trigger/*} - org.openhab.core.automation
2019-10-26 05:52:06.534 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventSubscriber}={service.id=441, service.bundleid=210, service.scope=singleton, event.topics=smarthome/items/gOutside_Trigger/*} - org.openhab.core.automation
2019-10-26 05:52:06.549 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventSubscriber}={service.id=442, service.bundleid=210, service.scope=singleton, event.topics=smarthome/items/Mode/*} - org.openhab.core.automation
2019-10-26 05:52:06.551 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventSubscriber}={service.id=443, service.bundleid=210, service.scope=singleton, event.topics=smarthome/items/sun_radiation/*} - org.openhab.core.automation
2019-10-26 05:52:06.559 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/personal/metadata.py'
2019-10-26 05:52:07.575 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger 'System_started_451273cff7d611e9933879a2ef65056e_45129ae1f7d611e98fe179a2ef65056e' of rule '36f4a44f-aa87-4072-a7eb-79d65d6b4e9a' is triggered.
2019-10-26 05:52:07.671 [DEBUG] [.community.area_triggers_and_actions] - papillon_light: [300.0] second light_action OFF timer has started
2019-10-26 05:52:07.696 [INFO ] [jsr223.jython.Mode or lux change    ] - Mode adjust: [NULL]: gPapillon_Action: papillon_light
2019-10-26 05:52:07.729 [INFO ] [ea_triggers_and_actions.area_actions] - <<<<<<<<<<<<<<<<<<<<< plug_003: OFF
2019-10-26 05:52:07.731 [INFO ] [jsr223.jython.Mode or lux change    ] - Mode adjust: [NULL]: gOutside_Action: plug_003
2019-10-26 05:52:07.766 [INFO ] [ea_triggers_and_actions.area_actions] - <<<<<<<<<<<<<<<<<<<<< plug_002: OFF
2019-10-26 05:52:07.768 [INFO ] [jsr223.jython.Mode or lux change    ] - Mode adjust: [NULL]: gOutside_Action: plug_002
2019-10-26 05:52:07.792 [INFO ] [ea_triggers_and_actions.area_actions] - <<<<<<<<<<<<<<<<<<<<< plug_001: OFF
2019-10-26 05:52:07.794 [INFO ] [jsr223.jython.Mode or lux change    ] - Mode adjust: [NULL]: gOutside_Action: plug_001
2019-10-26 05:52:07.796 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '36f4a44f-aa87-4072-a7eb-79d65d6b4e9a' is executed.
2019-10-26 05:52:07.870 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/personal/metadata.py
2019-10-26 05:52:09.214 [INFO ] [me.core.service.AbstractWatchService] - Loading script 'python/community/update_mode.py'
2019-10-26 05:52:11.037 [DEBUG] [ipt.internal.ScriptEngineManagerImpl] - Added ScriptEngine for language 'py' with identifier: file:/etc/openhab2/automation/jsr223/python/community/update_mode.py
2019-10-26 05:52:12.253 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventSubscriber}={service.id=444, service.bundleid=210, service.scope=singleton, event.topics=smarthome/channels/*/triggered} - org.openhab.core.automation
2019-10-26 05:52:12.256 [DEBUG] [org.openhab.core.automation         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventSubscriber}={service.id=445, service.bundleid=210, service.scope=singleton, event.topics=smarthome/channels/*/triggered} - org.openhab.core.automation
2019-10-26 05:52:12.262 [DEBUG] [le.handler.GenericCronTriggerHandler] - Scheduled cron job '0 45 5 * * ?' for trigger 'Time_cron_0_45_5_4873c740f7d611e999c479a2ef65056e_4873ee4ff7d611e9a04879a2ef65056e'.
2019-10-26 05:52:12.265 [DEBUG] [le.handler.GenericCronTriggerHandler] - Scheduled cron job '0 30 21 * * ?' for trigger 'Time_cron_0_30_21_48759c00f7d611e98b2b79a2ef65056e_4875c30ff7d611e98a3e79a2ef65056e'.
2019-10-26 05:52:13.276 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger 'System_started_48732b00f7d611e9b37a79a2ef65056e_4875ea21f7d611e9997b79a2ef65056e' of rule '57d4db84-50c7-429e-adfe-7f1b071e155f' is triggered.
2019-10-26 05:52:13.412 [DEBUG] [jsr223.jython.Update Mode           ] - Mode changed from [NULL] to [Night]
2019-10-26 05:52:13.415 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '57d4db84-50c7-429e-adfe-7f1b071e155f' is executed.
2019-10-26 05:52:13.426 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '36f4a44f-aa87-4072-a7eb-79d65d6b4e9a' is executed.
2019-10-26 05:52:13.427 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger 'Item-Mode-changed_4512c1f0f7d611e9856b79a2ef65056e_4512e900f7d611e9adfa79a2ef65056e' of rule '36f4a44f-aa87-4072-a7eb-79d65d6b4e9a' is triggered.

Bruce_Osborne · October 26, 2019, 12:10pm

One question about creating NGRE rules through the PaperUI.
Are the saved to text files or just in the database?

rlkoshak · October 26, 2019, 2:26pm

Yes.

The database is itself text files. But to answer your real question, they only get saved to jsondb.

Bruce_Osborne · October 26, 2019, 2:28pm

You cannot use NGRE with text rules then? I mean basic NGRE, not all the advanced automation scripting.

rlkoshak · October 26, 2019, 3:39pm

It’s complicated. Both ways of defining rules is NGRE. They are kind of the same as Items defined in .items files versus through PaperUI. You end up with rules either way and those rules are executed by the same NGRE. And as with Items, you can’t create a rule through .py files and edit it through PaperUI. And as with Items, both ways of defining rules can coexist. And I imagine at some point someone might come up with import/export scripts to convert between the two.

5iver · October 26, 2019, 4:49pm

This shows that the script is properly pulling the metadata for the light and that recurring should be None.

This all looks good. The Mode does not change on startup because you are using Channels. If you use times, the Mode gets set properly after startup. I don’t see a log entry of the recurring timer. When does this start happening?

You can edit the JSON rules directly in the jsondb, but the changes will not be picked up until OH restarts. You can include scripted automation in a JSON rule by adding a Scripted Condition or Action. If you add one through the UI, you’ll be able to see it in the jsondb. You can also use the helper libraries in Scripted Conditions and Actions.

Technically, you can… but not with rules created using the helper libraries.

Bruce_Osborne · October 27, 2019, 9:32am

Back to Rules DSL for me until this matures. My goal is to learn & benefit from home automation, not go down programming rat holes.
IF my expire binding replacement error is resolved I may use that to be free of v1 bindings. Otherwise I consider this thread as closed.