DSC Unlocker possible bug?

[BigHomie90]

I tried to unlock my DSC PC1616 alarm panel using DSC unlocker sketch 1.1 for esp8266 (expander version).
The sketch found the right code but i noticed that serial monitor didnt showed any message when it found the code. It just stopped. I have uploaded 3 videos on youtube to show you because i am a newbie on these things and i couldnt find a way to extract the serial window log to a text format. Maybe someone can help on how to do that. i can try whatever you want in order to track down the issue or other tests based on your code cause i have this alarm on my desk for testing purposes until i install it in my house sometime.
*Sorry for my English, it's not my native language.

https://youtu.be/B4cX34NHV1c
https://youtu.be/K_oLngPO0Ok
https://youtu.be/x9F-yK4ViuY

[kricon]

i couldnt find a way to extract the serial window log to a text format. Maybe someone can help on how to do that.

Just select all code (crtl+a) or lines you want and copy it (crtl+c) then paste it where you want. If its whole log, I suggest you to paste it on www.pastebin.com, but if its just a small portion of log you can paste it here, select it and press "insert code" <> icon for better formatting. I hope you got it.

When keypad is stuck (with programming mode icon), and unresponsive, can you try to disconnect NodeMCU from keybus? Maybe that will make panel and keypad alive again (to verify it is not related but the panel hang by itself).
Are you sure that keypad isnt in keypad lockout mode when it is stuck unresponsive? I remember when I powered one panel it was in keypad-lockout mode and armed, I tried to wait 2 hours but nothing so I just reset to default settings (it wasnt installed-locked out) but keypad was giving long beeps.

For help tracing a bug, I'll have PC1616 v4.5 available in week or so, and I can help verify if its related only to PC1616.

[BigHomie90]

Hello @kricon and thanks for replying! I was sure that i tried crtl+c before and it didnt catch the log but anyways i did it again and now it copied the log.
I run the DSC Unlocker 1.1 Esp8266 sketch 2 times with the default installer code "5555".
Here are the logs.
*Keypad lockout is disabled after the first time the sketch found the code and did a reset on the alarm panel.
The first log is perfect. It found the code, it shows the installer code text , the led on nodemcu blinks according to the code and keypad returned to normal mode.

11:54:18.473 -> DSC Keybus Interface is online. 11:54:19.359 -> 1s | Test position: 0 | Test code: 1000 11:54:22.472 -> 4s | Test position: 1 | Test code: 1182 11:54:25.500 -> 7s | Test position: 2 | Test code: 1212 11:54:28.427 -> 10s | Test position: 3 | Test code: 1234 11:54:31.402 -> 13s | Test position: 4 | Test code: 1500 11:54:34.478 -> 16s | Test position: 5 | Test code: 1550 11:54:37.485 -> 19s | Test position: 6 | Test code: 1555 11:54:40.419 -> 22s | Test position: 7 | Test code: 1626 11:54:43.389 -> 25s | Test position: 8 | Test code: 1676 11:54:46.374 -> 28s | Test position: 9 | Test code: 1984 11:54:49.514 -> 31s | Test position: 10 | Test code: 2500 11:54:52.405 -> 34s | Test position: 11 | Test code: 2525 11:54:55.383 -> 37s | Test position: 12 | Test code: 2530 11:54:58.466 -> 40s | Test position: 13 | Test code: 3000 11:55:01.489 -> 43s | Test position: 14 | Test code: 3101 11:55:04.416 -> 46s | Test position: 15 | Test code: 4010 11:55:07.398 -> 48s | Test position: 16 | Test code: 4020 11:55:10.378 -> 51s | Test position: 17 | Test code: 4112 11:55:13.479 -> 55s | Test position: 18 | Test code: 5010 11:55:16.404 -> 58s | Test position: 19 | Test code: 5020 11:55:19.385 -> 60s | Test position: 20 | Test code: 5050 11:55:22.356 -> 63s | Test position: 21 | Test code: 5150 11:55:25.466 -> 67s | Test position: 22 | Test code: 5555 11:55:27.930 -> 69s | Installer code: 5555
The second time i tried after restart nodemcu and alarm panel the issue happened again when it found the code.
Alarm keypad being unresponsive even i remove nodemcu from the alarm panel.

11:57:09.249 -> DSC Keybus Interface is online. 11:57:10.185 -> 1s | Test position: 0 | Test code: 1000 11:57:13.368 -> 4s | Test position: 1 | Test code: 1182 11:57:16.343 -> 7s | Test position: 2 | Test code: 1212 11:57:19.311 -> 10s | Test position: 3 | Test code: 1234 11:57:22.329 -> 13s | Test position: 4 | Test code: 1500 11:57:25.404 -> 16s | Test position: 5 | Test code: 1550 11:57:28.275 -> 19s | Test position: 6 | Test code: 1555 11:57:31.344 -> 22s | Test position: 7 | Test code: 1626 11:57:34.362 -> 25s | Test position: 8 | Test code: 1676 11:57:37.387 -> 28s | Test position: 9 | Test code: 1984 11:57:40.302 -> 31s | Test position: 10 | Test code: 2500 11:57:43.317 -> 34s | Test position: 11 | Test code: 2525 11:57:46.295 -> 37s | Test position: 12 | Test code: 2530 11:57:49.446 -> 40s | Test position: 13 | Test code: 3000 11:57:52.333 -> 43s | Test position: 14 | Test code: 3101 11:57:55.306 -> 46s | Test position: 15 | Test code: 4010 11:57:58.317 -> 49s | Test position: 16 | Test code: 4020 11:58:01.394 -> 52s | Test position: 17 | Test code: 4112 11:58:04.270 -> 55s | Test position: 18 | Test code: 5010 11:58:07.291 -> 58s | Test position: 19 | Test code: 5020 11:58:10.265 -> 61s | Test position: 20 | Test code: 5050 11:58:13.425 -> 64s | Test position: 21 | Test code: 5150 11:58:16.311 -> 67s | Test position: 22 | Test code: 5555
#When i upload the sketch to node mcu "Low memory available, stability problems may occur."

Executable segment sizes:
IROM : 243540 - code in flash (default or ICACHE_FLASH_ATTR)
IRAM : 30808 / 32768 - code in IRAM (ICACHE_RAM_ATTR, ISRs...)
DATA : 1256 ) - initialized variables (global, static) in RAM/HEAP
RODATA : 40900 ) / 81920 - constants (global, static) in RAM/HEAP
BSS : 26952 ) - zeroed variables (global, static) in RAM/HEAP
Sketch uses 316504 bytes (30%) of program storage space. Maximum is 1044464 bytes.
Global variables use 69108 bytes (84%) of dynamic memory, leaving 12812 bytes for local variables. Maximum is 81920 bytes.
Low memory available, stability problems may occur.
esptool.py v2.8
Serial port COM3
Connecting....
Chip is ESP8266EX
Features: WiFi
Crystal is 26MHz
MAC: ec:fa:bc:5f:96:aa
Uploading stub...
Running stub...
Stub running...
Configuring flash size...
Auto-detected Flash size: 4MB
Erasing flash (this may take a while)...
Chip erase completed successfully in 9.0s
Compressed 320656 bytes to 224858...
Wrote 320656 bytes (224858 compressed) at 0x00000000 in 19.9 seconds (effective 128.9 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...

Sometimes i have to unplug and plug usb (nodemcu) multiple times for the serial monitor to start capturing data. Meanwhile if serial monitor is blank, hardwired keypad shows that another keypad is accessing the system with the symbol of the "finger and keypad". (Double checked that COM3 is selected from arduino and pc assigns the same COM port on every reconnect).

After the second attempt physical keypad still "frozen with the symbol of installer access" 10 minutes now and node mcu completely disconnected.

[kricon]

I dont know if this problem is related to "low memory available, stability problems may occur", I didnt used unlocker sketch before (so I dont know if its normal message) but I will try it soon on PC1832 v4.2 I have available and ready for testing. I have 3rd party NodeMCU and Wemos D1 mini clones if that matters anything.

I saw you have two NodeMCUs. Is it possible that you put Unlocker sketch on one and KeybusReader on another? I wonder why panel and keypad froze even after NodeMCU disconnected, so maybe KeybusReader can give a hint where it hang up (maybe panel left in *8 programming?). Same COM port is assigned if using same USB port, if you change USB port - so will COM port change, atleast for me. Of course, you will need to have two serial monitors open for different arduino com ports (as you will have two nodeMCUs connected via usb to pc) - it should work by running multiple Arduino IDE instances, if it doesnt work that way you can use Putty program for multiple serial monitoring.

Its just my two cents, but thats what I would do first. Maybe wait for another opinion, if running multiple NodeMCUs is not convinient for you.

[BigHomie90]

@kricon I tried what you suggested and have the logs. One node mcu running the Unlocker Sketch and the other one Keybus Reader. I want to upload them on paste bin. Wich language do i select for correct code format? I choose none just to upload them now. If you want i can edit them. The physical keypad stuck again even if i remove the nodemcu that runs the unlocker. Also the led was not blinking. In a previous attempt The Unlocker found the code and show it in the Serial monitor and the led was blinking, but the keybus reader sketch didn't show any logs on the serial monitor.. As i said before, sometimes i have to restart the alarm panel and replugging the usb on the node mcu for the serial monitor to start showing activity.

https://pastebin.com/4JHmFAXt
https://pastebin.com/3VdW7F4g

[taligentx]

Hi @BigHomie90 - thanks for the logs while running both NodeMCUs, the output is showing some interesting behavior. Which branch are you using, develop or expander? The expander branch is more experimental at this point, develop is more tested for now.

The sketch starts entering test code 3000 and at 40.87 the sketch should be writing the 0 key, but for some reason the entire keypad data line is held low for all bits after the first byte (normally, entering a key only changes 1 byte as seen when 0 is written at 40.79). This continues for a full second until 41.88 when another 0 key is written successfully:

16:41:10.487 ->    40.63: 00000101 0 10000000 10110111 00010000 11000111 00010000 11000111 00010000 11000111 [0x05] Partition 1: Backlight - Enter installer code | Partition 2: disabled | Partition 3: disabled | Partition 4: disabled
16:41:10.534 ->    40.71: 11111111 1 00001111 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x05] Partition 1 Key: 3
16:41:10.627 ->    40.79: 11111111 1 00000000 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x05] Partition 1 Key: 0
16:41:10.720 ->    40.87: 11111111 1 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [Module/0x05] Partition 1 Key: 0Zone expander notification: Slot 8 9 10 11 12 13 14 16 | Wireless module battery notification| Unknown module notification| Keypad zone status notification
16:41:10.720 ->    40.89: 00101000 1 [0x28] Zone expander slot 9 query
16:41:10.720 ->    40.89: 00000000 1 [Module/0x28] Zone expander status update: Slot 9 
(...)
16:41:11.655 ->    41.79: 00000000 1 [Module/0x05] Partition 1 Key: 0Zone expander notification: Slot 8 9 10 11 | Wireless module battery notification| Unknown module notification| Keypad zone status notification
16:41:11.655 ->    41.81: 00000111 1 [Module/0x05] Partition 1 Key: 0Zone expander notification: Slot 8 9 10 11 | Wireless module battery notification| Unknown module notification| Keypad zone status notification
16:41:11.702 ->    41.88: 11111111 1 00000000 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x05] Partition 1 Key: 0

I don't have access to a panel for a while longer so it'll be some time before I can try to replicate this.

There's also a problem when the sketch gets the right code and enters installer programming - to make sure the panel is actually in installer programming, the sketch enters 000 to get into a programming section. The sketch should only write keys during a 0x05 command, but at 71.28, it writes the 0 keys during 0xEB and 0x0A commands - which shouldn't be happening:

16:41:41.042 ->    71.19: 00000101 0 10000010 11100100 00010000 11000111 00010000 11000111 00010000 11000111 [0x05] Partition 1: Armed Backlight - Installer programming | Partition 2: disabled | Partition 3: disabled | Partition 4: disabled
16:41:41.136 ->    71.28: 11101011 0 00000000 00100000 00101100 11000000 00001000 00000001 10101101 00000000 10101101 [0xEB] 2020.11.06 00:02 | Enter installer programming
16:41:41.136 ->    71.28: 11111111 1 00000000 11111111 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0xEB] Unknown data
16:41:41.183 ->    71.36: 11111111 1 00000000 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x0A] Unknown data
16:41:41.277 ->    71.44: 11111111 1 00000000 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x0A] Unknown data
16:41:43.146 ->    73.31: 00010001 0 10101010 10101010 10101010 10101010 10101010 10101010 10101010 [0x11] Module supervision query
16:41:47.238 ->    77.39: 00010001 0 10101010 10101010 10101010 10101010 10101010 10101010 10101010 [0x11] Module supervision query
(...)

The incorrect writes seem to be triggering the panel to send out0x11 queries every 4 seconds, and it's waiting for a response from some module to the query, which explains why the panel is not responsive even when you disconnect the NodeMCU - the panel will probably keep waiting forever for a nonexistent module to respond. You also can't use physical keypads to get out of this mode because only the physical keypad that entered the installer code will be responsive, all other keypads disable themselves when they see the panel go into installer programming due to input on some other keypad.

Let's see which code branch this is happening on and take it from there.

I dont know if this problem is related to "low memory available, stability problems may occur", I didnt used unlocker sketch before (so I dont know if its normal message)

For Unlocker, this is normal as the table of installer codes eats up memory, but there's plenty leftover for the sketch to operate normally (over 12kB of RAM left on the esp8266, the sketch runs fine on Arduino with 2kB of RAM).

Edit: typo

[BigHomie90]

You re welcome, it's the least I can do! I used the expander version unlocking sketch. I will do more tests if you like using the developer unlocking sketch but we have to w8 for a week because I ordered a new board pc1616. The last one "died" for unknown reason. (Relay clicking loop).

[kricon]

I've tested the unlocker sketch from same branch (expander), on PC1616 v4.50EU (installer code changed, default programming, without lockout) and at first run it overpast the correct installer code without stopping, then it found "non-programming *8 code" which wasnt even working (would NOT even enter *8 programming), I continue the search and leave it until morning - it said "All codes tested, no result". Then I tried running the sketch again, and it found correct code and stopped just like author said - without saying which is installer code. Keypad was reponsive, so it wasnt stuck in *8 menu.
I do not know if this issue is related to PC1616, this is my first time using the sketch. It cant be coincidence that 3 pc1616 panels the have same issue, I will test it more and with another panels.

[BigHomie90]

I think it's a hit or miss.. I obviously don't know the reason but after some tests with the unlocker i see 2 different results.

1. Unlocker finds the code but it don't show it on serial monitor. It just stops at the last entered code. (Physical keypad sometimes stuck)
2. Unlocker finds the code, shows it up on serial monitor as it should and physical keypad is working fine (working perfectly)
   @kricon till now it didn't happened to me ( overpass installer code or found a non programming code) . I will run the sketch more times and change installer code to see if this happens to me also.

[kricon]

Same thing is happening on PC1832 V4.24EU, installer code 5555. So its not PC1616 related issue. Unlocker sketch from expander branch did find correct installer code and halted showing last entered code. Keypads was not available. Tested two times in row.
Then I have tried unlocker sketch from development branch and two times in row everything work as it should (found installer code as it should and blink the led), but third time it just go past the installer code again.
Its a little hard to test multiple times as I also need to reconnect USB several times before it start outputing into serial monitor, but usually closing the serial monitor several times and reopening helps.

It seems that problem with incorrectly displaying installer code is somewhere between expander and development branch. Development branch seems to work stable, didnt had problem with keypad stuck and not displaying installer code as it should, tested a dozen times but both development and expander branch seems to miss correct installer code few times each (even tried on PC5020), which is not good thing as I can waste hours/days finding correct code which can be sometimes found in like few minutes. I still use few resistors soldered in series instead of one 33k, maybe that could be the problem, I got 33k resistors so I will replace that soon and also prepare another ESP8266 board for keybusreader.

I found out that if I pause the sketch and activate the keyboard, after I continue the sketch I can see "Enter your installer code" and "Invalid access code" messages. Sometimes when it test the correct installer code panel seems to send "Invalid access code" and thats why sketch ignores it and continue on. But most of the time it works as it should, and sketch open section 000 and then leave with saying which is correct installer code.

[Dilbert66]

Not all panels behave the same when entering programming mode. My panel a dsc832 (5010) does not send or at least the library is not showing any 0x05 cmds after a valid *8 cmd
I see 0x0a's and 0xE6's mostly. Also the status does not change to 0xf8 after sending 000, it remains at 0xe4. I duplicated the issue above. Once I changed the lines below, it worked as it should. The issue is that the script goes into an infinite loop waiting for a command that will not come and thus locks up the keypad.

line 649:
form this:
while (dsc.panelData[0] != 0x05 && dsc.panelData[0] != 0x7F) {
to this:
while (dsc.panelData[0] != 0x05 && dsc.panelData[0] != 0x7F && dsc.panelData[0] != 0xE6) {

line 663:
from this:
else if (dsc.status[0] == 0xF8 ) {
to this:
else if (dsc.status[0] == 0xF8 || dsc.status[0] == 0xE4 ) {

[Dilbert66]

taligentx, that issue with the codes being sent on the wrong cmds, I did see that before when i was testing and by mistake had an expander board on the same channel id as an existing device. The conflict caused odd behavior. I have new changes to provide to the expander code base for memory optimizations. The ESPhome library uses a lot of IRAM and I found ram is very tight now with the new versions of the library.. I was able to recover about 300 bytes of iram memory by optimizing ISR functions.
I think I suspect one issue. It's most likely a conflict with the keypad and pending device event pending flags. I'll add a check to ensure that keypad events have priority.

edit:
I havent done much testing but this change I added might be the issue. I was forcing device events to have priority.
Removing the !writeModulePending in the dscclockinterrupt function will revert to original behavior of keypad events having priority
from:
else if (!writeModulePending && writeKeyPending && !wroteAsterisk && isrPanelByteCount == writeByte && writeCmd) {
to:
else if ( writeKeyPending && !wroteAsterisk && isrPanelByteCount == writeByte && writeCmd) {

[Dilbert66]

Ok, I had a better look at the code. From what i see, the reason for the 0x05 command not always being seen correctly as the responded to command for modules is that the redundancy logic is not copying the redundant command into paneldata on every iteration. The only true indicator of the last command is the private variable currentCmd. Changing currentCmd ti a public variable you can then use dsc.currentCmd to check instead of using paneldata[0].

As to why the 0x11 keeps trying to get status in the log above, that is another issue somewhere where the 0x05 response got zeros in all slots. I seen this once a while ago but have not seen it since so can't duplicate it.

[kricon]

I've been trying for hours to replicate issue I had that will overpass correct installer code but without succes. Until I tried to enter *8, input first digit and then connect ESP8266 with unlocker sketch on it. Voila! That was it:

03:25:55.523 ->  4180.42: 00000101 0 10000000 10001111 00010000 11000111 00010000 11000111 10010001 00000001 [0x05] Partition 1: Backlight - Invalid access code | Partition 2: disabled | Partition 3: disabled | Partition 4: Ready Trouble Backlight - Partition ready
03:25:55.557 ->  4180.43: 11111111 1 00000000 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x05] Partition 1 Key: 0 Unknown data
03:25:55.730 ->  4180.60: 00101101 0 10000000 10001111 00010000 11000111 00000000 00010011 [0x2D] Partition 1: Backlight - Invalid access code | Partition 2: disabled | Zones 9-16 open: none
03:25:58.249 ->  4183.13: 00000101 0 10000000 10110111 00010000 11000111 00010000 11000111 10010001 00000001 [0x05] Partition 1: Backlight - Enter installer code | Partition 2: disabled | Partition 3: disabled | Partition 4: Ready Trouble Backlight - Partition ready
03:25:58.457 ->  4183.33: 11111111 1 00010110 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x05] Partition 1 Key: 5 Unknown data
03:25:58.630 ->  4183.53: 11111111 1 00010110 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x05] Partition 1 Key: 5 Unknown data
03:25:58.836 ->  4183.72: 11111111 1 00010110 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x05] Partition 1 Key: 5 Unknown data
03:25:58.870 ->  4183.76: 01111111 0 00000001 10000000 [0x7F] Partition 1 | Buzzer: 1s
03:25:59.077 ->  4183.96: 00000101 0 10000000 10001111 00010000 11000111 00010000 11000111 10010001 00000001 [0x05] Partition 1: Backlight - Invalid access code | Partition 2: disabled | Partition 3: disabled | Partition 4: Ready Trouble Backlight - Partition ready
03:25:59.111 ->  4183.98: 11111111 1 00010110 11111111 11111111 11111111 11111111 11111111 11111111 11111111 [Module/0x05] Partition 1 Key: 5 Unknown data
03:26:01.939 ->  4186.82: 00000101 0 10000000 10110111 00010000 11000111 00010000 11000111 10010001 00000001 [0x05] Partition 1: Backlight - Enter installer code | Partition 2: disabled | Partition 3: disabled | Partition 4: Ready Trouble Backlight - Partition ready

Im sure this can be fixed and make "idiot-proof". Im not certain how I manage to screw up on this at first as I dont remember trying to enter some digits before connecting ESP8266 onto keybus days ago when I reported that bug. But I do remember some times I was entering *8 and pressing # to awake keypad. However, this was only case when I was able to reproduce the same bug so it has to be it - or something close related to it.

And I must note that unlocker sketch from expander branch doesnt work on PC5020 panel, it doesnt even start at all, not sure why (probably what @Dilbert66 said and discover in posts above) and for new PC1616/1832/1864 series it still have same issue @BigHomie90 posted which I also reproduced. If you need another look at keybusreader log from pc1616/1832 just say.

[Dilbert66]

Have you tried modifying the ino unlocker file as I suggested?