Powermaster 33 disconnecting when alarm sounds

[gregdcBe]

Hello,

First thanks for all your work !

I've a Powermaster 33 connected over USB (USB-TTL adapter). It is working fine except that as soon as alarm is fired, integration lose connectivity due to bad message received. In HA log I can see some errors (see below).

NB : Just before this, the zone update message arrived fine.

Logger: custom_components.visonic.pyvisonic Source: custom_components/visonic/pyvisonic.py:1875 Integration: Visonic Intruder Alarm (documentation, issues) First occurred: 15:07:34 (12 occurrences) Last logged: 15:07:41

[data receiver] Warning : Construction of incoming packet validation failed - Message = 0d f4 05 00 80 c0 04 95 22 bd 66 98 13 c6 d5 66 36 ab 19 66 36 ab 08 d4 c4 4e 8f 52 ac 94 00 f1 25 3c 4b 55 70 1c 25 f7 a7 09 bd e8 b8 0e 13 52 89 bd e9 dc 05 f3 bd e9 c2 6f 7a 2e 02 f9 fe f4 be 7f bd 17 01 7c ff 00 7a 51 3f bd 3b 80 be 7f bd 1e 7f bd 17 01 7c ff 00 7a 3c ff 00 7a 2e 01 e7 fb d1 e7 fb d1 70 0f 3f de 97 ce f7 a2 e0 27 9d ef 47 9d ef 45 c0 43 2f bd 34 c9 4a e0 31 9e a1 66 a0 08 5c d5 77 checksum calcs 0X33 [data receiver] Warning : Construction of incoming packet validation failed - Message = 0d f4 05 00 90 c0 f7 a0 05 13 7b d2 f9 de f4 5c 05 f3 bd e8 f3 bd e8 b8 0b e7 7b d2 f9 de f4 5c 05 f3 bd e8 f3 bd e9 dc 05 f3 bd e8 f3 bd e8 b8 07 9d ef 4b e7 7b d1 70 0f 3b de 97 ce f7 a2 e0 1e 77 bd 2f 9d ef 45 c0 3c df 7a 3c df 7a 2e 03 4c 94 c3 25 2b 81 1b 3d 42 ed 40 15 dd aa b4 8d 40 15 dd aa 06 6e 6a 46 63 07 20 f2 2a 74 6a c4 44 ca d5 3a c9 56 98 c9 56 5a 94 4d 56 98 0e 13 fb d3 c4 fe f4 5c 07 09 fd e9 c2 7f 7a 77 01 44 fe f4 a2 7f 7a 2e 03 checksum calcs 0X84 [data receiver] Warning : Construction of incoming packet validation failed - Message = 0d f4 05 00 a0 c0 f3 fd e8 f3 fd e8 01 7c ff 00 7a 3c ff 00 7a 00 5f 3b de 9d e7 7b d0 02 f9 be f4 79 be f4 80 43 2d 34 cb 4c 06 34 b5 1b 49 40 10 bb d5 79 1e 80 2b 3b d4 2c d5 2d 81 d4 cb a2 5a cd 0b 21 85 41 23 82 07 20 d7 1b 77 01 b4 b9 78 8f 63 c5 15 23 65 71 0c 0f 4f 0f 59 26 31 e2 4a 70 97 de aa e0 2f 9b 4e 12 fb d1 cc 02 89 a9 de 75 3e 61 8a 26 f7 a5 13 7b d1 cc 02 89 e9 7c ff 00 7a 39 80 51 3f bd 2f 9f ef 45 c0 51 3f bd 2f 9f ef 4e e0 2f 9f ef 47 9f ef 47 30 0b f6 8f 7a 5f b4 7b d1 70 0f checksum calcs 0X37 ERROR Connection Lost : disconnected due to exception CRC errors Calling Exception handler.

Logger: homeassistant.util.async_ Source: util/async_.py:184 First occurred: 15:07:36 (1 occurrences) Last logged: 15:07:36

Detected blocking call to sleep inside the event loop. This is causing stability issues. Please report issue to the custom integration author for visonic doing blocking calls at custom_components/visonic/pyvisonic.py, line 1512: sleep(5.0) # a bit of time for the watchdog timers and keep alive loops to self terminate

[davesmeghead]

Hi, So looking at the last problem first, I already know about the "sleep" and it only happens when the integration is restarted so it's not the original cause.

I also know about the "0d f4" messages but I cannot decode them at the moment, only PowerMaster panels sends them. I have a PowerMaster 30 panel that I use for experimenting with and when it sends f4 message data the 5th byte is the data length but in your case it doesn't appear to be like that so I'd like to investigate further.

As you have only provided the "Warning" messages I don't have the information that I need, can you please set the HA log settings to debug like this on the wiki. Then get your panel to output these again and upload the log file to dropbox/pastebin so I can take a proper look. Thanks

[gregdcBe]

Hello,

Thanks for looking at this, here is the pastebin corresponding to last test https://pastebin.com/m5kKXELb password is cUTHZdCv8R

Test was : 10:19 debug activation/hass restart 10:33 alarm activation 10:34 motion on Z04 + siren crash of integration (unavailable) 10:36 integration come back

[davesmeghead]

Thanks for the log file

OK, so I can confirm that I am decoding the "0d f4" messages incorrectly :( By decoding them incorrectly I lose synchronisation with the panels messages and due to this I trigger a: ERROR Connection Lost : disconnected due to exception CRC errors And therefore a restart of the integration. After I restart the first time, the panel is still sending "0f f4" data and so the same thing happens again 2 more times, I restart the integration each time.

I am going to change the handling of the f4 messages to just look for a valid message in the stream and not try to decode it (as my existing decode method is wrong). Give me a bit of time and I'll upload a new version to Github. Thanks again for the log file.

[davesmeghead]

Are you able to edit the pyvisonic.py file located in /config/custom_components/visonic

If you are can you change line 309 to this 0xF4 : PanelCallBack( 0, True, True, 0, 0 ) # All you really need to do is change the 7, 4 and 2 to be 0

If you can, please give it a try. This should ignore the f4 messages and resynchronise itself when it gets a valid message i.e. a message that is structured correctly and has a valid checksum. You'll note that the same is true for f1 messages in the line above.

Let me know if you're doing this and what happens please.

[gregdcBe]

Changed python file, restarted whole home assistant. Alarm (motion -> siren) test done today at 14:21 (time corresponding to logs) Logs are here : https://pastebin.com/TCUjDzDi password : HLKSrj5925

[davesmeghead]

Just to let you know that I've had a quick look and it isn't obvious what's happening. It also doesn't look like it resynchronises and wouldn't even if we did not check the CRC of the F4 message data. It looks like the F4 message data is very long and any resync effort just tries within the F4 data itself and fails.

My current thoughts are to gather information first to try and work out what to do. It looks like the Camera sensor that is triggering the alarm so my thought is that the F4 message data may be a picture grab from the camera, and that could be hundreds of bytes.

Anyway, I'll have a think about it and take another look over the weekend. I just thought I'd keep you updated.

EDIT: What is the make and model number for the Camera sensor on Zone 4?

[gregdcBe]

Indeed motion sensor ( Visonic NEXT-CAM-K9-PG2) has camera so this could be image capture. I don't know format of Visonic message but I would expect some kind of Tag Length Value. Will dump whole incoming traffic and check on my own also trying to understand format.

[davesmeghead]

The format of a visonic message is normally like this as described on the wiki. So in this case: F4 is the PDU identifier byte. It looks like F4 is a variable length message and normally in variable length messages there's an indication of the actual length as part of the "The Message" itself. I have tabulated the F4 messages from your log file, here's a screen grab of the left side i.e. the start of each F4 message lined up in columns.

It looks like the 03 and 05 (the 1st byte of the Message Data) represents the Message Data Type. Each sequence starts with a single 03 and then multiple 05.

I'm not sure about the 00 column.

The d0, e0 etc column looks like a sequence counter.

The column with 15 and then c0 looks like it represents the variable length.

The number of bytes for the header, checksum, footer and the first part of the data packet is 8 bytes. I would guess that a "0d f4 03" message is 8 bytes plus 21 bytes (0x15) long I would guess that a "0d f4 05" message is 8 bytes plus 192 bytes (0xc0) long

How good is your python :) ? If you want me to write some code for you to put in the pyvisonic.py file I can. The thing to do is to forget about getting the integration working. Write a function to capture the stream and output it to the log file (in a similar way to what I do already). Look for the first "0d f4" received and then enter the function that just reads data and dumps it to the HA log file, that way we can see every byte in sequence and count the bytes. Every time you see "0d f4" then create a new line in the log file. After you trigger your alarm let HA run for 10 minutes or so and then look at the log file.

I hope this makes sense.

[gregdcBe]

Very clear, thanks My python is devops level but enough to understand and adapt the code :-) Will try to do that this weekend

[gregdcBe]

Just a question, I see "PACKET_MAX_SIZE = 0xB0"

I see in logs several message "PDU with CRC error Message" coming from

if len(self.ReceiveData) > PACKET_MAX_SIZE:

If the length exceeds the max PDU size from the panel then stop and resync

                log.warning("[data receiver] PDU with CRC error Message = {0}   checksum calcs {1}".format(self._toString(self.ReceiveData), hex(a).upper()))

As some messages can be longer (192 bytes), shouldn't we increase max size ? Is there specific reason to limit to 176 bytes?

[davesmeghead]

Ah OK. When I download the EPROM data I had problems if I asked for data lengths more than 176 bytes at a time. This may only be for some PowerMax panels but it is certainly the case for my PowerMax Pro Part panel. Please set PACKET_MAX_SIZE to whatever you need to, especially as we're experimenting at the moment.

[davesmeghead]

Did you make any progress on this Issue? If not then I'll close the Issue as there's no further code changes.

[davesmeghead]

I'll close this issue but if you have further problems then reopen it or create a new issue

[gregdcBe]

Hi,

sorry for being less reactive, I've no time anyore for this :-( Btw, all normal operations are working well.

Thanks again for your great work