I have issues with recent snapshots in which some Jython scripts apparently stop working.
It appears it may have to do with using OH2 timers. I noticed for instance that my triple-click script for Ikea Tradfri lights stopped functioning. When attempting at enabling debug logging, I encountered NPE.
For instance, in the callback function I use for the timer, I cannot use LogAction (NPE) but I am able to use the Telegram binding.
I still need to dig deeper but I don’t have the time to do so now.
I’m still on S1665, but I should be able to find some time to upgrade this weekend and check it out. There have been quite a few updates to core, but I don’t recall anything that should have affected scripted automation.
I think I found something.
It appears that the following code no longer works:
for i in itemRegistry.getItem(g).getAllMembers():
events.sendCommand(i, end_states[name])
For what it’s worth, the following (replacing i with i.name) also does not work:
for i in itemRegistry.getItem(g).getAllMembers():
events.sendCommand(i.name, end_states[name])
In the snippet above, end_states[name] is a string containing the end state (ON or OFF).
The code is definitely executed (I have logging in place to confirm). However nothing seems to happen when sendCommand() is invoked. No error message and no update in events.log.
I upgraded to S1674 yesterday and I cannot reproduce the issues you are reporting. Could you post a script that produces errors for you?
Here’s the script:
"""
This rule implements triple-click support for ITEA TRADFRI remotes by using timers and click count.
"""
from core.rules import rule
from core.triggers import when
from core.actions import LogAction
from core.actions import Telegram
import pprint
pp = pprint.PrettyPrinter(indent=4)
# Example using the createTimer Action
from core.actions import ScriptExecution
from org.joda.time import DateTime
class defaults:
DEFAULT_TOGGLE_TIMER_SECONDS = 3
TRIPLE_TOGGLE_GROUP_NAME = "gTripleToggle"
TELEGRAM_BOT_NAME = "homebrainz"
# Keep track of rule initialization
initialized = False
# Triple-click item timers:
timers = {}
# Triple-click item click counters:
clicks = {}
# Final state if triple-click event occurred:
end_states = {}
# Triple-click subgroup items
group_items = {}
rule_init_timestamp = DateTime.now()
logTitle = "triple_click.py@{ts}".format(ts=rule_init_timestamp.toString("HH:mm:ss"))
ruleTimeStamp = " -- (Rule set initialised {date} at {ts})".format(
date=rule_init_timestamp.toString("E d MMM yyyy"),
ts=rule_init_timestamp.toString("HH:mm:ss (z)"),
)
rulePrefix = "Triple-Click | "
def myRule_initialize():
global logTitle
logPrefix = "myRule_initialize(): "
global initialized
LogAction.logDebug(
logTitle,
logPrefix
+ "AT START OF METHOD - intialized == {initialized}".format(initialized=str(initialized)),
)
#global TRIPLE_TOGGLE_GROUP_NAME
global timers
global clicks
global end_states
global group_items
# Verify that item exists
if not itemRegistry.getItems(defaults.TRIPLE_TOGGLE_GROUP_NAME):
LogAction.logError(
logTitle,
"Item '{name}' does not exist! Please create this Group item.".format(
name=defaults.TRIPLE_TOGGLE_GROUP_NAME
),
)
return
# Verify thet item is of type Group
g = itemRegistry.getItem(defaults.TRIPLE_TOGGLE_GROUP_NAME)
if g.type != "Group":
LogAction.logError(
logTitle,
" Item '{name}' is of type '{type}', expecting 'Group'".format(
name=defaults.TRIPLE_TOGGLE_GROUP_NAME, type=g.type
),
)
return
# We're now okay to proceed, as the item named defaults.TRIPLE_TOGGLE_GROUP_NAME exists and is a Group
LogAction.logDebug(
logTitle,
"Item '{name}' is of type '{type}'".format(name=defaults.TRIPLE_TOGGLE_GROUP_NAME, type=g.type),
)
# Report if incorrect Item types are assigned as direct members of defaults.TRIPLE_TOGGLE_GROUP_NAME
tripleToggleGroupsErrors = list(item for item in g.getMembers() if item.type != "Group")
if tripleToggleGroupsErrors:
LogAction.logError(
logTitle,
"{count} Non-Group Item(s) found as direct members of '{name}'".format(
name=defaults.TRIPLE_TOGGLE_GROUP_NAME, count=len(tripleToggleGroupsErrors)
),
)
for item in tripleToggleGroupsErrors:
LogAction.logError(
logTitle,
"Item '{name}' is of type '{type}', expecting Group -- Item will be ignored".format(
name=item.name, type=item.type
),
)
# Now get all TripleToggle group names (they must be defined as direct members of defaults.TRIPLE_TOGGLE_GROUP_NAME and of thype Group)
tripleToggleGroups = list(item for item in g.getMembers() if item.type == "Group")
for item in tripleToggleGroups:
LogAction.logDebug(
logTitle, "Found TripleToggle [{type}] '{name}'".format(type=item.type, name=item.name)
)
# Process the members of the TripleToggle group
for item in (i for i in g.getAllMembers() if i.type != "Switch"):
LogAction.logError(
logTitle,
"Item '{name}' is of type '{type}', expecting 'Switch' -- Item will be ignored".format(
name=item.name, type=item.type
),
)
for item in (i for i in g.getAllMembers() if i.type == "Switch"):
LogAction.logInfo(logTitle, "[{type}] {name}".format(type=item.type, name=item.name))
# Determine the triple-click group(s) the Switch item belongs to:
item_triple_toggle_group_names = list(
group.name for group in tripleToggleGroups if group.name in item.getGroupNames()
)
item_triple_toggle_group_count = len(item_triple_toggle_group_names)
if item_triple_toggle_group_count == 0:
LogAction.logError(
logTitle,
"Item '{name}' belongs to 0 triple-click groups, probably direct descendant of '{groupname}' -- Item will be ignored".format(
name=item.name, groupname=defaults.TRIPLE_TOGGLE_GROUP_NAME
),
)
else:
if item_triple_toggle_group_count > 1:
LogAction.logWarn(
logTitle,
"Item '{name}' belongs to {count} triple-click groups: '{groups}'".format(
name=item.name,
count=str(item_triple_toggle_group_count),
groups="', '".join(item_triple_toggle_group_names),
),
)
else:
LogAction.logInfo(
logTitle,
"Item '{name}' belongs to 1 triple-click group(s): '{groups}'".format(
name=item.name, groups=item_triple_toggle_group_names
),
)
# Now initialize the Item:
group_items[item.name] = item_triple_toggle_group_names
timers[item.name] = None
clicks[item.name] = 0
end_states[item.name] = None
LogAction.logInfo(
logTitle,
"Item '{name}' of type '{type}' has been initialized".format(
type=item.type, name=item.name
),
)
# Initialization complete
initialized = True
LogAction.logDebug(
logTitle,
"AT END OF METHOD - intialized == {initialized}".format(initialized=str(initialized)),
)
@rule(
rulePrefix + "System started - Initialise rules context",
description="Initialize system state when the rule is reloaded" + ruleTimeStamp,
tags=["triple-click", ruleTimeStamp],
)
@when("System started")
def SystemStarted(event):
global logTitle
logPrefix = "SystemStarted()"
global initialized
myRule_initialize()
@rule(
rulePrefix + "Process state toggle of triple-toggle item",
description="""When a triple-toggle item toggled its state, we will keep track of the number of times the item toggles state in a 3-second time interval
managed by means of a timer. Each time the item state toggles, the timer is reinitialised and the click count incremented. When the click count reaches 3
before the timer expires, then all items in the triple-toggle group(s) to which the toggled item belongs, will receive the same state as the end state
of the toggled item. In other words, if the item was on (off), triple-toggling the item state will turn it off (on), as well as all items in the triple-toggle groups
to which the toggled item belongs."""
+ ruleTimeStamp,
tags=["triple-click", ruleTimeStamp],
)
@when("Descendent of {group_name} changed".format(group_name=defaults.TRIPLE_TOGGLE_GROUP_NAME))
def myRuleTripleClick_Clicked(event):
global logTitle
logPrefix = "myRuleTripleClick_Clicked" + (
"(event is None): "
if event is None
else "Item '{name}' of type '{type}' with state '{state}': ".format(
name=event.itemName,
type=itemRegistry.getItem(event.itemName).type,
state=str(event.itemState),
)
)
LogAction.logInfo( # Was: logDebug(
logTitle, logPrefix + "At start of rule"
)
global initialized
if not initialized:
LogAction.logWarn(logTitle, logPrefix + "Not yet initialized - no action will be taken yet")
return
if event is None:
LogAction.logWarn(logTitle, logPrefix + "event == None")
return
if isinstance(event.itemState, UnDefType):
LogAction.logWarn(
logTitle,
logPrefix
+ "event item '{name} has state '{state}".format(
name=event.itemName, state=str(event.state)
),
)
return
# We're good to go
global timers
global clicks
global end_states
global group_items
name = event.itemName
logPrefix += "clicks = " + str(clicks.get(name)) + " - "
LogAction.logInfo( # Was: logDebug(
logTitle, logPrefix + "group_items = {list}".format(list=pp.pformat(group_items))
)
tripleToggleGroups = group_items.get(name)
# Bail out if Item conventions for this rule are not respected
if tripleToggleGroups is None:
LogAction.logError(
logTitle,
logPrefix
+ "Item '{name}' has no triple-click groups defined -- nothing to do".format(name=name),
)
return
LogAction.logInfo( # Was: logDebug(
logTitle,
logPrefix
+ "AT START OF RULE - '{name}' (in group(s) '{groups}') has state '{state}' - starting the logic".format(
name=name, groups="', '".join(tripleToggleGroups), state=event.itemState
),
)
if timers.get(name) is None:
# Define the call-back that will be executed when the timer expires
def cb():
global logTitle
# This works:
Telegram.sendTelegram(
defaults.TELEGRAM_BOT_NAME,
"<b>"+logTitle+"</b> Triple-toggle timer for item '" + name + "' expired. Toggle counter is " + str(clicks[name]) + ", will be reset to 0."
)
timers[name] = None
clicks[name] = 0
#return
"""
# This now generates a Python exception:
LogAction.logInfo("Triple-toggle timer expired. Click count will be reset to 0.")
LogAction.logInfo("Triple-toggle timer for item '{name}' expired. Click count will be reset to 0.".format(
name=name,
))
global timers
global clicks
LogAction.logInfo("Triple-toggle timer for item '{name}' expired. Click count was {clicks} - will be reset to 0.".format(
name=name,clicks=str(clicks[name]),
))
"""
# We're using OH timers here as I want to reinitialize a running timer after each click (feature only available with OH timers)
timers[name] = ScriptExecution.createTimer(DateTime.now().plusSeconds(defaults.DEFAULT_TOGGLE_TIMER_SECONDS), cb)
clicks[name] = 1
# Store the desired end state (current state of triggeringItem)
end_states[name] = str(event.itemState)
else:
cnt = clicks[name] + 1
stateInfo = end_states[name]
if cnt >= 3:
Telegram.sendTelegram(
defaults.TELEGRAM_BOT_NAME,
"<b>"+logTitle + u"</b> Item '{name}' toggled {count} times (≥ 3). Will switch {stateInfo} all associated items".format(
name=name, stateInfo=stateInfo, count=cnt
)
)
LogAction.logInfo(
logTitle,
logPrefix
+ u"{name} (end state will be {stateInfo}) toggle count: {count} ≥ 3 -- Switching {stateInfo} all associated items".format(
name=name, stateInfo=stateInfo, count=cnt
),
)
for g in tripleToggleGroups:
LogAction.logInfo( # Was: logDebug(
logTitle,
logPrefix + "Processing items relating to group [{g}]".format(g=str(g)),
)
for i in itemRegistry.getItem(g).getAllMembers():
LogAction.logInfo( # Was: logDebug(
logTitle,
logPrefix
+ "Processing item [{i}] of type [{t}] relating to group [{g}]".format(
i=i.name, t=i.type, g=str(g)
),
)
LogAction.logInfo(logTitle,u"Will issue: events.sendCommand({i}, {state})".format(
i=i.name,state=end_states[name]
))
events.sendCommand(i, end_states[name])
if not timers[i.name] is None:
timers[i.name].cancel()
timers[i.name] = None
clicks[i.name] = 0
LogAction.logInfo( # Was: logDebug(
logTitle,
logPrefix
+ "Processing item triple-toggle ended for item [{name}]".format(name=name),
)
else:
timers[name].reschedule(DateTime.now().plusSeconds(defaults.DEFAULT_TOGGLE_TIMER_SECONDS))
clicks[name] = cnt
LogAction.logDebug(logTitle, logPrefix + "At end of rule")
There are 2 problems now:
LogAction can no longer be used in a call-back - I get a null-pointer exception if I do (e.g., in cb())sendCommand() behaves as a no-op nothing happens, no command sent as the event log remains silent)That’s 354 LOC! Could you please reduce this to the minimum required to reproduce the errors?
What was the last snapshot that worked without errors? You might want to use…
try:
# some stuff
except:
import traceback
log.error("Exception: {}".format(traceback.format_exc()))
… to get some better logging of the issue.
# This now generates a Python exception:
LogAction.logInfo("Triple-toggle timer expired. Click count will be reset to 0.")
Oops… it helps if I set the log title as 1st argument, as in:
# This works:
LogAction.logInfo(logTitle, "Triple-toggle timer expired. Click count will be reset to 0.")
However, there’s still something wrong with the TRADFRI binding now, as I can no longer control the state of my TRADFRI bulbs within OH2. The UI toggles but nothing happens. Hence, state changes aren’t propagating from Homekit to OH2 either. That’s another issue, not related to Jython/JSR223.
Just to be sure… your “oops” means your problem was a configuration issue? If so, could you mark this as resolved so that people aren’t misled to think that there is a current issue with Jython scripts in recent snapshots?