Exceptions in JSR223 rules (jython) are no longer shown in log (openhab2-daily)

Since some recent update of Openhab2-daily, exceptions in jython-rule execution are no longer shown, making it very hard to debug them.

I use openhab2-jython to execute my rules, but I don’t think this causes the problem (the trigger-decorators to to add the rules do not catch any exception).

My log-setting:
(RULES is the hierarchy I use to get the logger inside my rules - this works fine).

openhab> log:list                                                                                                            11:10:10
Logger                               β”‚ Level
ROOT                                 β”‚ INFO
RULES                                β”‚ DEBUG
javax.jmdns                          β”‚ ERROR
org.apache.karaf.jaas.modules.audit  β”‚ INFO
org.apache.karaf.shell.support       β”‚ OFF
org.eclipse.smarthome                β”‚ INFO
org.jupnp                            β”‚ ERROR
org.openhab                          β”‚ INFO
smarthome.event                      β”‚ DEBUG
smarthome.event.InboxUpdatedEvent    β”‚ ERROR
smarthome.event.ItemAddedEvent       β”‚ ERROR
smarthome.event.ItemRemovedEvent     β”‚ ERROR
smarthome.event.ItemStateEvent       β”‚ ERROR
smarthome.event.RuleStatusInfoEvent  β”‚ WARN
smarthome.event.ThingAddedEvent      β”‚ ERROR
smarthome.event.ThingRemovedEvent    β”‚ ERROR
smarthome.event.ThingStatusInfoEvent β”‚ ERROR

Example rule:

def calcUptime(event):
    dlog = logging.getLogger("RULES.Homie.Monitor.calcUptime") 
    dlog.debug("Event: " + unicode(event) + " (Type: " + unicode(event.__class__))
    item = event.getItemName()
    #up_seconds = event["state"].intValue()  --> Old code that triggered an exception - the exception was not shown.
    up_seconds = event.getItemState().intValue()
    dlog.debug("Item: " + unicode(item) + " (Type: " + unicode(item.__class__) + "); new State: " + unicode(up_seconds) + " (Type: " + unicode(up_seconds.__class__))
    days = up_seconds / 86400
    up_seconds %= 86400
    hours = up_seconds / 3600
    up_seconds %= 3600
    minutes = up_seconds / 60
    # up_seconds %= 60
    up_string = "{} {} {:02d}:{:02d}".format(unicode(days) if (days > 0) else "", "Tage, " if (days > 0) else "", hours, minutes)
    dlog.debug("Uptime: " + up_string)
    events.postUpdate(item + "_str", up_string)        

I have the feeling this is happening on my installation as well. Can’t tell since which version though.

I found out that they are send to syslog, so I can find them in /var/log/syslog.

Is there really no other way than to have a look at syslog?

I’ve created an issue on the smarthome project: https://github.com/eclipse/smarthome/issues/4825

A possible workaround for the current version: set the log level of org.eclipse.smarthome.automation.core to DEBUG

1 Like