Double Triggering?

steve9 · February 18, 2020, 11:02am

I seem to have a situation where double trigger of a rule is occurring for no reason that is obvious to me.

I have multiple devices that I want to use to trigger a rule:-

Front door MAG sensor (Yale Sync Alarm) -> Alexa -> Hubitat Skill -> Virtual Switch (VS) FRONT DOOR OPEN - this sets Global Variable (GV) hall-motion-detected to TRUE.
Motion Sensor 1 (Smart Life) -> IFTTT -> Hubitat -> VS HALL MOTION SWITCH ON - this sets GV hall-motion-detected to TRUE
Aeotec MultiSensor 6 Motion Sensor Active (Zwave Hubitat) - this sets GV hall-motion-detected to TRUE

I then have the following rule:-

Now in the LOG I see this:-

app:1112020-02-18 09:59:05.776 am infoAction:     Set hall-motion-detected to false
app:1112020-02-18 09:59:05.768 am infoAction: IF (Variable hall-motion-detected(true) = true(T) [FALSE]) THEN
dev:752020-02-18 09:59:05.717 am infohall-motion-detected variable is false
app:1112020-02-18 09:59:05.644 am infoAction: Set hall-motion-detected to false
app:1112020-02-18 09:59:05.640 am infoAction: IF (Variable hall-motion-detected(true) = true(T) [TRUE]) THEN
app:1112020-02-18 09:59:05.436 am infoHall Motion Detected Triggered
app:1112020-02-18 09:59:05.359 am infoHall Motion Detected: variable hall-motion-detected set to true by Rule Machine
app:1112020-02-18 09:59:05.306 am infoHall Motion Detected Triggered
app:1112020-02-18 09:59:05.226 am infoHall Motion Detected: variable hall-motion-detected set to true by Hall Motion Switch is ON
dev:752020-02-18 09:59:05.118 am infohall-motion-detected variable is true
app:1092020-02-18 09:59:05.041 am infoAction: Set hall-motion-detected to true
dev:362020-02-18 09:59:05.031 am infoHall Motion Switch was turned off
app:1092020-02-18 09:59:05.020 am infoAction: Off: Hall Motion Switch
app:1092020-02-18 09:59:04.996 am infoHall Motion Switch is ON Triggered
app:1092020-02-18 09:59:04.984 am infoHall Motion Switch is ON: Hall Motion Switch switch on
dev:362020-02-18 09:59:04.842 am infoHall Motion Switch was turned on
app:32020-02-18 09:59:04.831 am debugHall Motion Switch: Executing on()

So, we see variable hall-motion-detected set to true by Hall Motion Switch is ON which is expected, but we see almost immediately afterwards variable hall-motion-detected set to true by Rule Machine

Then we see, interlaced in the LOG, two simultaneous executions of the Hall Motion Detected rule being triggered.

So my question is: why do we see this variable being set twice (once by the Rule Hall Motion Switch is ON then again by Rule Machine?

jwjr · February 18, 2020, 2:21pm

@steve9, I've been seeing this same "set by Rule Machine" thing with one of my rules that sets an RM global variable ("AWAY"). In the logs, it looks like this:

dev:1163 2020-02-17 06:40:52.747 pm info AWAY variable is false
app:764 2020-02-17 06:40:53.390 pm info # - AWAY (from LEFT rule):  variable AWAY set to false by - ARRIVED (from HOME rules)
app:764 2020-02-17 06:40:53.650 pm info # - AWAY (from LEFT rule):  variable AWAY set to false by Rule Machine

Same thing if it's being set TRUE, by a different rule:

dev:1163 2020-02-17 05:46:56.960 pm info AWAY variable is true
app:764 2020-02-17 05:46:57.619 pm info # - AWAY (from LEFT rule):  variable AWAY set to true by - LEFT (from HOME rules)
app:764 2020-02-17 05:46:57.887 pm info # - AWAY (from LEFT rule):  variable AWAY set to true by Rule Machine

Even though the variable is only changing state once, both of these result in a rule triggered by a change in the variable being called twice.

steve9 · February 18, 2020, 6:55pm

That's precisely what is happening in my case. The way the rule is written, it can withstand being called again whilst it is running, but the performance has gone down since I simplified the rules when you'd expect it to have improved. I believe the double triggering is what is causing the performance problem.

Now I can enter via the front door, close the door, take my shoes off and put them in the cupboard, take my coat off and hang it up, walk down the hall and exit by the bottom door and the light is just coming on as I exit. That's no use at all.

ccoupe · February 19, 2020, 11:21pm

Global variables are known to be slow. You are also going to the internet for a couple of devices (IFTTT and likely, alexa) which are also slow. If the goal is to turn on the light when any of three things happen then there are several easier ways to do that. I'd setup a motion zone for the hallway and include your 2 motion sensor and the Virtual Switch. Then create a motion lighting app (both are built in apps) to manage the light. The only hitch is you might need a different Virtual Switch driver that pretends to be a motion sensor too. There's one around here somewhere.

JNS · February 19, 2020, 11:24pm

github.com

ogiewon/Hubitat/blob/master/Drivers/virtual-motion-switch.src/virtual-motion-switch.groovy

/**
 *  Virtual Motion with Switch
 *
 *  https://raw.githubusercontent.com/ogiewon/Hubitat/master/Drivers/virtual-motion-switch.src/virtual-motion-switch.groovy
 *
 *
 *
 *  Copyright 2018 Daniel Ogorchock
 *
 *  Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except
 *  in compliance with the License. You may obtain a copy of the License at:
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 *  Unless required by applicable law or agreed to in writing, software distributed under the License is distributed
 *  on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License
 *  for the specific language governing permissions and limitations under the License.
 *
 *  Change History:
 *

This file has been truncated. show original

steve9 · February 20, 2020, 9:36am

OK Guys - thanks for your very helpful replies. This is what I've done as a result and I'll report back whether it resolves the problem...

Installed the Virtual Motion Switch driver and create a device VS Hall Motion Detected.

Change: Front Door Mag (Yale Sync) -> Alexa -> Hubitat -> VS Hall Motion Detected = ON
Change: Motion Detector (Smart Life) -> IFTTT -> Hubitat -> VS Hall Motion Detected = ON
Rule: Hall Motion Detected...

Trigger Aeotec MultiSensor 6 Motion Detected (Z-Wave) or VS Hall Motion Detected = ON
Trim away conditions and actions no longer needed

So the rule now looks like this...

I know the IFTTT and Alexa links will be slow - can't be helped. Also, the actual switching will be slow too because that is also IFTTT - the controller for the Hall Lights is a Smart Life device and is unfortunately immutable - it's installed, Z-Wave / Zigbee equivalents are too big to fit, and the hall has been redecorated over the top of it - so it's there to stay.

The controller was an interesting choice because, being in the UK, plus how the wires are boxed in within my house, there is no ready access to Neutral or Earth, and also I need the original two-way light switches to play a part too in that if someone switches the lights on manually then the automatic mechanism is to be disabled until someone switches the lights off manually, and then they revert back to automatic. So I had to lay in extra wiring, but couldn't get behind the ceiling so it's on the surface in the smallest possible plastic trunking, then all painted over during the redecoration. The switching unit being small enough to fit into the ceiling rose of one of the two light units.

That's why the logic is not simple: I need to detect manual switching ON/OFF and factor that in, and I also need to assess how much light is in the hallway and not turn the lights on if there's good sunlight lighting it up (which is admittedly rare for our hall).

It was interesting to learn that Global Variables are slow - do you mean that the Hubitat is slow to notice that they have changed and so triggering is slow? Or do you mean that even setting them or testing them is slow too?

I know I should be able to get a 2 second response time because earlier tests showed that, and I'll be happy once I achieve that again.

I could speed it all up by fitting another Aeotec MultiSensor 6, since one can't cover the entire hall because areas get hidden by a central archway, but they are very expensive. So that one is covering entry through the lounge door, and entry through the front door is covered by the MAG sensor on the alarm system. The other Motion Sensor (Smart Life) is experimental - if it works well then I'll keep it, otherwise I'll remove it from the picture.

Incidentally, I would NOT recommend the Smart Life Motion Sensor because it seems to be random as to whether I get a feed from IFTTT for it, so it is unreliable. If I simply use it in the Smart Life app to turn on a Smart Life device then that works OK.

Thanks again - will report back.

jwjr · February 25, 2020, 3:03pm

I'm not seeing a performance issue, and I've rewritten my rules to withstand the double call, but I'm still seeing two separate notifications from the two calls.

Tagging @bravenel on this for (hopefully) an explanation of "set by Rule Machine".

steve9 · February 25, 2020, 3:31pm

Based on advice in this forum, I have changed mine now to be triggered by one real motion sensor and one virtual motion sensor (instead of a virtual switch) and I no longer get the double triggering.

I was advised to use a the built-in Motion Zone App but that didn't really suit my needs because not all of my triggers are real motion sensors and they don't behave like motion sensors - using a Virtual Motion Sensor lets me treat them all as if they were Motion Sensors.

bravenel · February 25, 2020, 4:18pm

Sorry, but I don't know what you're talking about or asking.

jwjr · February 25, 2020, 4:42pm

Sorry! I'm asking about the problem in message 2 in this thread, where a global boolean variable is being set twice - once by rule, as intended, and then a second time about a quarter of a second later, noted in the log as "set to [state] by Rule Machine". Even though the variable only changes state once, any rule triggered by its change is executed twice. Thanks!

bravenel · February 25, 2020, 4:52pm

You would have to show me the rules in question.

jwjr · February 25, 2020, 6:29pm

Here's one:

("LEFT" is another global variable)

bravenel · February 25, 2020, 6:33pm

What is dev:1163? Do you have a connector involved? Also, please use screenshots to show logs, not copy paste.

jwjr · February 25, 2020, 7:06pm

"dev:1163" is the RM connector for "AWAY".

Here's a log screenshot:

"app:872" is the "LEFT" rule from 2 messages ago. "app:764" is my "AWAY" rule that's being triggered twice - in this case, once at 11:59:29.083 by "AWAY variable set to true by - LEFT (from HOME rules)", then again at 11:59:29.177 by "AWAY variable set to true by Rule Machine".

bravenel · February 25, 2020, 9:23pm

Are you on the latest build, 2.1.9?

Also, I need to know which rule is the one you showed above, and which rule you are showing in the logs. There are multiple rules in the logs, so it's not clear what exactly you are referring to. I don't have the context to know what's what.

jwjr · February 26, 2020, 1:29am

I am running "2.1.9.114".

"872" is the rule in message 11 in this thread.

"764" is this rule (which is being triggered twice):

Capture

bravenel · February 26, 2020, 3:56pm

This clearly has something to do with the connector for AWAY. Not sure exactly what yet, but it's "bouncing" due to the connector changing value.

bravenel · February 26, 2020, 6:03pm

OK, Found and fixed this bug. The fix will be in an upcoming hot fix release. Double triggering was caused by an issue with how Boolean GVs were saved in Rule Machine.

jwjr · February 26, 2020, 7:17pm

Awesome, Bruce. Thanks!

bravenel · February 27, 2020, 9:25pm

This bug has been fixed in latest hot fix release for 2.1.9.

This fix involves changing how Boolean GVs are saved, so something needs to change or set the value of any Boolean GV being used as a trigger for the fix to become effective.