Unipi relay switching and then switching back immediately when rule triggers

---

First of all, thanks a lot. Pimatic is really a marvellous piece of software! It’s really working in a big way.

Now, I did come across an issue when I tried to improve my rules, and I have decided to post it here, because I am not sure whether this is a bug or I am just getting my rules wrong. Please advise if I should rather post this on github.

My setup involves pimatic with the unipi-evok and max plugins, as well as some others which I don’t think are related to this topic. The relays on the Unipi board are used to switch the pumps and the burner of the heating system.

With my new rules I observe a strange behavior which consists in a relay switching as according to my rule but then immediately switching back, although (I believe) there is no rule that should trigger such an action. I have observed this on several occasions, although I don’t think that the effect can be reliably reproduced. I wonder if this is related to varying response times from the Unipi board which is connected via the Evok web service running on the Pi. When I switch logging on for unipi-evok, then this situation shows as follows:

10:49:53.738 [pimatic-unipi-evok] debug: [UniPiTemperature#speicher] status update: { interval: 15,
10:49:53.738 [pimatic-unipi-evok] debug:>  value: 60.05,
10:49:53.738 [pimatic-unipi-evok] debug:>  circuit: '28FF2179B51605B6',
10:49:53.738 [pimatic-unipi-evok] debug:>  address: '28FF2179B51605B6',
10:49:53.738 [pimatic-unipi-evok] debug:>  time: 1515923393.731506,
10:49:53.738 [pimatic-unipi-evok] debug:>  typ: 'DS18B20',
10:49:53.738 [pimatic-unipi-evok] debug:>  lost: false,
10:49:53.738 [pimatic-unipi-evok] debug:>  dev: 'temp' }
10:49:53.766 [pimatic-unipi-evok] debug: [UniPiRelay#pumpe-laden-warmwasser] state change requested to: false
10:49:53.834 [pimatic-unipi-evok] debug: [UniPiRelay#pumpe-vorlauf-heizung] state change requested to: true
10:49:53.892 [pimatic-unipi-evok] debug: [UniPiRelay#brenner] state change requested to: false
10:49:53.974 [pimatic] info: rule set-state-off: set $operation-state to off
10:49:54.019 [pimatic-unipi-evok] debug: [UniPiRelay#brenner] state changed to: false
10:49:54.024 [pimatic] info: rule set-state-off: turned Brenner off
10:49:54.040 [pimatic-unipi-evok] debug: [UniPiRelay#pumpe-laden-warmwasser] state changed to: false
10:49:54.046 [pimatic] info: rule set-state-off: turned Pumpe Laden Warmwasser off
10:49:54.072 [pimatic-unipi-evok] debug: [UniPiRelay#pumpe-vorlauf-heizung] state changed to: true
10:49:54.077 [pimatic] info: rule set-state-off: turned Pumpe Vorlauf Heizung on
10:49:54.092 [pimatic-unipi-evok] debug: [UniPiUpdateManager] received update: {"value": 0, "pending": false, "circuit": "3", "dev": "relay", "glob_dev_id": 0}
10:49:54.098 [pimatic-unipi-evok] debug: [UniPiRelay#pumpe-laden-warmwasser] status update: { value: 0,
10:49:54.098 [pimatic-unipi-evok] debug:>  pending: false,
10:49:54.098 [pimatic-unipi-evok] debug:>  circuit: '3',
10:49:54.098 [pimatic-unipi-evok] debug:>  dev: 'relay',
10:49:54.098 [pimatic-unipi-evok] debug:>  glob_dev_id: 0 }
10:49:54.101 [pimatic-unipi-evok] debug: [UniPiUpdateManager] received update: {"value": 1, "pending": false, "circuit": "2", "dev": "relay", "glob_dev_id": 0}
10:49:54.105 [pimatic-unipi-evok] debug: [UniPiRelay#pumpe-vorlauf-heizung] status update: { value: 1,
10:49:54.105 [pimatic-unipi-evok] debug:>  pending: false,
10:49:54.105 [pimatic-unipi-evok] debug:>  circuit: '2',
10:49:54.105 [pimatic-unipi-evok] debug:>  dev: 'relay',
10:49:54.105 [pimatic-unipi-evok] debug:>  glob_dev_id: 0 }
10:49:54.108 [pimatic-unipi-evok] debug: [UniPiUpdateManager] received update: {"value": 1, "pending": false, "circuit": "3", "dev": "relay", "glob_dev_id": 0}
10:49:54.118 [pimatic-unipi-evok] debug: [UniPiRelay#pumpe-laden-warmwasser] status update: { value: 1,
10:49:54.118 [pimatic-unipi-evok] debug:>  pending: false,
10:49:54.118 [pimatic-unipi-evok] debug:>  circuit: '3',
10:49:54.118 [pimatic-unipi-evok] debug:>  dev: 'relay',
10:49:54.118 [pimatic-unipi-evok] debug:>  glob_dev_id: 0 }

Everything looks good until 10:49:54.108 when UniPiUpdateManager suddenly reports that the relay at circuit 3 has a value of 1 again. The rule that has triggered this is here:

{
  "id": "set-state-off",
  "name": "set-state-off",
  "rule": "when [$operation-mode = \"hot-water\" and $speicher.temperature > ($clipTemperatureHotWaterBottom + $clipTemperatureHotWaterOffset)] or [$operation-mode = \"heating-with-hot-water\" and $heizung-vorlauf.temperature > ($clipTemperatureBottom + $clipTemperatureOffset) and $speicher.temperature > ($clipTemperatureHotWaterBottom + $clipTemperatureHotWaterOffset)] then set $operation-state to \"off\" and turn brenner off and turn pumpe-vorlauf-heizung on and turn pumpe-laden-warmwasser off",
  "active": true,
  "logging": true
}

@mwittig marcus did you see this one here?

@leader21 Yes, but I am not able to reproduce the error

ok! i thought if there’s a solution on this you might have been the one to know

Thanks, I take it that this is not a behaviour that is familiar to the Pimatic team, correct? I fancy that this is really something to do with the Evok subsystem. It looks like for some timing or latency issue the state change request is overtaken by an state update and then lost.
I’ll cross-post this issue in the Unipi forum and get back here with whatever I find out.

After involuntarily taking a couple of cold showers recently I thought I get back to this subject. A have built myself a little test rig (luckily I have a spare UniPi). I can confirm now that there is a reproducible behavior in my pimatic / UniPi combination that leads to a state in which a relay is not switched as desired. The condition is a) that at least 2 relays are switched at the same time plus b) a race condition. Although reproducible, b) results in this effect showing or not. The condition a) can be met by switching 2 relays in the same rule as well as 2 relays switching in 2 different rules, where one rule triggers the other. For example, the following set of rules will produce the behavior:

{
  "id": "switchback-tester",
  "name": "switchback_tester",
  "rule": "when brenner is turned on then turn relay-5 off and turn relay-6 off",
  "active": true,
  "logging": true
},
{
  "id": "switchback-tester-2",
  "name": "switchback_tester-2",
  "rule": "when brenner is turned off then turn relay-5 on and turn relay-6 on",
  "active": true,
  "logging": true
},
{
  "id": "switchback-tester-brenner",
  "name": "switchback_tester_brenner",
  "rule": "when every 30s then turn brenner on",
  "active": true,
  "logging": true
},
{
  "id": "switchback-tester-brenner-2",
  "name": "switchback_tester_brenner-2",
  "rule": "when every 30s then after 15s turn brenner off",
  "active": true,
  "logging": true
}

These rules should set both relay 5 and 6 to the same state but rarely do. I have found a workaround for no more cold showers, which involves avoiding the situation that more than one relay is switched at a time. This workaround is not very good, as many rules depend on sensors are hence are non-deterministic, so I can’t really be sure they prevent the undesireful behavior.

Since relays are a lot slower than anything else that is happening in the processor or memory, I wonder if it is possible to modify rule execution in such a way that it is blocking. I assume that this effect could be prevented, if the switching of a relay is waited for until the new state is confirmed and only then further rules are evaluated. I would like to contribute but am not expert enough neither in Pimatic nor in Coffee for giving it a try.

Could somebody let me know if such blocking behavior is even possible and if so, what would be the right way to go about it? Blocking would mean that rule execution needs to be queued, so that no events are lost. I wonder if this compatible with the current architecture of the rule engine.

BTW, the workaround is as follows: For rules that involve no relay state in the condition, but switch several relays in their action, switch the first relay with no delay, but the second with 4s, the third with 8s and so on. For rules with a relay state in their condition, switch the first relay with a delay of 4s, the second with 8s etc. Hope it works, just only changed my rules.

@bmx Thanks for the detailed test case. I’ll try to repoduce the case based on your findings asap

Could it be related to an insufficient power supply of the UniPi board, especially if there are already some activated relays and the rule switches an additional one. Have you installed the evok web service where you can switch the relays via webinterface independent from pimatic to test it?

@emeins Thanks, yes, I did test that, and I have just tried again. By hitting the switches in the UI of the UniPi Control Panel I have not been able to produce the behavior mentioned above. I rather think it’s not a power but a timing issue.

@mwittig Thank you for looking into that. If there is anything I can do to help, e. g. test any new code, please let me know.

Getting back to this after a long time. As per this answer in the UniPi forum – I must have missed the notification – the reason for the behavior evidently is related to internal state caching in UniPi / EVOK. My final test with the original power supply would not change the odd behavior, so it wasn’t my weal power supply either.

For the record, in case somebody faces the same problem, here is an idea for a workaround. I add a second safety layer, by using a variable that holds the due state of the relay. This variable is operated by Pimatic only and not subjected to any relay measurement or caching issues. If pimatic detects that there has been an error switching the relay, it corrects it. Like so:

    {
      "id": "setter",
      "name": "setter",
      "rule": "when its 17:00 then turn relay-5 on and set $relay5_due_state to 1",
      "active": true,
      "logging": true
    },
    {
      "id": "relay5-checker-on",
      "name": "relay5_checker_on",
      "rule": "when every 5s and relay-5 is off and $relay5_due_state = 1 then turn relay-5 on and log \"Corrected relay5 state to on.\"",
      "active": true,
      "logging": true
    },
    {
      "id": "relay5-checker-off",
      "name": "relay5_checker_off",
      "rule": "when every 5s and relay-5 is on and $relay5_due_state = 0 then turn relay-5 off and log \"Corrected relay5 state to off.\"",
      "active": true,
      "logging": true
    }

Such a set of 2 checker rules is required for every relay on the UniPi. If a relay is switching back, then the rule will force it to its correct position. I have tested it, and it works fine. Only downside: It’s important to set the variable when one actually wants to set the relay. But that can be managed.

I think you could delete one of the checker rules.

What about this:
Make the state a string variable

$relay5_due_state = "on" | "off"

And one checker rule:

when every 5s and $relay-5.state is not $relay5_due_state
    then $relay-5.state = $relay5_due_state and log "corrected relay5 to $relay5_due_state"

I’m not sure whether the relay has a property “state”, but it’s worth a try. Maybe “on” and “off” need to be named “true” and “false”.

Just check the variables page and check how the relay properties are named and filled.

Thanks, I was hoping to be able to put that in just one rule. The case is that $relay-5.state seems to be read-only and so far I fail to set it to a value like in

$relay-5.state = $relay5_due_state

So far, I have found no alternative to

turn relay-5 on

where “on” or “off” apparently may not be replaced by a variable.

Any ideas welcome.

As far as I can see, the PowerSwitch supports changes of the state attribute:
https://github.com/pimatic/pimatic/blob/master/lib/devices.coffee#L350

Maybe @mwittig could clarify this.

@saxnpaule said in Unipi relay switching and then switching back immediately when rule triggers:

As far as I can see, the PowerSwitch supports changes of the state attribute:
https://github.com/pimatic/pimatic/blob/master/lib/devices.coffee#L350
Maybe @mwittig could clarify this.

Correct. Actually, “turn/switch on/off” changes the value of the “state” value of the relay. By design, device state variables (not to be confused with user-defined variables) are always read-only.

Okay, then the only working solution with one rule would be to toggle the relay because it could only have 2 different values (on/off). If the current state is wrong, it could only be the other one

when every 5s and $relay-5.state is not $relay5_due_state
    then toggle $relay-5 and log "corrected relay5 to $relay5_due_state"

Yes, toogle, that’s it! A little more tweaking gave me the following rule, which now does what I need.

    {
      "id": "relay5-checker-single",
      "name": "relay5_checker_single",
      "rule": "when every 5s and [relay-5 is on and $relay5_due_state is \"off\"] or [relay-5 is off and $relay5_due_state is \"on\"] then toggle relay-5 and log \"Corrected relay5 to $relay5_due_state\"",
      "active": true,
      "logging": true
    },
    {
      "id": "relay6-checker-single",
      "name": "relay6_checker_single",
      "rule": "when every 5s and [relay-6 is on and $relay6_due_state is \"off\"] or [relay-6 is off and $relay6_due_state is \"on\"] then after 2s toggle relay-6 and log \"Corrected relay6 to $relay6_due_state\"",
      "active": true,
      "logging": true
    }

AFAIK, relay states are always boolean, while variables may not be boolean, but strings and numbers only, so I changed the expression a bit. I have also put a delay of 2s into the rule for the second relay, so that I don’t run into the Unipi problem all the time. Also, I believe it is useful to initialise the variables on startup with a startup rule, otherwise the variables may be set to “null” and the checker rules won’t trigger.

Thanks a lot for your help!