search

rbrouwer / dahua-vto-dz

Dahua VTO Dz is a plugin, which connects Domoticz to your Dahua VTO doorbell
ISC License
5 stars 0 forks source link

plug in deconnection #2

Open rezzalex opened 1 year ago

rezzalex commented 1 year ago

it happens 3 to 4 times / day :

2023-09-12 06:33:26.417 Error: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:26.421 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:26.421 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:26.421 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:26.422 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06:33:26.422 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:26.422 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get' 2023-09-12 06:33:26.422 Error: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:26.422 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:26.422 Error: Visiophone : File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:26.422 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:26.422 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06:33:26.422 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:26.422 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get' 2023-09-12 06:33:26.422 Error: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:26.422 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:26.422 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:26.422 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:26.422 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06:33:26.422 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:26.422 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get' 2023-09-12 06:33:30.098 Error: Visiophone: Initialization not completed; Retrying failed calls. 2023-09-12 06:33:30.152 Error: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:30.152 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:30.152 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:30.152 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:30.153 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06:33:30.153 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:30.153 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get' 2023-09-12 06:33:30.153 Er ror: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:30.153 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:30.154 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:30.154 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:30.154 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06:33:30.154 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:30.155 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get' 2023-09-12 06:33:35.055 Error: Visiophone: Initialization not completed; Retrying failed calls. 2023-09-12 06:33:35.107 Error: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:35.108 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:35.108 Error: Visiophone: File "/opt/domoticz/userdata/p lugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:35.108 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:35.108 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06:33:35.109 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:35.109 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get' 2023-09-12 06:33:35.109 Error: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:35.109 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:35.109 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:35.109 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:35.109 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06 :33:35.109 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:35.109 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get' 2023-09-12 06:33:40.098 Error: Visiophone: Initialization not completed; Retrying failed calls. 2023-09-12 06:33:40.150 Error: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:40.150 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:40.150 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:40.150 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:40.150 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06:33:40.150 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:40.150 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get' 2023-09- 12 06:33:40.150 Error: Visiophone: Call to function 'onMessage' failed, exception details: 2023-09-12 06:33:40.150 Error: Visiophone: Traceback (most recent call last): 2023-09-12 06:33:40.150 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 637, in onMessage 2023-09-12 06:33:40.150 Error: Visiophone: _plugin.on_message(Data) 2023-09-12 06:33:40.150 Error: Visiophone: File "/opt/domoticz/userdata/plugins/dahua-vto-dz/plugin.py", line 502, in on_message 2023-09-12 06:33:40.150 Error: Visiophone: message_id = message.get("id") 2023-09-12 06:33:40.150 Error: Visiophone: AttributeError: 'NoneType' object has no attribute 'get'

rbrouwer commented 1 year ago

I think I would like to add some additional debug-logging for this, because I do wonder what the VTO is sending in that case.

The received message does not contain a "{" and "}". Therefore "parse_response" returns None. The on_message does not handle this case when parse_response returns None. I can definitely handle None messages in parse_response.

rbrouwer commented 1 year ago

@rezzalex, can you check out the latest commit and see if that helps out? And can you find any logs messages: "Unparseable data message received: " followed by data when using that version? If so, could you post those here.

rezzalex commented 1 year ago

Just add it and here some messages intercepted at start-up :

2023-09-14 11:14:09.158 Visiophone: Failed to read data: b' \x00\x00\x00DHIP\xc3DU\x13\r\x00\x00\x00f\x10\x00\x00\x00\x00\x00\x00f\x10\x00\x00\x00\x00\x00\x00{"id":13,"params":{"table":[{"AccessProtocol":"Local","AutoRemoteCheck":{"Enable":false,"Time":255},"BreakInAlarmEnable":false,"CardNoConvert":0,"CloseAlwaysTime":255,"CloseTimeout":60,"CustomPasswordEnable":false,"DoorNotClosedAlarmEnable":false,"DuressAlarmEnable":true,"Enable":true,"FirstEnter":{"Enable":false,"Status":"Normal","Time":1},"HelmetEnable":false,"HolidayTime":255,"LockMode":2,"Method":42,"Name":"Door1","OpenAlwaysTime":255,"ProtocolType":0,"ReadCardState":0,"RemoteCheck":false,"RemoteDetail":{"TimeOut":0,"TimeOutDoorStatus":"Close"},"RepeatEnterAlarm":false,"RepeatEnterTime":0,"SensorEnable":false,"State":"Normal","TimeSchedule":[[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}]],"UnlockHoldInterval":2,"UnlockReloadInterval":15},{"AccessProtocol":"Dahua","AutoRemoteCheck":{"Enable":false,"Time":255},"BreakInAlarmEnable":false,"CardNoConvert":0,"CloseAlwaysTime":255,"CloseTimeout":60,"CustomPasswordEnable":false,"DoorNotClosedAlarmEnable":false,"DuressAlarmEnable":true,"Enable":true,"FirstEnter":{"Enable":false,"Status":"Normal","Time":1},"HelmetEnable":false,"HolidayTime":255,"LockMode":2,"Method":42,"Name":"Door2","OpenAlwaysTime":255,"ProtocolType":0,"ReadCardState":0,"RemoteCheck":false,"RemoteDetail":{"TimeOut":0,"TimeOutDoorStatus":"Close"},"RepeatEnterAlarm":false,"RepeatEnterTime":0,"SensorEnable":false,"State":"Normal","TimeSchedule":[[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}]],"UnlockHoldInter', error: Expecting ',' delimiter: line 1 column 4046 (char 4045), Line: 588

and also

2023-09-14 11:13:59.089 Error: Visiophone: Initialization not completed; Retrying failed calls.

rbrouwer commented 1 year ago

I got it. onMessage gets only a partial message from Domoticz or VTO (not sure which), therefore parsing those 2 partial messages that will give invalid messages and/or json twice. I've modified the plugin to attempt to prepend the previous unreadable message to the next one and attempt to parse it then.

This seems to fix this issue.

rezzalex commented 1 year ago

error message just after restart after update :

2023-09-14 16:19:11.113 Error: Visiophone: Unparseable data message received: b' \x00\x00\x00DHIP\xa2$BZ\x07\x00\x00\x00f\x10\x00\x00\x00\x00\x00\x00f\x10\x00\x00\x00\x00\x00\x00{"id":7,"params":{"table":[{"AccessProtocol":"Local","AutoRemoteCheck":{"Enable":false,"Time":255},"BreakInAlarmEnable":false,"CardNoConvert":0,"CloseAlwaysTime":255,"CloseTimeout":60,"CustomPasswordEnable":false,"DoorNotClosedAlarmEnable":false,"DuressAlarmEnable":true,"Enable":true,"FirstEnter":{"Enable":false,"Status":"Normal","Time":1},"HelmetEnable":false,"HolidayTime":255,"LockMode":2,"Method":42,"Name":"Door1","OpenAlwaysTime":255,"ProtocolType":0,"ReadCardState":0,"RemoteCheck":false,"RemoteDetail":{"TimeOut":0,"TimeOutDoorStatus":"Close"},"RepeatEnterAlarm":false,"RepeatEnterTime":0,"SensorEnable":false,"State":"Normal","TimeSchedule":[[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"}],[{"Method":42,"TimeSection":"00:00:00-23:59:59"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00-00:00:00"},{"Method":42,"TimeSection":"00:00:00' 2023-09-14 16:19:15.062 Error: Visiophone: Initialization not completed; Retrying failed calls. 2023-09-14 16:19:15.062 Error: Visiophone: Reloading access control factory instance.

Then everything seems fine

rbrouwer commented 1 year ago

I believe the exceptions towards Domoticz are now handled. As long as it logs: "Initialized successfully" sooner or later, it is happy. Those "Errors" are errors, but no real issue. As the last one says: It just retries.