[BUG] ET Groups - false positive when detecting device change

[Ltek]

spud and PSA for all HS3 users (not sure if it happens in HS4)...

I'm seeing frequent (once a day or so) false positives where ET thinks a device (used in an ET Group) has changed -- but it has not.

I have reproduced this with multiple ET groups, using completely different devices : Ademco devices from spud plugin and MyQ devices from Eric Fetty's plugin

On 7/14 I converted Ademco events back to require using my Composite Devices (not ET Groups) and the Events work properly again - and have for 2 weeks. While the Events using ET Groups still have false positives.


Note: All devices used for these event I tried this setting both On (my default usage) and Off; "Do not update device last change time if device value does not change"

Ademco plugin:
-- I converted about 10 Events that use devices ONLY from Spud's Ademco plugin. I moved them from using my own Composite Devices script (vDevice to represent a group) over to EasyTrigger (because Spud put in the nice feature of being able to identify which device triggered the change)

-- After trying Event logic using several variations (has changed, been in range for exactly, etc) over 3 weeks they showed the same bug ... ET detects a change when HS3 says there is not.

-- For instance, when ET detected my Deck Door opened on 7/14/2021 7:15:25 AM; yet HS3 says the physical device had not changed in over 2 days: 7/11/2021 7:58:13 PM

--
Eric Fetty's MyQ plugin (Garage Doors): <<screenshots from today>>

-- note the Event triggers on both garage doors yet one has not changed / opened for several days!

[spud]

Could you try to set the log level to Debug for EasyTrigger until the problem appears? That way we could see what device changes the plugin sees

"Device X value updated from Y to Z"

and as a result what event is fired

"Firing event X"

[Ltek]

spud
OK, found the debug entries...

Jul-31 8:01:36 AM

EasyTrigger

DEBUG Device 5333 value changed from 5 to 3

Jul-31 8:01:25 AM

EasyTrigger

DEBUG Device 5333 value changed from 3 to 5

I'm not sure what makes the devices go offline for a few seconds every once and a while. But this happened with your Ademco plugin too.
I dont understand why the HS3 devices 'Last Change' is not recording these changes but ET sees the change (with both MyQ and Ademco devices)?

[Ltek]

spud
Please look into this bug. Its a huge issue I'm surprised others have not reported. I had to stop using ET Groups in about 20 events because they ALL trigger false positives when the devices in the group come from your Ademco plugin or the MyQ plugin

I think what is happening is the plug-ins are refreshing the status of the HS devices quickly... Homeseer does NOT detect an actual change (as you can see by the time stamp on the HS devices) but somehow EasyTrigger is detecting a change.

[spud]

Could you set the log level to Debug for the EnvisaLink Ademco plugin, and see if the plugin reports an actual change when the problem happens?

If the EnvisaLink Plugin reports an actual change, even if it just last for a few seconds, then the problem is the Last Change Time value that does not update.

If the EnvisaLink plugin does not report any actual change, then the problem is HS reporting a false device value change event to ET.

In both cases it's not really an EasyTrigger issue.

[avpman]

Similar issue here. I have a group of devices for the battery level of all of my door locks. The locks are polled every 24hours. I have an event that checks if any of the batteries in the locks is less than 50% and if so it sends me a text. Some days I'll get a multitude (over 10) texts alerting me. Yet none of the batteries dropped below the 50% level. I finally had to disable the event because of all of the false triggers.

[Ltek]

spud is there a way to do Debug logging to a file instead of to the HS3 log? I have a ton of ET Events and Groups, its impossible to navigate other stuff in the log.

Also, since the HS3 MyQ event is dead, I cannot use that to troubleshoot so I'll use your Ademco Plugin (which is set to Debug to a file).

Thx!

[spud]

I will add the possibility to log to a file in EasyTrigger.

[Ltek]

spud After a few days of this issue repeating I've done some looking and have files for you. I think you have a bugs in, at least...

"Any device in group DoorLocks was set and has a value that is not equal to"
and
"Any device in group DoorsAll was set and has a value that is less than"

I've changed them all to 'not equal to' so there is no variation, and I see this happening with all of them when ran manually with "conditions are true" and when they are the only trigger also.


Situation:

I have 2 events, they each only have a single trigger, no conditions...

(1) IF Any device in group Windows has its value changed

... works correctly.
... did not trigger all day after 9:22am, when I did close the window. The log shows: "Ademco Window Value Changed", correctly

(2) IF Any device in group Windows was set and has a value that is not equal to 0

... triggers falsely.
... at 8:15 PM, ET triggered this event. The Ademco log at/around 8:15 pm, does not log any window value being changed. This is correct since no windows anywhere were open.


I opened that window at 8:28 PM, and the PI correctly logged...

Sep-05 8:28:35 PM EnvisaLinkAdemco INFO Den Window Right status change: Opened


Hoping the attached logs help you identify the problem:
All from the HS3 event log... ET Debug setting, Ademco PI, Events in that time range
plus, Ademco debug file at this link (4mb zip of text)... https://easyupload.io/waw03x


Also...
ET falsely triggers two other event anytime they are ran manually with "If the event conditions are True".

(a) these two devices in that group have not changed in almost a week -- that plugin was disabled, thus the devices cannot change. They are always set to value 3.

IF Any device in group GarageDoors was set and has a value that is not equal to 3

(b) theser devices have not changed in over an hour, they have been equal to 255 the whole time.

IF Any device in group DoorLocks was set and has a value that is not equal to 255

[spud]

In Log_ET.txt at 8:15 PM, there is no "Firing event" entry, so it doesn't look like it's ET that is firing this event. Are you sure it's not triggered by something else, like for example Google/Alexa? I see you have voice command for this event.

[Ltek]

In Log_ET.txt at 8:15 PM, there is no "Firing event" entry, so it doesn't look like it's ET that is firing this event. Are you sure it's not triggered by something else, like for example Google/Alexa? I see you have voice command for this event.

Positive its ET triggering it. While we have Voice in there, its 90% unreliable so we never use it.
This is the same issue as the other events that also run when they should not... For instance, the attached screenshot ET triggers this event which the group has only two MyQ devices. That PI is disabled so that values have been 3 for a week since I disabled that PI. So how did that event run at 10:30pm last night when the 2nd screenshot show the event that tells it to run only if the conditions are true? I had to changed those events to use my custom script that creates 'Composite Devices'. If you have a way to identify this more LMK. Maybe the way your PI pulls info from HS is showing a bug in HS... but my script reads the HS devices values 1 at a time, and its been 100% accurate (with a slight delay of a second or so course)

[zwolfpack]

The event shown in post #1 doesn't have any conditions (AND IF), only a trigger (IF). Is this the event you're talking about?

If you're calling this from another event, with "if conditions are True" set, it will always trigger, since there aren't any conditions.

[Ltek]

The event shown in post #1 doesn't have any conditions (AND IF), only a trigger (IF). Is this the event you're talking about?

If you're calling this from another event, with "if conditions are True" set, it will always trigger, since there aren't any conditions.

So a Trigger is not a Condition? While I believe it, that is just stupid. But seems like a Homeseer thing to do. A trigger should always be considered a Condition... its just the first and most important.

[zwolfpack]

While HomeSeer has plenty of stupid, I don't think this qualifies as that. A trigger represents a moment in time. If for example a time trigger was considered when calling from another event, it would almost never fire, unless the times lined up exactly.

I have a several events where the "trigger" is repeated as a "condition", just so that it can be called from another event. For example, the "main" trigger for some lighting is derived from the ambient light level, but its not allowed to run if the alarm system is armed. So when the alarm becomes disarmed, this event gets called from another event, and it runs if the lighting condition is satisfied.

[Ltek]

zwolfpack thank you for pointing that out. And, apologies for calling it "stupid", I may have stated that incorrectly. More correctly would be... "its not smart, it not efficient, and its not necessary." ;-)

If the Trigger was considered a Condition it would allow what I thought we could do... have a single event (like my Garage event screenshot above) work as both a point-in-time, manually ran to "check" things, and allow it to be an always-watching triggering event. But instead, like the screenshot of my Windows event posted here, I must add 2 more lines that do and mean exactly the same thing.

I should not be surprised by any of this.


spud

The way Homeseer is doing this make it no way when the event is manually ran to update the ET Global Variables to be accurate. They will always reflect the past unless we create a separate set of events to force the ET Globals to be updated -- not sure if that will even work properly. Plus, hope there is not a race condition or force a wait time to ensure there is not one.

Otherwise, the ET Global will show the previous / last change... which is exactly what I'm seeing; the incorrect data -- which I thought was the bug.

For instance, right now my _Windows global shows an open window that has not been open for 6 hours. Clearly this is a result of HS event running but not forcing the ET Global to be refreshed.

since I we cant force a manual ET Global refresh -- there is no value, or accuracy, to use ET Global in manually triggered events.

Maybe having 'ET global variables suffix' added to Conditions would help (force a refresh) ? ** feature request I asked for just last week ;-)