Event/Switch toggles

[icompas (Immo)]

• Platform information:

  • Hardware: RasPI 3B+
  • OS: Debian 9.0
  • openHAB version: 2.4.0

• Issue of the topic:

I have rules which should trigger a pump to run for five minutes only. That will happen frequently, e.g. every 15 minutes.

rule "Vormittags"
when
/* Seconds, Minutes, Hours, Day-of-Month, Month, Day-of-Week, Year (optional field)*/
/* alle 15 Minute, 5-10 Uhr, Mo-Fri */
    Time cron "0 0/15 5-9 ? * 2-6"
then
    if (VacationMode.state.toString == 'OFF') {
        akt_verbrauch = (Verbrauch.state as DecimalType).floatValue
        logInfo("leistungsdaten.rules", "Aktuell bei Einschalten: " + akt_verbrauch )
    	logInfo("leistungsdaten.rules", "Geraetedaten bei Einschalten: " + Verbrauch.state )
        if (Pumpe_Warmwasser.state != ON) {
        	Pumpe_Warmwasser.sendCommand(ON)
        }
    } 
end

This rule sends the command ON to the pump.
To switch the pump off after five minutes, I have created another rule, which fires a timer, and issues the command OFF. See the code below, and you can ignore the calculations.

rule "Pumpe_an_5_Minuten"
when
        Item Pumpe_Warmwasser changed from OFF to ON
then
    currentHour = now.getHourOfDay()
    logInfo("leistungsdaten.rules","--- Aktuelle Stunde System: " + currentHour)

    if (currentHour < 23 && currentHour > 4) {
        if (timer !== null) {
                timer.cancel
                timer = null
        }
        timer = createTimer(now.plusMinutes(5), [|
        // aktuellen Wert abfragen
        logInfo("leistungsdaten.rules", "Aktuell bei Ausschalten: " + (Verbrauch.state as DecimalType).floatValue)
        akt_verbrauch = (Verbrauch.state as DecimalType).floatValue - akt_verbrauch
        // Differenz ausgeben
        logInfo("leistungsdaten.rules", "Differenz bei Ausschalten: " + akt_verbrauch)
        if (Pumpe_Warmwasser.state != OFF) {
                Pumpe_Warmwasser.sendCommand(OFF)
        }
        ])
    } 
end

I have choosen the approach no to integrate everything in one rule, since I use various time frames for switching throughout the week, e.g. morning/evening vs. the remaining day, weekdays vs. weekends. So, the rule for switching ON basically exists multiple times. Having the ‘OFF to ON’ rule is for simplification, since it applies for all times and days the same.

Generally, this works ok, But what I observe is that the event is toggling unwantedly sometimes. Here some extracts from the events.log:

2018-10-11 08:00:00.100 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-11 08:00:14.852 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
...
2018-10-11 08:15:00.081 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-11 08:15:00.185 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
2018-10-11 08:15:15.105 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-11 08:20:15.205 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
...
2018-10-11 09:00:00.160 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-11 09:00:00.696 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
2018-10-11 09:00:15.683 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-11 09:05:15.807 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
2018-10-11 09:05:15.820 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-11 09:05:30.794 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF

Especially the 0900 event is interesting, because it shows toggling while transitioning from OFF to ON and vice versa.

Anyone an idea how to improve this and make it more stable?

[vzorglub (Vincent Regaud)]

Only create the timer when it is null and cancel it at the end of execution
Are there any other rules that could turn the pump OFF?

rule "Pumpe_an_5_Minuten"
when
        Item Pumpe_Warmwasser changed from OFF to ON
then
    currentHour = now.getHourOfDay()
    logInfo("leistungsdaten.rules","--- Aktuelle Stunde System: " + currentHour)

    if (currentHour < 23 && currentHour > 4) {
        if (timer === null) {
            timer = createTimer(now.plusMinutes(5), [|
                // aktuellen Wert abfragen
                logInfo("leistungsdaten.rules", "Aktuell bei Ausschalten: " + (Verbrauch.state as DecimalType).floatValue)
                akt_verbrauch = (Verbrauch.state as DecimalType).floatValue - akt_verbrauch
                // Differenz ausgeben
                logInfo("leistungsdaten.rules", "Differenz bei Ausschalten: " + akt_verbrauch)
                if (Pumpe_Warmwasser.state != OFF) {
                    Pumpe_Warmwasser.sendCommand(OFF)
                }
                timer.cancel
                timer = null
            ])
        }
    } 
end

[icompas (Immo)]

Thanks for the hint. I will apply it and test it.
No, there are no other rules turning the pump OFF.

[rossko57]

Just pointing out … nothing magic about the variable name ‘timer’. You may have other rules operating on what they think is their own’ timer’ , it’s a little trap.
I would change the name to pumpTimer or something so that you don’t get caught out.

[icompas (Immo)]

Thanks, might be good to consider in the future. Currently, it is the one and only I use.

[rlkoshak (Rich Koshak)]

I have choosen the approach no to integrate everything in one rule, since I use various time frames for switching throughout the week, e.g. morning/evening vs. the remaining day, weekdays vs. weekends. So, the rule for switching ON basically exists multiple times. Having the ‘OFF to ON’ rule is for simplification, since it applies for all times and days the same.

If they are truly the same rule repeated multiple times then you should consider combining those rules into one. You can trigger a Rule with multiple triggers.

I actually like keeping the 5 minute Rules separate because that will ensure that the pump only runs for 5 minutes no matter how it is turned on.

You might find the Design Pattern: Time Of Day useful which will centralize a lot of these time calculations and make them available as a state to all your Rules.

You can simplify the canceling of the Timer code to:

timer?.cancel

The ? will skip the line if timer is null. Otherwise it will call cancel. There is no need to set timer to null here because the very next line will reassign it a new Timer anyway.

What is in openhab.log? Do you see the log from inside the Timer at 09:00? If not then something else is turning off the pump. I could see it being possible that the binding is polling the pump for its state at the same time that you issue the command to turn it on. So you send your command, the Item changes from OFF to ON, and at the same time the result from the last poll comes in and since the pump was OFF it changes the Item to OFF. I don’t know what binding you are using and whether it even polls devices for states or not, but that is one scenario that could explain the behavior.

From a readability perspective it helps to indent the code inside the [ ]. It makes it easier to tell where the Timer lambda starts and stops.

Anyway, after all of that, I don’t see anything obviously wrong with the logic.

[vzorglub (Vincent Regaud)]

If you want the pump to only run for 5 minutes no matter what then have a look at the expire binding.

[icompas (Immo)]

Thanks for all the hints and tips, much appreciated.
So, I basically applied the corrections for the timer, incl. the

timer?.cancel

This makes the code more readable and easier to understand.
Second, I combined the several rules into one, using multiple triggers. And this definitely increases the code simplification a lot.

rule "Pumpe_An"
when
/* Seconds, Minutes, Hours, Day-of-Month, Month, Day-of-Week, Year (optional field)*/
/* alle 15 Minute, 5-10 Uhr, Mo-Fri */
/* alle 20 Minute, 10-17 Uhr, Mo-So */
/* alle 15 Minute, 17-23 Uhr, Mo-So */
/* alle 15 Minute, 6-10 Uhr, Sa, So */

    Time cron "0 0/15 5-9 ? * 2-6" or
	Time cron "0 0/20 10-16 ? * *" or
	Time cron "0 0/15 17-22 ? * *" or
	Time cron "0 0/15 6-9 ? * 1,7" 

then
    if (VacationMode.state.toString == 'OFF') {
		akt_verbrauch = (Verbrauch.state as DecimalType).floatValue
		logInfo("leistungsdaten.rules", "Aktuell bei Einschalten: " + akt_verbrauch )
    	        logInfo("leistungsdaten.rules", "Geraetedaten bei Einschalten: " + Verbrauch.state )
		if (Pumpe_Warmwasser.state != ON) {
			Pumpe_Warmwasser.sendCommand(ON)
		}
	} 
end

The openhab.log did not reveal anything. I use the AVM Fritz! binding. Not sure though if it does any polling. I agree that this would might be a reason for the bounce effect seen.
So, let’s see how the code changes behave.

[icompas (Immo)]

Ok - I think I need to deal with polling, which might interferes with my intentions.

OpenHab2 - avmfritz binding & expire binding conflict (ON every 15 seconds)

Hi Uwe, I’m not sure you really need a proxy item. It should also work like this (not tested): rule "ug_hzng_outlet1 timer" when Item ug_hzng_outlet1 changed then if (ug_hzng_outlet1.state == OFF) { if (timer != null) { timer.cancel timer = null } } if (ug_hzng_outlet1 == ON) { timer = createTim…

This actually describes a similar issue, and points to polling.

[icompas (Immo)]

So, I checked the the debug level of the AVM Fritz! binding.
It polls every 15 seconds, e.g. 11, 26, 41, 56 after the minute. That shifts a bit depending on whatever condition.

I tracked the behavior after the changes made above, suing the DEBUG mode for

org.openhab.binding.avmfritz

openhab> things list
...
avmfritz:FRITZ_DECT_200:192_168_2_10:087610053251 (Type=Thing, Status=ONLINE, Label=FRITZ!DECT 200, Bridge=avmfritz:fritzbox:192_168_2_10)
...

In the event.log I observe the following bounce:

2018-10-12 12:20:00.100 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-12 12:20:01.192 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
2018-10-12 12:20:15.880 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON

So I checked the opnehab.log and find the following information:

2018-10-12 12:20:00.049 [INFO ] [me.model.script.leistungsdaten.rules] - Aktuell bei Einschalten: 33773.0
2018-10-12 12:20:00.061 [INFO ] [me.model.script.leistungsdaten.rules] - Geraetedaten bei Einschalten: 33773
2018-10-12 12:20:00.095 [DEBUG] [itz.handler.AVMFritzBaseThingHandler] - Handle command 'ON' for channel outlet
2018-10-12 12:20:00.103 [DEBUG] [ternal.hardware.FritzAhaWebInterface] - GETting URL http://192.168.2.10/webservices/homeautoswitch.lua?ain=087610053251&switchcmd=setswitchon&sid=da19b9dde9f88aa5
2018-10-12 12:20:00.130 [INFO ] [me.model.script.leistungsdaten.rules] - --- Aktuelle Stunde System: 12
2018-10-12 12:20:00.173 [DEBUG] [tz.handler.AVMFritzBaseBridgeHandler] - polling FRITZ!Box avmfritz:fritzbox:192_168_2_10
2018-10-12 12:20:00.175 [DEBUG] [ternal.hardware.FritzAhaWebInterface] - GETting URL http://192.168.2.10/webservices/homeautoswitch.lua?switchcmd=getdevicelistinfos&sid=da19b9dde9f88aa5
2018-10-12 12:20:00.608 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response 200
2018-10-12 12:20:00.610 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response 200
2018-10-12 12:20:00.612 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response complete: 1
2018-10-12 12:20:00.614 [DEBUG] [.callbacks.FritzAhaSetSwitchCallback] - Received State response 1
 for item 087610053251
2018-10-12 12:20:01.113 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response 200
2018-10-12 12:20:01.117 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response 200
2018-10-12 12:20:01.120 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response complete: <devicelist version="1"><device identifier="11657 0057984" id="21" functionbitmask="1280" fwversion="04.09" manufacturer="AVM" productname="FRITZ!DECT Repeater 100"><present>1</present><name>FRITZ!DECT Rep 100</name><temperature><celsius>235</celsius><offset>0</offset></temperature></device><device identifier="08761 0053251" id="22" functionbitmask="2944" fwversion="04.09" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><name>FRITZ!DECT 200</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><powermeter><voltage>230050</voltage><power>0</power><energy>33773</energy></powermeter><temperature><celsius>320</celsius><offset>0</offset></temperature></device></devicelist>
2018-10-12 12:20:01.159 [DEBUG] [tz.handler.AVMFritzBaseBridgeHandler] - set device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@f750ae[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@f750ae[ain=087610053251,bitmask=2944,isDectRepeater=false,isPowermeter=true,isTempSensor=true,isSwitchableOutlet=true,isHeatingThermostat=false,id=22,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.09,present=1,name=FRITZ!DECT 200,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@3f53b[state=0,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@1921c42[power=0.000,energy=33773],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1e1972e[celsius=32.0,offset=0.0]]
2018-10-12 12:20:01.164 [DEBUG] [tz.handler.AVMFritzBaseBridgeHandler] - update thing avmfritz:FRITZ_DECT_200:192_168_2_10:087610053251 with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@f750ae[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@f750ae[ain=087610053251,bitmask=2944,isDectRepeater=false,isPowermeter=true,isTempSensor=true,isSwitchableOutlet=true,isHeatingThermostat=false,id=22,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.09,present=1,name=FRITZ!DECT 200,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@3f53b[state=0,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@1921c42[power=0.000,energy=33773],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1e1972e[celsius=32.0,offset=0.0]]
2018-10-12 12:20:01.185 [DEBUG] [tz.handler.AVMFritzBaseBridgeHandler] - no thing UID found for device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@f750ae[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@f750ae[ain=087610053251,bitmask=2944,isDectRepeater=false,isPowermeter=true,isTempSensor=true,isSwitchableOutlet=true,isHeatingThermostat=false,id=22,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.09,present=1,name=FRITZ!DECT 200,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@3f53b[state=0,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@1921c42[power=0.000,energy=33773],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1e1972e[celsius=32.0,offset=0.0]]

The outlet is switched on, and response of the command is ok. But looking into the message of the [tz.handler.AVMFritzBaseBridgeHandler] I see the state=0.

openhab.binding.avmfritz.internal.ahamodel.SwitchModel@3f53b[state=0 …

The polling result 15 seconds later posts the expected state,

2018-10-12 12:20:15.178 [DEBUG] [tz.handler.AVMFritzBaseBridgeHandler] - polling FRITZ!Box avmfritz:fritzbox:192_168_2_10
2018-10-12 12:20:15.190 [DEBUG] [ternal.hardware.FritzAhaWebInterface] - GETting URL http://192.168.2.10/webservices/homeautoswitch.lua?switchcmd=getdevicelistinfos&sid=da19b9dde9f88aa5
2018-10-12 12:20:15.795 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response 200
2018-10-12 12:20:15.799 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response 200
2018-10-12 12:20:15.803 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response complete: <devicelist version="1"><device identifier="11657 0057984" id="21" functionbitmask="1280" fwversion="04.09" manufacturer="AVM" productname="FRITZ!DECT Repeater 100"><present>1</present><name>FRITZ!DECT Rep 100</name><temperature><celsius>235</celsius><offset>0</offset></temperature></device><device identifier="08761 0053251" id="22" functionbitmask="2944" fwversion="04.09" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><name>FRITZ!DECT 200</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><powermeter><voltage>229710</voltage><power>49990</power><energy>33773</energy></powermeter><temperature><celsius>320</celsius><offset>0</offset></temperature></device></devicelist>
2018-10-12 12:20:15.840 [DEBUG] [tz.handler.AVMFritzBaseBridgeHandler] - set device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@19ab55a[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@19ab55a[ain=087610053251,bitmask=2944,isDectRepeater=false,isPowermeter=true,isTempSensor=true,isSwitchableOutlet=true,isHeatingThermostat=false,id=22,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.09,present=1,name=FRITZ!DECT 200,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@1e0d190[state=1,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@456e7c[power=49.990,energy=33773],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1ae7e8f[celsius=32.0,offset=0.0]]
2018-10-12 12:20:15.846 [DEBUG] [tz.handler.AVMFritzBaseBridgeHandler] - update thing avmfritz:FRITZ_DECT_200:192_168_2_10:087610053251 with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@19ab55a[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@19ab55a[ain=087610053251,bitmask=2944,isDectRepeater=false,isPowermeter=true,isTempSensor=true,isSwitchableOutlet=true,isHeatingThermostat=false,id=22,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.09,present=1,name=FRITZ!DECT 200,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@1e0d190[state=1,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@456e7c[power=49.990,energy=33773],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1ae7e8f[celsius=32.0,offset=0.0]]
2018-10-12 12:20:15.865 [DEBUG] [tz.handler.AVMFritzBaseBridgeHandler] - no thing UID found for device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@19ab55a[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@19ab55a[ain=087610053251,bitmask=2944,isDectRepeater=false,isPowermeter=true,isTempSensor=true,isSwitchableOutlet=true,isHeatingThermostat=false,id=22,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.09,present=1,name=FRITZ!DECT 200,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@1e0d190[state=1,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@456e7c[power=49.990,energy=33773],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1ae7e8f[celsius=32.0,offset=0.0]]

openhab.binding.avmfritz.internal.ahamodel.SwitchModel@1e0d190[state=1

This matches the event.log entry earlier,

2018-10-12 12:20:15.880 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON

Actually in this 5 minute ON/OFF sequence, the same behavior happens when the switch is turned OFF.

2018-10-12 12:25:00.175 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
2018-10-12 12:25:01.278 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-12 12:25:15.944 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF

The DEBUG information in the openhab.log reveals this.

Interesting is, that thereafter everything works as expected,

2018-10-12 12:40:00.079 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-12 12:45:00.145 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
2018-10-12 13:00:00.132 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-12 13:05:00.185 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF
2018-10-12 13:20:00.103 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from OFF to ON
2018-10-12 13:25:00.200 [vent.ItemStateChangedEvent] - Pumpe_Warmwasser changed from ON to OFF

Will now be interesting to find a way to avoid this.

[rlkoshak (Rich Koshak)]

You might file an issue on the binding you are using because I don’t think there is much you can do about this from your Rules. There may need to be something done in in the binding to deal with this.

[icompas (Immo)]

Any hints on how and where?
I’m happy to address this issue.

[rlkoshak (Rich Koshak)]

avmfritz

openhab/openhab2-addons

Reference this thread in your issue. Provide as much information as you can including configurations and logs.

[icompas (Immo)]

Thank you! Just done …