davesmeghead / visonic

Visonic Custom Component for integration with Home Assistant
Apache License 2.0
90 stars 20 forks source link

Version 0.8.2.1 can't read Powermax Pro #66

Closed jorgebnunes closed 2 years ago

jorgebnunes commented 2 years ago

Hi, latest update v0.8.2.1 broke my integration with my PowermaxPro Alarm:

Este erro teve origem numa integração personalizada.

Logger: custom_components.visonic.pyvisonic Source: custom_components/visonic/pyvisonic.py:1841 Integration: Visonic Intruder Alarm (documentation, issues) First occurred: 15:37:52 (1 occurrences) Last logged: 15:37:52

[Controller] Visonic Plugin has suspended all operations, there is a problem with the communication with the panel (i.e. no data has been received from the panel)

v0.8.1.0 worked like a charm.

Thanks.

davesmeghead commented 2 years ago

It could be the new checksum calculation, is it possible that you could upload a log file for me to take a look. Also, is it from the start or does it last a minutes/hours before it does that?

jorgebnunes commented 2 years ago

Hi, thanks for the reply.

Here it is:

2022-10-23 18:18:16.376 DEBUG (MainThread) [custom_components.visonic.pyvisonic] Initialising Protocol - Protocol Version 1.0.17.0 2022-10-23 18:18:16.384 DEBUG (MainThread) [custom_components.visonic.client] Initialising Client - Version 0.8.2.1 2022-10-23 18:18:16.392 INFO (MainThread) [custom_components.visonic] Starting Visonic Component 2022-10-23 18:18:16.479 DEBUG (MainThread) [custom_components.visonic] ***** create connection here ** 2022-10-23 18:18:16.479 INFO (MainThread) [custom_components.visonic] Starting Visonic with entry id=3c........Omited..........f8 configured panels=1 2022-10-23 18:18:16.479 DEBUG (MainThread) [custom_components.visonic] Panel Ident set up: panelident = 0 next auto panelident = 1 2022-10-23 18:18:16.479 DEBUG (MainThread) [custom_components.visonic.client] Exclude sensor list = [] Exclude x10 list = [] 2022-10-23 18:18:16.479 DEBUG (MainThread) [custom_components.visonic] Setting client ID for entry id 3c........Omited..........f8 2022-10-23 18:18:16.586 DEBUG (MainThread) [custom_components.visonic.client] ........... attempting connection 2022-10-23 18:18:16.586 DEBUG (MainThread) [custom_components.visonic.client] Visonic Connection Device Type is ethernet {<PyConfiguration.DownloadCode: 0>: 'ERASED by me :-)', <PyConfiguration.ForceStandard: 9>: False, <PyConfiguration.ForceAutoEnroll: 1>: False, <PyConfiguration.AutoSyncTime: 2>: True, <PyConfiguration.PluginLanguage: 3>: 'EN', <PyConfiguration.MotionOffDelay: 4>: 60, <PyConfiguration.SirenTriggerList: 5>: ['intruder', 'tamper', 'fire', 'emergency', 'gas', 'flood', 'x10', 'panic'], <PyConfiguration.B0_Enable: 6>: False, <PyConfiguration.B0_Min_Interval_Time: 7>: 5, <PyConfiguration.B0_Max_Wait_Time: 8>: 30} 2022-10-23 18:18:16.587 DEBUG (MainThread) [custom_components.visonic.pyvisonic] Setting TCP socket Options 2022-10-23 18:18:16.594 DEBUG (MainThread) [custom_components.visonic.pyvisonic] Buffer Flushed and Received some data! 2022-10-23 18:18:16.675 DEBUG (MainThread) [custom_components.visonic.pyvisonic] Initialising Protocol - Using Home Assistant Loop 2022-10-23 18:18:16.675 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Force Standard set to False 2022-10-23 18:18:16.675 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Force Auto Enroll set to False 2022-10-23 18:18:16.675 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Force Auto Sync Time set to True 2022-10-23 18:18:16.675 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Download Code set to ERASED by me :-), again! 2022-10-23 18:18:16.675 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Language set to EN 2022-10-23 18:18:16.676 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Motion Off Delay set to 60 2022-10-23 18:18:16.676 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Siren Trigger List set to ['intruder', 'tamper', 'fire', 'emergency', 'gas', 'flood', 'x10', 'panic'] 2022-10-23 18:18:16.676 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] B0 Enable set to False 2022-10-23 18:18:16.676 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] B0 Min Interval set to 5 2022-10-23 18:18:16.676 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] B0 Max Wait Time set to 30 2022-10-23 18:18:16.711 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Connection] Connected to local Protocol handler and Transport Layer 2022-10-23 18:18:16.711 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [_clearList] Setting queue empty 2022-10-23 18:18:16.711 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [StartDownload] Starting download mode 2022-10-23 18:18:16.750 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Sending Command (Exit) raw data 0d 0f f1 0a waiting for message response [] 2022-10-23 18:18:16.751 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Command has a wait time after transmission 1.5 2022-10-23 18:18:16.751 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] download_counter is 1 2022-10-23 18:18:17.692 DEBUG (MainThread) [custom_components.visonic.client] ........... connection made 2022-10-23 18:18:18.039 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] download_counter is 2 2022-10-23 18:18:18.749 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Sending Command (Stop) raw data 0d 0b f5 0a waiting for message response [] 2022-10-23 18:18:18.749 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Command has a wait time after transmission 1.5 2022-10-23 18:18:19.759 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] download_counter is 3 2022-10-23 18:18:28.213 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] download_counter is 4 2022-10-23 18:18:28.262 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Resetting expected response counter, it got to 4 Response list length before 0 after 1 2022-10-23 18:18:28.264 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Setting Download Mode to true 2022-10-23 18:18:28.264 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Sending Command (Start Download Mode) waiting for message response ['0X3C'] 2022-10-23 18:18:36.309 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] Trigger Panel Download Attempt - Not yet received the panel details 2022-10-23 18:18:36.309 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [StartDownload] Starting download mode 2022-10-23 18:18:36.339 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Resetting expected response counter, it got to 5 Response list length before 0 after 1 2022-10-23 18:18:36.339 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Setting Download Mode to true 2022-10-23 18:18:36.339 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Sending Command (Start Download Mode) waiting for message response ['0X3C'] 2022-10-23 18:19:05.484 ERROR (MainThread) [custom_components.visonic.pyvisonic] [Controller] Visonic Plugin has suspended all operations, there is a problem with the communication with the panel (i.e. no data has been received from the panel) 2022-10-23 18:19:05.497 DEBUG (MainThread) [custom_components.visonic.client] Visonic update event panel=0 event=10 {'state': 'NeverConnected', 'condition': 10} 2022-10-23 18:19:05.516 DEBUG (MainThread) [custom_components.visonic.alarm_control_panel] Initialising alarm control panel Visonic Alarm 2022-10-23 18:19:05.516 DEBUG (MainThread) [custom_components.visonic.alarm_control_panel] alarm control panel async_setup_entry called <EntityPlatform domain=alarm_control_panel platform_name=visonic config_entry=<homeassistant.config_entries.ConfigEntry object at 0x7f93efd560>> 2022-10-23 18:19:05.538 DEBUG (SyncWorker_0) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?) 2022-10-23 18:19:05.545 DEBUG (MainThread) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?)

Holland1 commented 2 years ago

I have the same issue. Also a powermax pro. Please find the log below

2022-10-24 02:29:40.723 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration visonic which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-10-24 02:29:40.727 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-10-24 02:29:40.729 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration nefiteasy which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-10-24 02:29:40.731 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration samsungtv_encrypted which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-10-24 02:29:58.190 DEBUG (MainThread) [custom_components.visonic.pyvisonic] Initialising Protocol - Protocol Version 1.0.17.0 2022-10-24 02:29:58.196 DEBUG (MainThread) [custom_components.visonic.client] Initialising Client - Version 0.8.2.1 2022-10-24 02:29:58.201 INFO (MainThread) [custom_components.visonic] Starting Visonic Component 2022-10-24 02:29:58.263 DEBUG (MainThread) [custom_components.visonic] ***** create connection here ** 2022-10-24 02:29:58.263 INFO (MainThread) [custom_components.visonic] Starting Visonic with entry id=c8f56b2c99227e65e3e28451e9d39b40 configured panels=1 2022-10-24 02:29:58.264 DEBUG (MainThread) [custom_components.visonic] Panel Ident set up: panelident = 0 next auto panelident = 1 2022-10-24 02:29:58.264 DEBUG (MainThread) [custom_components.visonic.client] Exclude sensor list = [] Exclude x10 list = [] 2022-10-24 02:29:58.264 DEBUG (MainThread) [custom_components.visonic] Setting client ID for entry id c8f56b2c99227e65e3e28451e9d39b40 2022-10-24 02:29:58.660 DEBUG (MainThread) [custom_components.visonic.client] ........... attempting connection 2022-10-24 02:29:58.660 DEBUG (MainThread) [custom_components.visonic.client] Visonic Connection Device Type is ethernet {<PyConfiguration.DownloadCode: 0>: '', <PyConfiguration.ForceStandard: 9>: False, <PyConfiguration.ForceAutoEnroll: 1>: False, <PyConfiguration.AutoSyncTime: 2>: True, <PyConfiguration.PluginLanguage: 3>: 'NL', <PyConfiguration.MotionOffDelay: 4>: 120.0, <PyConfiguration.SirenTriggerList: 5>: ['intruder'], <PyConfiguration.B0_Enable: 6>: False, <PyConfiguration.B0_Min_Interval_Time: 7>: 5, <PyConfiguration.B0_Max_Wait_Time: 8>: 30} 2022-10-24 02:29:58.660 DEBUG (MainThread) [custom_components.visonic.pyvisonic] Setting TCP socket Options 2022-10-24 02:29:59.714 DEBUG (MainThread) [custom_components.visonic.pyvisonic] Initialising Protocol - Using Home Assistant Loop 2022-10-24 02:29:59.714 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Force Standard set to False 2022-10-24 02:29:59.714 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Force Auto Enroll set to False 2022-10-24 02:29:59.714 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Force Auto Sync Time set to True 2022-10-24 02:29:59.714 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Language set to NL 2022-10-24 02:29:59.714 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Motion Off Delay set to 120.0 2022-10-24 02:29:59.715 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] Siren Trigger List set to ['intruder'] 2022-10-24 02:29:59.715 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] B0 Enable set to False 2022-10-24 02:29:59.715 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] B0 Min Interval set to 5 2022-10-24 02:29:59.715 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Settings] B0 Max Wait Time set to 30 2022-10-24 02:29:59.768 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Connection] Connected to local Protocol handler and Transport Layer 2022-10-24 02:29:59.769 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [_clearList] Setting queue empty 2022-10-24 02:29:59.769 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [StartDownload] Starting download mode 2022-10-24 02:29:59.799 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Sending Command (Exit) raw data 0d 0f f1 0a waiting for message response [] 2022-10-24 02:29:59.799 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Command has a wait time after transmission 1.5 2022-10-24 02:29:59.799 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] download_counter is 1 2022-10-24 02:30:09.221 DEBUG (MainThread) [custom_components.visonic.client] ........... connection made 2022-10-24 02:30:09.221 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] download_counter is 2 2022-10-24 02:30:09.275 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Sending Command (Stop) raw data 0d 0b f5 0a waiting for message response [] 2022-10-24 02:30:09.275 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Command has a wait time after transmission 1.5 2022-10-24 02:30:10.824 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] download_counter is 3 2022-10-24 02:30:11.200 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Resetting expected response counter, it got to 3 Response list length before 0 after 1 2022-10-24 02:30:11.201 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Setting Download Mode to true 2022-10-24 02:30:11.201 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Sending Command (Start Download Mode) waiting for message response ['0X3C'] 2022-10-24 02:30:16.225 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [Controller] Trigger Panel Download Attempt - Not yet received the panel details 2022-10-24 02:30:16.226 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [StartDownload] Starting download mode 2022-10-24 02:30:16.226 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Resetting expected response counter, it got to 5 Response list length before 0 after 1 2022-10-24 02:30:16.228 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Setting Download Mode to true 2022-10-24 02:30:16.229 DEBUG (MainThread) [custom_components.visonic.pyvisonic] [sendPdu] Sending Command (Start Download Mode) waiting for message response ['0X3C'] 2022-10-24 02:30:41.363 ERROR (MainThread) [custom_components.visonic.pyvisonic] [Controller] Visonic Plugin has suspended all operations, there is a problem with the communication with the panel (i.e. no data has been received from the panel) 2022-10-24 02:30:41.380 DEBUG (MainThread) [custom_components.visonic.client] Visonic update event panel=0 event=10 {'state': 'NeverConnected', 'condition': 10} 2022-10-24 02:30:41.397 DEBUG (MainThread) [custom_components.visonic.alarm_control_panel] Initialising alarm control panel Visonic Alarm 2022-10-24 02:30:41.398 DEBUG (MainThread) [custom_components.visonic.alarm_control_panel] alarm control panel async_setup_entry called <EntityPlatform domain=alarm_control_panel platform_name=visonic config_entry=<homeassistant.config_entries.ConfigEntry object at 0x7fa523d970>> 2022-10-24 02:30:41.413 DEBUG (SyncWorker_6) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?) 2022-10-24 02:30:41.419 DEBUG (MainThread) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?) 2022-10-24 02:31:11.434 DEBUG (SyncWorker_5) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?) 2022-10-24 02:31:11.440 DEBUG (MainThread) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?) 2022-10-24 02:31:41.436 DEBUG (SyncWorker_8) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?) 2022-10-24 02:31:41.442 DEBUG (MainThread) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?) 2022-10-24 02:32:11.435 DEBUG (SyncWorker_0) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?) 2022-10-24 02:32:11.438 DEBUG (MainThread) [custom_components.visonic.client] isPanelConnected: code format none as armcode is none (panel starting up or is there a problem?)

davesmeghead commented 2 years ago

I don't really understand what's happening so we're going to have to try a few experiments:

Other than this I'm a bit stuck at the moment. As 0.8.1.0 works and 0.8.2.1 doesn't then the only thing left to do is to make the various software changes 1 at a time to try to work out which one breaks it. I have changed 5 of the source code files and I've worked out that they should be compatible if you change them in the correct order.

Do you know how to do the following, and between each line I'd like you to delete the integration from within HA and restart HA (not just from within HA but externally stop it running and restart it as I need to make sure that it picks up the python software changes) and then reinstall the integration from within HA:

jorgebnunes commented 2 years ago

Hi again, tested your procedure and the integration breaks when replacing the last file pyvisonic.py over version 0.8.1.0. Thanks.

jorgebnunes commented 2 years ago

Well, it is the checksum calculation. On version 0.8.2.1 did:

    checksum = 0xFF - (checksum % 0xFF)
    if checksum == 0xFF:
        checksum = 0x00
    # 29/8/2022: Commented out the above 3 lines and added the following 3.  I think that the checksum should never be zero.
    #      This works for both my panels and always validates exactly (never using the +1 or -1 code in _validatePDU)
    #      It also matches the checksums that the Powerlink 3.1 module generates.
    #checksum = 256 - (checksum % 255)
    #if checksum == 256:
        #checksum = 1

Reverted your modification and the panel works again.

bwillette commented 2 years ago

Came here to report the same issue with my PoweMax+ and the change above to revert the checksum logic from jorgebnunes got mine working again too (thank you!)

davesmeghead commented 2 years ago

Thanks for all your help and patience. I've reverted the checksum calc back to original and uploaded 0.8.2.2 to Github and HACS. I'll close this issue, any further problems then open a new issue please.