[Z-Wave] OH 2.5.9 stable - a lot of double events in 10 to 20 ms

I’m migrated from OH 2.4 to OH 2.5.9. I see a lot of z-wave events which are arrved more then one time at the event bus.

This means, the same event is tirggered more times in OH within some ms.

Does anyone else see this problem?

Yes.

This is not the same problem.

my problem:
on OH 2.4 I do not see such problems

on OH 2.5.8 I see this:

item:
Switch Motion01_MotionAlarm                     "Treppe EG/OG Motion [MAP(motion.map):%s]"                              <alarm> (gMAPDB,gAlarmNotification) { channel="zwave:device:15a7a49f3a6:node93:alarm_motion" }

rule:
rule "gAlarmNotification ausloesen und in log schreiben"
	when
		Member of gAlarmNotification changed
	then
...
logInfo("Logger", triggeringItem.label + " " + transform("MAP", "ITEMACTION.map", triggeringItem.name + "#" + triggeringItem.state.toString ) + ".")
...

only one event in events.log:
2020-09-30 22:24:00.323 [vent.ItemStateChangedEvent] - Motion01_MotionAlarm changed from OFF to ON

but 2 log entries in openhab.log with same time stamp:
2020-09-30 22:24:13.915 - Treppe EG/OG Motion erkannt.
2020-09-30 22:24:13.915 - Treppe EG/OG Motion erkannt.

It looks like there is a problem with rules engine which is not there in OH 2.4? Some events are triggered more times even if the event itself is there only one time.

Not sure if thsi will happen only for z-wave items, but at the moment I do not see it for my modbus items.

The changed event you showed us seems to have nothing to do with the rule log from thirteen seconds later? Or are you saying that the rule takes thirteen seconds to trigger?

Thinks - as this happens to be a motion sensor, is there another change (back to idle) in that thirteen seconds? I am thinking about two events queued up waiting for the rule to “compile” or whatever causes that delay period.

For logging - note that by default only changes are logged. An Item can get updated twice but only one change will be logged. That shouldn’t matter here, because your rule is triggered on change, just pointing out for interpretation of logs.

New log file snipes:

2020-10-01 11:04:43.931 [vent.ItemStateChangedEvent] - DoorSensor58 changed from CLOSED to OPEN

causes two times trigger on change rule
2020-10-01 11:04:43.947 - Briefkasten geoeffnet.
2020-10-01 11:04:43.962 - Briefkasten geoeffnet.

Is there a way to debug this?

Perhaps the first step is to eliminate any Group interactions. As far as I know, group rule triggers actually expand behind to the scenes to a list of individual Items, it is theoretically possible therefore to get listed twice.

It should not be possible to have exact duplicate copies of rules, as they are keyed on rule “name”. Two copies of one rule in the same or different rules files would result in only the ‘last’ one read being in service.

Leave your existing rules alone, add rules for an individual -

rule "testing change"
	when
		DoorSensor58 changed
	then
        logInfo("testchange", triggeringItem.label + " changed " 
end

rule "testing update"
	when
		DoorSensor58 received update
	then
        logInfo("testupdate", triggeringItem.label + " updated " 
end

This topic was automatically closed 41 days after the last reply. New replies are no longer allowed.