DEBOUNCE logic seems overly aggressive

[sbrown4]

For example, the 0x05 that reports Armed:Stay gets skipped. As a result, web_keypad never gets updated to show the correct status. Commenting out the DEBOUNCE define restores the expected behavior. Below is debug output. Below that is a keybus trace.

[05:45:05][I][dsc_alarm_panel:760]: Paneldata:  16: 16 00 0E 46 F1 5B 00 00 00 00 00 00 00 00 00 00
[05:45:05][I][dsc_alarm_panel:760]: Paneldata:  A5: A5 00 24 46 A5 B0 BF 00 23 00 00 00 00 00 00 00
[05:45:05][I][dsc_alarm_panel:760]: Paneldata:  75: 75 00 00 75 00 00 00 00 00 00 00 00 00 00 00 00
[05:45:05][I][dsc_alarm_panel:760]: Moduledata: 05: FF 01 FF FF EF FF FF 37 FF FF 01 00 00 00 00 00
[05:45:05][I][dsc_alarm_panel:760]: Paneldata:  39: 39 00 FF FF FF FF FF 00 00 00 00 00 00 00 00 00
[05:45:05][I][dsc_alarm_panel:760]: Moduledata: 39: FF 01 55 55 55 55 44 00 00 00 00 00 00 00 00 00
[07:44:08][I][dsc_alarm_panel:760]: Paneldata:  16: 16 00 0E 46 F1 5B 00 00 00 00 00 00 00 00 00 00
[07:44:08][I][dsc_alarm_panel:760]: Paneldata:  A5: A5 00 24 46 AC B4 BF 00 2E 00 00 00 00 00 00 00
[07:44:08][V][text_sensor:013]: 'event (evt)': Received new state '2024.01.21 12:45 P:1 Armed: Special'
[07:44:08][D][text_sensor:064]: 'event (evt)': Sending state '2024.01.21 12:45 P:1 Armed: Special'
[07:44:08][V][json:038]: Attempting to allocate 512 bytes for JSON serialization
[07:44:08][V][json:058]: Size after shrink 112 bytes
[07:44:08][V][mqtt:474]: Publish(topic='dscalarm/sensor/event__evt_/state' payload='2024.01.21 12:45 P:1 Armed: Special' retain=1)
[07:44:08][I][dsc_alarm_panel:760]: Paneldata:  75: 75 00 00 75 00 00 00 00 00 00 00 00 00 00 00 00
[07:44:08][I][dsc_alarm_panel:760]: Paneldata:  05: 05 00 8A 04 00 C7 00 C7 00 C7 01 00 00 00 00 00
[07:44:08][I][dsc_alarm_panel:1590]: status 04, last status 08, selection 01, partition=1, skip=0, force=0
[07:44:08][I][dsc_alarm_panel:1602]: status 04, last status 08, selection 01, partition=1, skip=0, force=0
[07:44:08][V][text_sensor:013]: 'line1 Partition 1 (ln1_1)': Received new state 'Armed:       '
[07:44:08][D][text_sensor:064]: 'line1 Partition 1 (ln1_1)': Sending state 'Armed:       '

=================================================

304885.97: 00010110 0 00001110 01000110 11110001 01011011 [0x16] Panel version: v4.6 | Zone wiring: NC | Code length: 4 digits | *8 programming: no
304886.03: 10100101 0 00100100 01000110 10100101 10110000 10111111 00000000 00100011 [0xA5] 2024.01.21 05:44 | Partition 1 | Armed: Special
304886.06: 01110101 0 00000000 01110101 [0x75] Partition 1 | Tone: none
304886.16: 00000101 0 10001010 00000100 00000000 11000111 00000000 11000111 00000000 11000111 [0x05] Partition 1: Armed Bypass Backlight - Armed: Stay | Partition 2: disabled | Partition 3: disabled | Partition 4: disabled
304886.16: 11111111 1 11111111 11111111 11101111 11111111 11111111 00110111 11111111 11111111 [Module/0x05] Zone expander notification: 3 4 5 | Keypad notification
304886.22: 00111001 0 11111111 11111111 11111111 11111111 11111111 [0x39] Zone expander query: 3
304886.22: 11111111 1 01010101 01010101 01010101 01010101 01000100 [Module/0x39] Zone expander: 3

[Dilbert66]

Interesting. Since the 05 is sent constantly, the debounce function only ignores the first one of a sequence to elimintate spurious cmds. If what you indicate is the issue, then it would mean that the stay cmd is only sent once. I'll look into it. i have not seen the issue on my end but different firmware versions do behave differently in some cases.

I'll remove the debounce for now until I find a better solution.

[sbrown4]

The panel is a PC1864 V4.60NA Could the debounce logic ignore the first of the sequence and redundantPanelData() ignore the rest?

[Dilbert66]

That's what it's doing. The debounce is ignoring the first and the redundantpaneldata function ignores the rest after the 2nd one is received. This should never be an issue unless your system is only sending 1 valid 05 cmd which would be odd but possible.

[sbrown4]

To me, it looks like debounce ignores the first and redundantPanelData() evaluates TRUE for the 2nd and all subsequent bytes of the sequence. So, the entire sequence gets ignored. I don't see where redundantPanelData() is prompted to return FALSE on the 2nd of the sequence.

[Dilbert66]

I've added some comments to clarify, yes it can be confusing logic. The idea was to minize memory use also as this code resides in limited ISR ram. It's the variable skipData that controls whether a cmd is processed or not.

 static byte previousCmd05[dscReadSize];
      static byte previousCmd1B[dscReadSize]; 

      switch (isrPanelData[0]) {
        case 0x05: pcmd=previousCmd05;break;
        case 0x1B: pcmd=previousCmd1B;break;
     }
      if (pcmd!=NULL) { // if it's a cmd05 or cmd1b pcmd will point to the previouscmd buffer for that cmd
        if (redundantPanelData(pcmd, isrPanelData, isrPanelByteCount)) {
         //if we are here then we are on the second or more of the previous cmd
          if (skipFirst) 
            skipFirst = false; //if we are here then this is the second iteration as skipfirst is set(we have already skipped the first one)
                   //skipdata is false at this point so this cmd does get processed
           else 

              skipData = true; //if skip first is not set (we are on the third or more copy), we skip the cmd
        } 

       else { // we skip the first cmd to remove spurious invalid ones during a changeover. Reported on a pc5005 and pc1832
      //if we are here then this is the first time we see this cmd so we set skipdata=true to skip this one and set skipfirst
          // to flag this as the first cmd
          skipData = true;
          skipFirst = true;
        }  

       }
      }

[Dilbert66]

Do you have a log of arming with debounce active? I'd like to see what those logs look like to compare. It's very odd. On one hand I'm dealing with some panels including mine a pc1832 that does periodically send those bogus 05's and a pc5005 that does the same , and yours that behaves differently. It's very possible that there is only one 05 sent in which case I will definitively need to change the logic or at least add a yaml config to allow control of the feature.

[Dilbert66]

I've added a "debounce: true/false" controllable option to the yaml config so you can turn the feature on or off easily.

[sbrown4]

The logs in my original post are with debounce active. They are from Armed:Stay. I just got another from Armed:Away that I'll send shortly. What's strange is that debounce has no problem with the 0x05 for the 0x3E->0x01 transition nor the 0x08->0x3E. However, Armed:Away similarly fails. The only difference I see is that the failing cases have 0x05 module data and the ones that succeed don't.

[sbrown4]

Here are the outputs for Armed:Away

[14:20:53][D][binary_sensor:036]: 'Partition 1 Ready (rdy_1)': Sending state OFF
[14:20:53][V][json:038]: Attempting to allocate 512 bytes for JSON serialization
[14:20:53][V][json:058]: Size after shrink 96 bytes
[14:20:53][V][mqtt:474]: Publish(topic='dscalarm/binary_sensor/partition_1_ready__rdy_1_/state' payload='OFF' retain=1)
[14:20:53][I][dsc_alarm_panel:785]: Moduledata: 1B: FF 01 FF FF FE FF FF FF FF FF 01 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 2C 01 FF FF 00 00 11 00 00 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  5D: 5D 00 00 00 00 00 00 5D 00 00 00 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 18 01 00 00 00 00 00 FF 00 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  B1: B1 00 FF FF FF FF 00 00 00 00 AD 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  16: 16 00 0E 46 F1 5B 00 00 00 00 00 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  A5: A5 00 24 47 13 7C BF 00 5E 00 00 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 1A 40 00 00 01 00 00 00 41 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  75: 75 00 00 75 00 00 00 00 00 00 00 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Moduledata: 05: FF 01 FF FF EF FF FF 37 FF FF 01 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Paneldata:  39: 39 00 FF FF FF FF FF 00 00 00 00 00 00 00 00 00 
[14:20:53][I][dsc_alarm_panel:785]: Moduledata: 39: FF 01 55 55 55 55 44 00 00 00 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  3E: 3E 00 82 05 00 C7 00 8C 00 00 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 08 FF FF FF FF FF FF 01 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Moduledata: E6: FF 01 FF 54 55 55 55 34 FF 01 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 09 00 EF 00 00 00 00 00 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 0A FF FF FF FF FF FF 01 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Moduledata: E6: FF 01 FF 55 55 05 55 4F FF 01 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 0B 00 F1 00 00 00 00 00 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  1B: 1B 00 00 C7 00 C7 00 C7 00 C7 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Moduledata: 1B: FF 01 FF FF FF FD FF FF FF FF 01 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 25 FF FF FF FF FF 00 00 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Moduledata: E6: FF 01 FF FF FF FF FF FC 00 00 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  5D: 5D 00 00 00 00 00 00 5D 00 00 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  E6: E6 00 18 01 00 00 00 00 00 FF 00 00 00 00 00 00 
[14:20:54][I][dsc_alarm_panel:785]: Paneldata:  EB: EB 00 01 24 07 13 7C 00 BF 00 65 00 00 00 00 00 
[14:20:54][V][text_sensor:013]: 'event (evt)': Received new state '2024.01.24 19:31 P:1 Armed: Special'
[14:20:54][D][text_sensor:064]: 'event (evt)': Sending state '2024.01.24 19:31 P:1 Armed: Special'

=================================================

272081.50: 11111111 1 11111111 11111111 11111110 11111111 11111111 11111111 11111111 11111111 [Module/0x1B] Keypad on partition: 1 going idle
272081.59: 11100110 0 00101100 00000001 11111111 11111111 00000000 00000000 00010001 [0xE6.2C] Partition 1 | Enabled zones 33-64: 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 
272081.66: 01011101 0 00000000 00000000 00000000 00000000 00000000 01011101 [0x5D] Partition 1 | Status lights flashing: none | Zones 1-32 flashing: none
272081.72: 11100110 0 00011000 00000001 00000000 00000000 00000000 00000000 00000000 11111111 [0xE6.18] Partition 1 | Status lights flashing: none | Zones 33-64 flashing: none
272081.81: 10110001 0 11111111 11111111 11111111 11111111 00000000 00000000 00000000 00000000 10101101 [0xB1] Enabled zones 1-32 | Partition 1: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 | Partition 2: none
272081.88: 00010110 0 00001110 01000110 11110001 01011011 [0x16] Panel version: v4.6 | Zone wiring: NC | Code length: 4 digits | *8 programming: no 
272081.94: 10100101 0 00100100 01000111 00010011 01111100 10111111 00000000 01011110 [0xA5] 2024.01.24 19:31 | Partition 1 | Armed: Special
272082.03: 11100110 0 00011010 01000000 00000000 00000000 00000001 00000000 00000000 00000000 01000001 [0xE6.1A] Partitions in alarm: none 
272082.06: 01110101 0 00000000 01110101 [0x75] Partition 1 | Tone: none
272082.13: 00000101 0 10000010 00000101 00000000 11000111 00000000 11000111 00000000 11000111 [0x05] Partition 1: Armed Backlight - Armed: Away | Partition 2: disabled | Partition 3: disabled | Partition 4: disabled
272082.16: 11111111 1 11111111 11111111 11101111 11111111 11111111 00110111 11111111 11111111 [Module/0x05] Zone expander notification: 3 4 5 | Keypad notification 
272082.22: 00111001 0 11111111 11111111 11111111 11111111 11111111 [0x39] Zone expander query: 3
272082.22: 11111111 1 01010101 01010101 01010101 01010101 01000100 [Module/0x39] Zone expander: 3 
272082.28: 00111110 0 10000010 00000101 00000000 11000111 00000000 10001100 [0x3E] Partition 1: Armed Backlight - Armed: Away | Partition 2: disabled | Zones 25-32 open: none 
272082.38: 11100110 0 00001000 11111111 11111111 11111111 11111111 11111111 11111111 [0xE6.08] Zone expander query: 4
272082.38: 11111111 1 11111111 01010100 01010101 01010101 01010101 00110100 11111111 [Module/0xE6.08] Zone expander: 4 | Zones changed: 33 open 
272082.41: 11100110 0 00001001 00000000 11101111 [0xE6.09] Zones 33-40 open: none 
272082.50: 11100110 0 00001010 11111111 11111111 11111111 11111111 11111111 11111111 [0xE6.0A] Zone expander query: 5
272082.53: 11111111 1 11111111 01010101 01010101 00000101 01010101 01001111 11111111 [Module/0xE6.0A] Zone expander: 5 | Zones changed: 47 open 48 open 
272082.56: 11100110 0 00001011 00000000 11110001 [0xE6.0B] Zones 41-48 open: none 
272082.63: 11111111 1 11111111 11111111 11111111 11111101 11111111 11111111 11111111 11111111 [Module/0x1B] Wireless notification 
272082.72: 11100110 0 00100101 11111111 11111111 11111111 11111111 11111111 [0xE6.25] [CRC Error]
272082.72: 11111111 1 11111111 11111111 11111111 11111111 11111111 11111100 [Module/0xE6.25] Unknown data
272082.78: 01011101 0 00000000 00000000 00000000 00000000 00000000 01011101 [0x5D] Partition 1 | Status lights flashing: none | Zones 1-32 flashing: none
272082.88: 11100110 0 00011000 00000001 00000000 00000000 00000000 00000000 00000000 11111111 [0xE6.18] Partition 1 | Status lights flashing: none | Zones 33-64 flashing: none
272082.97: 11101011 0 00000001 00100100 00000111 00010011 01111100 00000000 10111111 00000000 01100101 [0xEB] 2024.01.24 19:31 | Partition 1 | Armed: Special
272083.

[Dilbert66]

Ok, that kinda indicates that my assumption of multiple 05's is not accurate. I need to rethink how to eliminate the bogus cmds that I get without resorting to losing cmds. Just set the debounce: false in your yaml and that will disable it. I've also set it to default off.

[Dilbert66]

Ok, i see the issue on my end. It's more a communications error than anything the panel is doing. The data loses a bit so shifts info over. Unfortunately the 05/1b cmds unlike the others does not use a crc so it's tricky to validate it. I'll dig further into it. The debounce of course would correct that since it made sure that we got two valid cmds before accepting it. Unfortunately that doesnt seem to work on all systems while it corrects the issue on mine.

[Dilbert66]

I found another solution for it. On the bad 05 packets, it loses the final bit on byte 10, so now I look for that and if missing i ignore the cmd altogether. Pushed new version.