Apparently I was doing something wrong with timers.
Meanwhile I am now disambiguating different runs of the same rules file by defining the following global:
logTitle = "automation_script_name.py@{ts}".format(ts=DateTime.now().toString("HH:mm:ss"))
This way I can always see which version is running by comparing timestamps when using LogAction as in the following method which describes how to launch a startup timer up to 5 times to check whether all key items in the item registry have been found:
from core.rules import rule
from core.triggers import when
from core.actions import LogAction
# Allows using the createTimer Action:
from core.actions import ScriptExecution
from org.joda.time import DateTime
# Default values and automation-specific constants:
class defaults:
STARTUP_TIMER_RETRY_SECONDS = 30
# Global system state information:
system_startup_timer = None
system_startup_timer_retry_count = 0
system_initialized = False
def start_system_timer():
"""Start a system startup timer until all key items for this automation script have been found in the item registry,
or until the number of retries has been exceeded.
Unless the retry count is exceeded, initialisation will resume when all key items have been found in the item registry.
"""
global logTitle
logPrefix = "start_system_timer(): "
global system_startup_timer
global system_startup_timer_retry_count
def system_timer_callback():
"""Callback method that is called when the timer expires. It can restart the system startup timer if needed.
"""
global system_startup_timer
global system_startup_timer_retry_count
system_startup_timer_retry_count += 1
LogAction.logDebug(
logTitle,
logPrefix
+ "At start of call-back (after timer expired): system_startup_timer is None? {test} -- system_startup_timer_retry_count is {retry_count}".format(
test=str(system_startup_timer is None),
retry_count=str(system_startup_timer_retry_count),
),
)
# Check if all key items needed for running this automation script exist:
if ir_items.key_items_exist():
# All key items exist, reset timer and retry counter and initialize automation:
system_startup_timer = None
system_startup_timer_retry_count = 0
initialize_automation()
elif system_startup_timer_retry_count > 5:
# Not all key items exist in the item registry, retry counter limit reached -- nothing to do
LogAction.logWarn(
logTitle,
logPrefix
+ "system_startup_timer_retry_count {retry_count} > 5 -- Nothing to do".format(
retry_count=str(system_startup_timer_retry_count)
),
)
else:
# Not all key items exist in the item registry, reinitialize the timer
LogAction.logInfo(
logTitle,
logPrefix
+ "At end of call-back (will re-spawn timer): system_startup_timer is None? {test} -- system_startup_timer_retry_count is {retry_count}".format(
test=str(system_startup_timer is None),
retry_count=str(system_startup_timer_retry_count),
),
)
system_startup_timer = None
start_system_timer()
if system_startup_timer is None:
# This should always be the case, since we are in the callback method that runs when the timer expired
LogAction.logInfo(
logTitle,
logPrefix
+ "system_startup_timer is None, retry count is {retry_count} -- Starting new timer".format(
retry_count=str(system_startup_timer_retry_count)
),
)
system_startup_timer = ScriptExecution.createTimer(
DateTime.now().plusSeconds(defaults.STARTUP_TIMER_RETRY_SECONDS), system_timer_callback
)
else:
# This should not happen, unless there is an early restart or a double-trigger event -- do nothing
LogAction.logWarn(
logTitle,
logPrefix
+ "system_startup_timer exists, retry count is {retry_count} -- THIS SHOULD NOT HAPPEN".format(
retry_count=str(system_startup_timer_retry_count)
),
)
In principle I could use a Python timer instead of an OpenHAB timer since I’m never rescheduling it.
The code above will work if (1) you define the following class (and instantiate it once), and (2) you define initialize_automation():
class my_item_registry_items:
"""Contains information on all item registry items required for this automation.
"""
KEY_ITEM_A = "Item_name_for_key_item_A"
KEY_ITEM_B = "Item_name_for_key_item_B"
OPTIONAL_ITEM_C = "Item_name_for_optional_item_C"
def key_items(self):
return list( (
KEY_ITEM_A,
KEY_ITEM_B,
)
)
def key_items_exist(self):
"""Check that all key items exist in the item registry. Can be used also to delay initialisation due to system startup
Returns:
boolean -- True if all items in the item list were found in item registry, else False
"""
global logTitle
logPrefix = "key_items_exist(): "
missing_items = list()
errors = 0
for item_name in self.key_items():
LogAction.logDebug(
logTitle,
logPrefix
+ "Checking the existence of key item '{item_name}' in the item registry".format(
item_name=item_name,
),
)
if len(itemRegistry.getItems(item_name)) == 0:
LogAction.logError(
logTitle,
logPrefix
+ "The key item '{item_name}' was not found in the item registry".format(
item_name=item_name
),
)
missing_items.append(item_name)
errors += 1
if errors > 0:
LogAction.logError(
logTitle,
logPrefix
+ "{num} key item{s} for the automation rules couldn't be retrieved in the item registry".format(
num=errors, s="" if errors == 1 else "s"
),
)
return False
return True
ir_items = my_item_registry_items()
This way my System started rule can remain short:
@rule(
"Automation - System started or automation enabled",
description="Initialization when rules file is reloaded",
)
@when("System started")
@when(
"Item {item} changed to ON".format(item=ir_items.AUTOMATION_SWITCH_ITEM)
)
def Rule_System_started(event):
global logTitle
logPrefix = "Rule_System_started(): "
LogAction.logInfo(
logTitle, logPrefix + "Verifying the existence of all key items in the item registry"
)
if ir_items.key_items_exist():
initialize_automation()
else:
# Not all key items found in the item registry -- retry by using a timer:
start_system_timer()
The actual initialization takes place in initialize_automation().
. If you can, minimize your script to the simplest form that reproduces the issue.
