Zones showing faulted/restored when door open

[frogger77]

I've decided to abandon SmartThings integration, which had not been working for me for quite some time. I'm now trying to setup HomeAssistant and seeing it reporting as open/closed every few seconds in HomeAssistant.

cap0.PNG (12.4 KiB) Viewed 97108 times

The sensor is an RF 5822T, installed and working for a few years. I saw a note that firmware v8.9 fixed an issue with 5800 sensors, so I updated it about an hour ago. The behavior changed, it seems like it's faulting & restoring faster with v8.9, compared to 8.8.

I am seeing an RF garage door constantly faulting and clearing in the log.

cap2.PNG (68.19 KiB) Viewed 97108 times

cap1.PNG (27.5 KiB) Viewed 97108 times

My settings:

cap3.PNG (75.65 KiB) Viewed 97108 times

[frogger77]

Looking at the interaction below, I'm focusing on zone 6 door, which has been open for hours and falsely reporting as restored whenever other (zone 35/36) zones are restored.

From the log, it appears that I'm getting expander reports right before these false door reports, so I'm thinking there is an interaction here?

exp addr 10, channel 3 = zone 35 (partition 1)
exp addr 10, channel 4 = zone 36 (partition 2)

log from /var/logs/syslog

Code: Select all

May 28 08:43:22 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:22,960] DEBUG in types: Event: Zone <unnamed> (35) has been faulted.
May 28 08:43:23 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:23,008] INFO in types: Event: ZONE:10:3:1
May 28 08:43:23 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:23,337] DEBUG in types: Event: Zone Beam Sensor (36) has been faulted.
May 28 08:43:23 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:23,418] INFO in types: Event: ZONE:10:4:1
May 28 08:43:25 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:25,271] DEBUG in types: Event: Zone <unnamed> (35) has been restored.
May 28 08:43:25 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:25,324] INFO in types: Event: ZONE:10:3:0
May 28 08:43:25 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:25,492] DEBUG in types: Event: Zone Kitchen Garage Door (6) has been restored.
May 28 08:43:25 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:25,639] DEBUG in types: Event: Zone Beam Sensor (36) has been restored.
May 28 08:43:25 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:25,692] INFO in types: Event: ZONE:10:4:0
May 28 08:43:29 AlarmDecoder gunicorn[505]: [2020-05-28 08:43:29,467] DEBUG in types: Event: Zone Kitchen Garage Door (6) has been faulted.
May 28 08:44:17 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:17,731] DEBUG in types: Event: Zone <unnamed> (35) has been faulted.
May 28 08:44:17 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:17,779] INFO in types: Event: ZONE:10:3:1
May 28 08:44:18 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:18,101] DEBUG in types: Event: Zone Beam Sensor (36) has been faulted.
May 28 08:44:18 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:18,149] INFO in types: Event: ZONE:10:4:1
May 28 08:44:19 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:19,718] DEBUG in types: Event: Zone <unnamed> (35) has been restored.
May 28 08:44:19 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:19,773] INFO in types: Event: ZONE:10:3:0
May 28 08:44:19 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:19,943] DEBUG in types: Event: Zone Kitchen Garage Door (6) has been restored.
May 28 08:44:20 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:20,091] DEBUG in types: Event: Zone Beam Sensor (36) has been restored.
May 28 08:44:20 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:20,139] INFO in types: Event: ZONE:10:4:0
May 28 08:44:23 AlarmDecoder gunicorn[505]: [2020-05-28 08:44:23,909] DEBUG in types: Event: Zone Kitchen Garage Door (6) has been faulted.

[frogger77]

Is there any way to log the full communications between alarmdecoder and the bus?

I turned on more debug and I'm seeing a similar interaction with Zone 39 (expander 10, channel 7)

Capture.PNG (113.87 KiB) Viewed 96896 times

[frogger77]

Is it possible that the AlarmDecoder will see restore messages from partition 2 ("2 DISARMED Ready to Arm ") and assume that zones in partition 1 are also restored? I masked out my non-keypad devices (Envisalink & cellular communicator) which seems to help. But I'm still getting the random restore on multiple doors from time to time, not sure what's triggering that.

[frogger77]

I installed Wireshark on the Raspberry Pi and was able to log the raw USB packets around the instance in which the device reported zone 7 as restored. It appears to be a lapse in zone fault reporting that is either being missed by the device or the panel is not sending.

Logging telnet shows the same thing. Is it possible I have too many zones and packets are being dropped on the bus or is the microcontroller struggling to keep up?

[frogger77]

I put the Wireshark on the Envisalink (I have both on same panel), it's showing the same lapse in fault reporting, so the issue is my alarm bus is getting too crowded. Too many zones I guess.

When the zone actually closes, the EVL-3 doesn't report the RESTORE as fast as the AlarmDecoder, so perhaps all I need to do is add some hysteresis to the state logic. It can take upwards of 20-30 seconds for the EVL-3 to report a zone closed, but having closing state latency would be better than a false trigger.

[jjlawren]

I noticed this behavior in Home Assistant after upgrading to 2.2a.8.9b-306. I reverted back to 2.2a.8.8 and the fault/restore behavior continued. Once I restarted HA the proper behavior returned. Any chance this could be related to restarting the AD device during runtime which causes an issue downstream in HA?

[frogger77]

From what I observed, the messages are being dropped from the alarm bus.

I think it's just the design of the bus from Ademco, when zones are restored, its happy and waiting for faults, when many zones are faulted, you might not see them all until they are restored. If the bus is crowded with many fault messages, not really an issue for an alarm panel. But for HA (not a use case that Ademco considered) it can be an issue.

[jjlawren]

There's some more discussion around the issues as observed in Home Assistant here: https://github.com/home-assistant/core/issues/36298.