Rules cycling despite reentrant.lock

Setup, Configuration and Use Scripts & Rules
10

Needs to be var ReentrantLock, not just var Lock, however rule still triggers twice:

2017-02-16 20:00:54.626 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:00:54.627 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)
2017-02-16 20:00:54.627 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:00:54.628 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)
11

If the second trigger arrives after the rule is completed, it will run twice. The lock only stops reentrancy, i.e. two copies of the rule running at the same time.

Alarms is a group and multiple updates are the norm, as you know

12

I am missing the (ALL), but yes, I have:

Group:Contact:OR(OPEN, CLOSED) Alarms

13

Having got a lock now, you can work around the multiple update ‘feature’ by having your rule sleep while it has a hold of the lock. Further updates will be bounced until the lock is released.

14

All that did was delay the 2nd firing of the rule.

Before Delay:

2017-02-16 20:00:54.626 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:00:54.627 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)
2017-02-16 20:00:54.627 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:00:54.628 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)

With Delay:

2017-02-16 20:14:58.307 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:14:58.564 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)
2017-02-16 20:14:58.795 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:14:58.796 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)

Rule:

import java.util.concurrent.locks.ReentrantLock

var ReentrantLock lock = new ReentrantLock()

rule "Alarm Triggered"
when
  Item Alarms received update
then
  if (!lock.isLocked) {
    lock.lock()
    try {
      Thread::sleep(200)
      logInfo("Testing", "Alarms received update")
      val alarm = Alarms.members.filter[s|s.lastUpdate("mapdb") != null].sortBy[lastUpdate("mapdb")].last
      if (alarm.state == OPEN) {
        logInfo("Testing", "Test: " + alarm)
      }
    }
    finally {
      lock.unlock()
    }
  }
end
15

Try this out of curiousity

    ...
    finally {
      lock.unlock()
    }
  } else {
      logInfo("testing", "locked, update ignored")
 }
end

I use .lock / .unlock without brackets, but I don’t suppose that matters

16 
2017-02-16 20:32:28.070 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:32:28.070 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)
2017-02-16 20:32:28.271 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:32:28.271 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)
17

Interesting, I added a test if if it was locked and I think the issue is that the rule is being triggered faster then the lock can setup.

2017-02-16 20:34:54.654 [INFO ] [g.openhab.model.script.Testing] - Lock: false
2017-02-16 20:34:54.654 [INFO ] [g.openhab.model.script.Testing] - Lock: false
2017-02-16 20:34:54.855 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:34:54.914 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)
2017-02-16 20:34:55.115 [INFO ] [g.openhab.model.script.Testing] - Alarms received update

Rule:

import java.util.concurrent.locks.ReentrantLock

var ReentrantLock lock = new ReentrantLock()

rule "Alarm Triggered"
when
  Item Alarms received update
then
  logInfo("Testing", "Lock: " + lock.isLocked)
  if (!lock.isLocked) {
    lock.lock()
    try {
      Thread::sleep(200) 
      logInfo("Testing", "Alarms received update")
      val alarm = Alarms.members.filter[s|s.lastUpdate("mapdb") != null].sortBy[lastUpdate("mapdb")].last
      if (alarm.state == OPEN) {
        logInfo("Testing", "Test: " + alarm)
      }
    } 
    finally {
      lock.unlock()
    }
  } else {
    logInfo("Testing", "locked, update ignored")
 }
end
18

Every once and a long time, the rule will not fire in the same ms and it will work!

2017-02-16 20:37:31.061 [INFO ] [g.openhab.model.script.Testing] - Lock: false
2017-02-16 20:37:31.062 [INFO ] [g.openhab.model.script.Testing] - Lock: false
2017-02-16 20:37:31.091 [INFO ] [g.openhab.model.script.Testing] - locked, update ignored
2017-02-16 20:37:31.262 [INFO ] [g.openhab.model.script.Testing] - Alarms received update
2017-02-16 20:37:31.262 [INFO ] [g.openhab.model.script.Testing] - Test: First_Floor_Condensate_Alarm (Type=ContactItem, State=OPEN)

That is more what I am looking for, but 99% of the time it fires twice.

19

Just a side note: Using a lock, the check with " if !lock.islocked" isn’t needed, the lock does that already!

20

In this case, we want to take a different action if we enter the rule and the lock is locked, rather than just queue for it, hence the if-test. Or do you mean you can put the .lock method in the test?
If (!mylock.lock) { … does that work? Would save tme

Looks like you will either have to write code that doesn’t matter if it runs twice, for find a trigger condition other than update-of-group. I cannot think of any locking or debouncing technique quicker than what you have tried.

What is the Openhab host, out of interest? I developed a set of rules on an ancient Windows XP laptop, worked lovely. When transferred to a dual core desktop, it showed up all sorts of reentrant hiccups and needed lots of rework.

21

Linux Intel i7-4770K 3.5 GHz 8 threads

22

Ouch :wink:

23

Posting for future ref - It seems the solution here is to use a structure like

boolean gotLock = lock.tryLock();
try{
    if(gotLock){
        // Do Stuff
    } else {
        // Don't do stuff
    }
}
finally{
    if(gotLock){
        lock.unlock();
    }
}

The .tryLock method allows for acquiring and testing the lock all in one go. It will grab the lock and return TRUE, or it will fail to get the lock and return FALSE. Then you can make a decision, in Nathan’s case to abort the rule altogether, and are not forced into a queue as with the simple .lock method.

By putting a sleep in the got-lock code, you can reject subsequent triggers for a period while it has possession of the lock. An effective (if complicated) debounce method.

1 Like
24

Hi, have several rules and i need to prevent it from firing for 3 seconds.
My switches receive state ON in 3 sec after power on.
Do i have to use lock1, lock2, lock3 for every my switch or ReentrantLock use only one instance?

25

Reentrant lock may not be what you want at all here. Depends what you mean by " prevent firing" - do not perform any action, like discarding that trigger? Or to wait, queue up to perform the action?

How many locks or other tests you might depends on the wanted behaviour too.
Guessing we are dealing with some kind of output switch? OpenHAB turns the switch on, 3 seconds later some Item gets a ready response?
Are you trying to get one switch sequence “in progress” to discard or delay action on other switches? Sounds a bit like a Group job.

26

I add esp8266 after one way RF module, and when RF module received command ON, it powerup light and ESP.
ESP boot up time is 3-4 seconds.
Im use proxy switches for this.
When i turn on light, proxy received comman ON, some times it immediately changing to OFF because of no ping from ESP.
And i want proxy switch do not react for 3 sec after switching and wait for ping.

27

Share your Items definitions, please

28

Here it is, it very complicated - measures current lightness and set dimmer to measured value, when i set brightness from wall switch.

Dimmer	Light_Kuhn2_DIM	"Kitchen table [%.0f %%]"	<slider>	(gDimmers)	{ mqtt="<[oh2agdisk:/esp/kuhn2/lwt:state:0], <[oh2agdisk:/esp/kuhn2/sensors/light:state:SCALE(kuhn2_lux_to_dim.scale)], >[oh2wb:/devices/noolite_tx_0x109/controls/level/on:command:*:SCALE(kuhn2_dim_to_mqtt.scale)]" }
String	Light_Kuhn2_DIM_CMD	"Kitchen table"	<light>	(gLights, gKitchen, gSoftAwake_OtherLights)	{ mqtt=">[oh2wb:/devices/noolite_tx_0x109/controls/state/on:command:OFF:0], >[oh2wb:/devices/noolite_tx_0x109/controls/state/on:command:ON:1], >[oh2wb:/devices/noolite_tx_0x109/controls/switch/on:command:SWITCH:1], >[oh2wb:/devices/noolite_tx_0x109/controls/slowdown/on:command:SLOWDOWN:0], >[oh2wb:/devices/noolite_tx_0x109/controls/slowup/on:command:SLOWUP:1], >[oh2wb:/devices/noolite_tx_0x109/controls/slowswitch/on:command:SLOWSWITCH:1]  ", autoupdate="false" }
Number	ESP_Kuhn2_Uptime	"Uptime [%.0f сек]"	<clock>	{ mqtt="<[oh2agdisk:/esp/kuhn2/sensors/uptime:state:default]" }
Switch	ESP_Kuhn2_Switch	"Kitchen table"	<light>	{ channel="network:device:192_168_1_27:online", mqtt="<[oh2agdisk:/esp/kuhn2/lwt:state:OFF], <[oh2agdisk:/esp/kuhn2/sensors/uptime:state:ON]" } 
Number	ESP_Kuhn2_Lightness	"Kitchen table Lighness [%.0f Lux]" 	{ mqtt="<[oh2agdisk:/esp/kuhn2/sensors/light:state:default]" }
//Proxy Switch
Switch	Light_Kuhn2_Switch	"Kitchen table"	<light>

rule "Light_Kuhn2_Switch" 
when
	Item Light_Kuhn2_Switch received command
then
	if (!lock_kuhn2.isLocked) {
		lock_kuhn2.lock
		try {
			Light_Kuhn2_DIM_CMD.sendCommand(receivedCommand)
			Thread::sleep(3000)
		} finally {
			lock_kuhn2.unlock
			logInfo ("   ---> Lighting", Light_Kuhn2_Switch.label + " - " + receivedCommand)		
		}
	}
end


rule "ESP_Kuhn2_Switch" 
when
	Item ESP_Kuhn2_Switch changed
then
	if (!lock_kuhn2.isLocked) {
		Light_Kuhn2_Switch.postUpdate(ESP_Kuhn2_Switch.state)
		logInfo ("   ---> Lighting", Light_Kuhn2_Switch.label + " - " + ESP_Kuhn2_Switch.state)
	}
end
29

Something change with 2.1? I now get:

java.lang.RuntimeException: The name '<XFeatureCallImplCustom>.lastUpdate(<XStringLiteralImpl>)' cannot be resolved to an item or type.