search

elad-bar / DahuaVTO2MQTT

Listens to events from Dahua VTO unit and publishes them via MQTT Message
103 stars 39 forks source link

error: substring not found, Line: 400 #53

Open matlab22 opened 2 years ago

matlab22 commented 2 years ago

Hi I am getting an error, when I use my fingerprint reader on my VTO4202F. Can you help me figer out what the problem is?

2022-05-31 21:13:57,663 ERROR clients.DahuaClient Failed to read data: b' \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00\xeb\x00\x00\x00\x00\x00\x00\x00\xeb\x00\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"SIPRegisterResult","Data":{"LocaleTime":"2022-05-31 21:11:51","Success":false,"UTC":1654027911.0},"Index":0}]},"session":798630027}\n \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00\xd5\x00\x00\x00\x00\x00\x00\x00\xd5\x00\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Start","Code":"VideoMotion","Data":{"LocaleTime":"2022-05-31 21:12:26","UTC":1654027946.0},"Index":0}]},"session":798630027}\n \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00\xe1\x00\x00\x00\x00\x00\x00\x00\xe1\x00\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"BackKeyLight","Data":{"LocaleTime":"2022-05-31 21:12:26","State":9,"UTC":1654027946.0},"Index":-1}]},"session":798630027}\n \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00\xed\x00\x00\x00\x00\x00\x00\x00\xed\x00\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"FingerPrintCheck","Data":{"FingerPrintID":-1,"LocaleTime":"2022-05-31 21:12:26","UTC":1654027946.0},"Index":0}]},"session":798630027}\n \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00{\x01\x00\x00\x00\x00\x00\x00{\x01\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"AccessControl","Data":{"CardNo":"","CardType":null,"ErrorCode":16,"LocaleTime":"2022-05-31 21:12:26","Method":6,"Name":"OpenDoor","Password":"","ReaderID":"1","RecNo":116,"SnapURL":"","Status":0,"Type":"Entry","UTC":1654027946.0,"UserID":""},"Index":0}]},"session":798630027}\n \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00\xd4\x00\x00\x00\x00\x00\x00\x00\xd4\x00\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Stop","Code":"VideoMotion","Data":{"LocaleTime":"2022-05-31 21:12:32","UTC":1654027952.0},"Index":0}]},"session":798630027}\n \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00\xeb\x00\x00\x00\x00\x00\x00\x00\xeb\x00\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"SIPRegisterResult","Data":{"LocaleTime":"2022-05-31 21:12:49","Success":false,"UTC":1654027969.0},"Index":0}]},"session":798630027}\n \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00 \x01\x00\x00\x00\x00\x00\x00 \x01\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"NTPAdjustTime","Data":{"Address":"185.122.238.196","Before":"31-05-2022 21:13:22","LocaleTime":"2022-05-31 21:13:22","UTC":1654028002.0,"result":true},"Index":0}]},"session":798630027}\n \x00\x00\x00DHIP\x8b \x9a/\x08\x00\x00\x00\xeb\x00\x00\x00\x00\x00\x00\x00\xeb\x00\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"SIPRegisterResult","Data":{"LocaleTime":"2022-05-31 21:13:47","Success":false,"UTC":1654028027.0},"Index":0}]},"session":798630027}\n', error: substring not found, Line: 400

matlab22 commented 2 years ago

I am not sure if it is related, but the script loses the connection to the mqtt broker: 2022-06-02 23:02:59,198 INFO clients.DahuaClient Server sent EOF message 2022-06-02 23:02:59,208 WARNING __main__ Disconnected, will try to connect in 5 seconds 2022-06-02 23:03:04,214 INFO __main__ Connecting 2022-06-02 23:03:04,221 INFO clients.MQTTClient MQTT Broker is trying to connect... 2022-06-02 23:03:04,224 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-02 23:03:04,231 INFO clients.MQTTClient MQTT Broker connected with result code 0

where do I find the log?

elad-bar commented 2 years ago

From time to time the MQTT can disconnect clients, that means it automatically reconnected

matlab22 commented 2 years ago

In my case it does not reconnect: 2022-06-16 21:02:40,901 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-16 21:02:40,902 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-16 21:02:41,906 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-16 21:02:41,907 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-16 21:02:42,910 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-16 21:02:42,910 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-16 21:02:43,914 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-16 21:02:43,915 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-16 21:02:44,919 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-16 21:02:44,919 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-16 21:02:45,923 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-16 21:02:45,924 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-16 21:02:46,928 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-16 21:02:46,928 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was los

when I restart the script it reconnects instantly but I am getting this message: 2022-06-16 21:04:22,254 INFO clients.DahuaClient Device Type: VTO4202F 2022-06-16 21:04:22,255 ERROR clients.DahuaClient Failed to handle message, error: 'NoneType' object has no attribute 'get', Line: 76

matlab22 commented 2 years ago

is there anything I can try. This happens very often and it can not reconnect automatically. The mqtt broker is stable I use it with my zigbee devices all the time

matlab22 commented 2 years ago

It lost connection and never try to reconnect: 2022-06-19 08:24:51,165 ERROR clients.DahuaClient Failed to handle message, error: 'NoneType' object has no attribute 'get', Line: 76 2022-06-19 08:24:52,097 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-19 08:24:52,098 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-19 08:24:53,101 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-19 08:24:53,101 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-19 08:24:54,105 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-19 08:24:54,105 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-19 08:24:55,110 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost 2022-06-19 08:24:55,110 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-19 08:24:56,113 INFO clients.MQTTClient MQTT Broker connected with result code 0 2022-06-19 08:24:56,114 WARNING clients.MQTTClient MQTT Broker got disconnected, Reason Code: 7 - The connection was lost it looks like it can connect but not properly. so it never goes in the exception of "while not self.is_connected:" How do i know what reason code 7 means?

elad-bar commented 2 years ago

I will check it later today, Error 7 is connection lost, most probably by the broker, Seems that the issue related to first message in the log dump

matlab22 commented 2 years ago

Perfect thank you. I guess the message is too long so it is not getting fully parsed. 2022-06-19 08:40:10,017 INFO clients.DahuaClient Device Type: VTO4202F 2022-06-19 08:40:10,019 ERROR clients.DahuaClient Failed to read data: b' \x00\x00\x00DHIPd\x11Qh\x08\x00\x00\x00A\x00\x00\x00\x00\x00\x00\x00A\x00\x00\x00\x00\x00\x00\x00{"id":8,"params":{"SID":513},"result":true,"session":1750143332}\n \x00\x00\x00DHIPd\x11Qh\x04\x00\x00\x00f\x10\x00\x00\x00\x00\x00\x00f\x10\x00\x00\x00\x00\x00\x00{"id":4,"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', error: Expecting ',' delimiter: line 1 column 2737 (char 2736), Line: 404 2022-06-19 08:40:10,021 ERROR clients.DahuaClient Failed to handle message, error: 'NoneType' object has no attribute 'get', Line: 76 2022-06-19 08:40:10,022 INFO clients.DahuaClient Serial Number: 6L0C4A9PAJ19C69 2022-06-19 08:40:10,072 INFO clients.DahuaClient Version: 4.511.0000000.0.R, Build Date: 2021-11-16 2022-06-19 11:13:03,581 ERROR clients.DahuaClient Failed to read data: b' \x00\x00\x00DHIPd\x11Qh\x08\x00\x00\x00{\x01\x00\x00\x00\x00\x00\x00{\x01\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"AccessControl","Data":{"CardNo":"","CardType":null,"ErrorCode":16,"LocaleTime":"2022-06-19 09:13:02","Method":6,"Name":"OpenDoor","Password":"","ReaderID":"1","RecNo":13,"SnapURL":"","Status":0,"Type":"Entry","UTC":1655629982.0,"UserID":""},"Index":0}]},"session":1750143332}\n', error: substring not found, Line: 401 2022-06-19 11:13:03,583 ERROR clients.DahuaClient Failed to handle message, error: 'NoneType' object has no attribute 'get', Line: 76 2022-06-19 11:13:39,317 ERROR clients.DahuaClient Failed to read data: b' \x00\x00\x00DHIPd\x11Qh\x08\x00\x00\x00{\x01\x00\x00\x00\x00\x00\x00{\x01\x00\x00\x00\x00\x00\x00{"id":8,"method":"client.notifyEventStream","params":{"SID":513,"eventList":[{"Action":"Pulse","Code":"AccessControl","Data":{"CardNo":"","CardType":null,"ErrorCode":16,"LocaleTime":"2022-06-19 09:13:38","Method":6,"Name":"OpenDoor","Password":"","ReaderID":"1","RecNo":14,"SnapURL":"","Status":0,"Type":"Entry","UTC":1655630018.0,"UserID":""},"Index":0}]},"session":1750143332}\n', error: substring not found, Line: 401 2022-06-19 11:13:39,318 ERROR clients.DahuaClient Failed to handle message, error: 'NoneType' object has no attribute 'get', Line: 76