Is it also possible with your new implementation, to set the rulename (at least partially, maybe a random suffix should be created) as UID?
Otherwise the log statements are not human readable
2018-11-13 19:48:20.401 [.event.RuleStatusInfoEvent] - a7b86e52-a729-4bbf-baa6-c4921cc5e249 updated: RUNNING
That would be really great and btw thanks for your great library 
The rule name is being set… take a look in Paper UI> Rules and you will see all of your JSR223 rules listed by name. That log is displaying the rule UID, which can’t be modified through SimpleRule. Changing that log entry should be a really quick fix, and I’ve been meaning to update it for a while now… thank you for the reminder!
Not OOTB, that I’m aware of. But a composite module, like the the StartupTrigger.py, may work for you. I’d really like to see a ShutdownTrigger.py get built. But I don’t know how you’d inform the timer to cancel itself. How do you know the timer is not garbage collected? I would think it would have to be, but maybe only after the timer terminated.
Scott, I haven’t dug deeply into this but… it seems timers in Python persist even after rules are reloaded and then they fire. I haven’t had the time to fully understand what is happening. In my use case, the timers are held within an object, and if the object got a “rule unloading” event, the object could clean up before its done.
that would be great…
@5iver, I am really enjoying writing rules using the decorators you added to the openHAB Jython libraries, thank you!
I thought I would put this out there as an example of a simple little utility scritpt that I have found very useful when debugging some of my other rule scripts:
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
# requires osgi import
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
groupLister = rule("Group Test Rule")(
when("Time cron 10 0/1 * * * ?")
(GroupLister("groupLister")))
#logger.info("groupLister attributes & methods: %s" % dir(groupLister))
… an excerpt of its output from openhab.log:
2018-11-14 11:37:10.147 [INFO ] [thome.model.script.Rules.GroupLister] - ==> gAllOffToggleMonitor_Scene_Monitors (Type=GroupItem, Members=2, State=NULL, Label=null, Category=null)
2018-11-14 11:37:10.152 [INFO ] [thome.model.script.Rules.GroupLister] - |-- gScene_Monitor_Scene_03 (Type=GroupItem, BaseType=SwitchItem, Members=3, State=ON, Label=null, Category=null, Groups=[gAllOffToggleMonitor_Scene_Monitors])
2018-11-14 11:37:10.156 [INFO ] [thome.model.script.Rules.GroupLister] - |-- gScene_Monitor_Scene_04 (Type=GroupItem, BaseType=SwitchItem, Members=3, State=ON, Label=null, Category=null, Groups=[gAllOffToggleMonitor_Scene_Monitors])
First an observation – I just converted some fairly complex Extend-style rules to use the JSR223-Jython interface and it is blazing-fast. The new decorators make a lot of sense and are very usable.
Second – a bit of a conundrum. I have a bunch of rules with “Member of Group changed”-style triggers. They all start out like this:
@rule("Member of gGroup_01 changed")
@when("Member of gGroup_01 changed")
def mainFunction(event):
thisItem = ir.getItem(str(event.itemName))
triggeredby = str(thisItem.name)
## DO STUFF based on item state......
@rule("Member of gGroup_02 changed")
@when("Member of gGroup_02 changed")
def mainFunction(event):
thisItem = ir.getItem(str(event.itemName))
triggeredby = str(thisItem.name)
## DO STUFF based on item state......
The problem that I am seeing occurs when a given item is a member of both gGroup_01 and also of gGroup_02 ergo both rules fire. MOST of the time everything works swimmingly (and FAST) but every once in a while the second-firing rule ends up throwing a NPE when making the call to ir.getitem(). This occurs on the order of 5 percent (or less) of the time – it is not confined to any particular item and the system recovers – the event in question is lost and so garbage-collection gets triggered in the JVM by the NPE – things in general are insensitive for a few seconds but do recover. I’ve put Try … Except blocks around the code with a delay-retry of the ir.getItem() in the exception block but that does not eliminate the problem (at least so far). Based on some of the logs I am getting, it looks like the window of vulnerability to this is a few thousandths of a second wide.
Hi @bob_dickenson, I’m using a fairly complex set of generic, group-based rules that use triggers very similar to yours, in particular, because I have some items that belong to multiple groups referenced in multiple triggers, I have multiple rules triggered nearly simultaneously by changes to a single item common to more than one group. Because my rule actions need to know the group or the groups to which the triggering item belongs, the first part of my rules get a proper item instance as follows (no need for the conversion to a Jython str):
sceneGroup = ir.getItem(event.itemName)
if sceneGroup in self.group.members:
self.logger.debug("scene load group: %s changed to: %s" %
(sceneGroup.name, event.itemState))
Also, note that when an item instance’s string name is needed, I haven’t found it necessary to explicitly convert the item’s name attribute to a Jython str.
I have yet to see any indication in my logs that I have bumped into the problem you describe, which seems odd.
Which version of OH are you running? If not recent (I think it is in M5… definitely in recent snapshots), you may not have this fix. You could log the itemName at the start of the rule, and you might be able to spot the issue. This would only effect you if you have groups as members of the group.
Another thing is that your two functions are defined with the same name (mainFunction), but they should be unique. I’m actually surprised that the script works at all.
Hopefully this helps!
Why is it so that they have to be unique?
I have one test script with same kind of content but never got any problems? I always name them
def execute(event, log)
blah blah...
I guess when you don’t use these decorators the identical class name would be a problem?
I’m using M5 with a standalone jython2.7.1. The str() might not be necessary in the immediate context – I started doing it routinely because concatenation in log.X statements doesn’t like non-strings.
I’ll re-insert some naked logging of the event.itemName — although I believe that in some earlier iterations I was using a construct similar to:
def mainFunction(event):
triggeredby=event.itemName
thisItem = ir.getItem(triggeredby)
## DO STUFF
The NPE first started showing up under this type of wiring (AFAIR – it’s been an intense few days).
Nonetheless, I will put logging (back) in as you suggest and go snipe-hunting.
Also changing to unique function names – although (like @gitMiguel ) I have gotten no error messages or other misbehavior from this. (?? maybe you mean the “@rule” contents — uniqueness there would be consistent with Xtend…)
Could this be a 2.7.1 problem?
Why would you want to redefine all of your functions? 
The second time you define a function to the same name, you are redefining the function:
def test():
log.debug("JSR223: test: inside 1")
log.debug("JSR223: test: outside 1")
test()
def test():
log.debug("JSR223: test: inside 2")
log.debug("JSR223: test: outside 2")
test()
This will log
2018-11-16 15:10:39.253 [DEBUG] [org.eclipse.smarthome.model.script.Rules] - JSR223: test: outside 1
2018-11-16 15:10:39.253 [DEBUG] [org.eclipse.smarthome.model.script.Rules] - JSR223: test: inside 1
2018-11-16 15:10:39.254 [DEBUG] [org.eclipse.smarthome.model.script.Rules] - JSR223: test: outside 2
2018-11-16 15:10:39.254 [DEBUG] [org.eclipse.smarthome.model.script.Rules] - JSR223: test: inside 2
If you don’t have issues with redefining the functions, that’s good to know. But are you sure that this isn’t/won’t cause any problems? I’m not so sure, I’ve never tested it, and I did not intend for the functions to be redefined when I wrote the decorators. That’s why I pointed it out. It would be good to test with unique function names to see if this might resolve the problem. If it doesn’t, I still would not recommend it as it could cause other issues. And if anything, it’s just smelly code!
Redefining the functions means you can’t call them from other rules, and you can’t call them directly in the script when it loads, as a replacement for the StartupTrigger.
Try using format. It can take about anything and turn it into a string, and can do some conversions too.
log.debug("Member of Group_01 changed: [{}]: [{}]".format(event.itemName, thisItem.label))
There are known issues with 2.7.1. It would be best to use 2.7.0 until they are resolved. Not sure if it would cause the issue, but possible. If you’re running M5, then you have the fix for ItemStateChangeTrigger.
No, I meant the function names. The rule names actually do not have to be unique, but I recently added this as a requirement so that the rules can be iterated by name. You will get an error in the log when a rule is being added with a name that matches another rule.
Are you running off an SD card? Could possibly be a sign of a the card having issues?
In no particular order:
As a “play-by-play” report – since I made earlier changes supra, problem has not recurred. To be fair, it often took a few hours to manifest when it was failing “regularly” so that is not conclusive, but just reporting.
[ On a pure “gut level”, this has smelled like some sort of timing heisenbug from early on, so adding logging injections could easily mask the root cause — not an intellectually-complete answer but pragmatic (if it holds up). ]
Will keep the thread posted as things go on.
ok, I finally realized what is going on with the timer - you cannot cancel a timer once it has been started it seems?
I don’t quite follow you here. I understand what you mean but this aplies e.g. for global functions defined in top of single script file:
That is not the same as in Bobs post or my post. Aren’t we talking about two separate rules callback functions in a single file? As in Bobs post:
My example was illustrating redefining a function, which is what Bob is doing. I am surprised the decorators and rule engine handle it. This was not intended or tested, so there is a chance of it causing unexpected side effects. 
I am also confused ( like @gitMiguel )— unless the “@rule” decorator invocations are all emitting functions to the same class – there is no redefinition here. Seems like each rule definition might be a subclass of a super “Rule” or a “Member of group”-rule subclass.
(I did change all my function names to be unique – just to eliminate that as a source of noise in figuring this issue out…but NOT clear on the reasoning here.)
Also switched back to Jython 2.7.0
@bob_dickenson and @gitMiguel, in your code you created two function objects with the name, mainFunction, within the same scope. The second definition effectively overwrites the first within that scope. The decorators don’t replace mainFunction(), they simply wrap it. @5iver’s reasoning makes sense to me.
so you are saying that all “@rule” share the same scope–ergo all function names must be unique ? If that is so, then why allow function definitions outside of “@rule” since they all have the same scope. That just seems “wrong” and un-pythonic.