AlertStream: No Element Found about pyhik

[mezz64]

For the error, please add debug logging lines to your hass config for pyhik and post the output from a HASS start. I'd like to verify your sensors and XML namespace are being identified correctly.

logs:
   pyhik.hikvision: debug
   homeassistant.components.binary_sensor.hikvision: debug

In regards to the boundary trigger, the cameras I used for testing provided a constant stream of videoloss events that reliably generated boundary messages at a fast pace so it wasn't an issue. Parsing the content length certainly isn't a bad idea, but I've seen some conflicting results in the past where the reported content length did not match the XML body. Ultimately working off the boundary seemed more reliable.

[randellhodges]

Here is the exceprt from the log:

2017-12-04 08:18:35 INFO (MainThread) [homeassistant.components.telegram_bot] Setting up telegram_bot.webhooks
2017-12-04 08:18:35 DEBUG (SyncWorker_10) [pyhik.hikvision] Initializing new hikvision device at: http://camera-driveway
2017-12-04 08:18:35 DEBUG (SyncWorker_10) [pyhik.hikvision] Using Namespace: http://www.hikvision.com/ver20/XMLSchema
2017-12-04 08:18:35 DEBUG (SyncWorker_10) [pyhik.hikvision] Processed 5c137e18-ef30-11b4-8396-4cbd8fcf2330 as CAM Device.
2017-12-04 08:18:35 DEBUG (SyncWorker_10) [pyhik.hikvision] Found events: {'VMD': [1], 'tamperdetection': [1], 'linedetection': [1], 'fielddetection': [1], 'facedetection': [1], 'unattendedBaggage': [1], 'attendedBaggage': [1]}
2017-12-04 08:18:35 WARNING (SyncWorker_10) [pyhik.hikvision] Sensor type "unattendedBaggage" is unsupported.
2017-12-04 08:18:35 WARNING (SyncWorker_10) [pyhik.hikvision] Sensor type "attendedBaggage" is unsupported.
2017-12-04 08:18:35 DEBUG (SyncWorker_10) [pyhik.hikvision] Initialized Dictionary: {'Motion': [[False, 1, 0, datetime.datetime(2017, 12, 4, 8, 18, 35, 983325)]], 'Tamper Detection': [[False, 1, 0, datetime.datetime(2017, 12, 4, 8, 18, 35, 983330)]], 'Line Crossing': [[False, 1, 0, datetime.datetime(2017, 12, 4, 8, 18, 35, 983331)]], 'Field Detection': [[False, 1, 0, datetime.datetime(2017, 12, 4, 8, 18, 35, 983333)]], 'Face Detection': [[False, 1, 0, datetime.datetime(2017, 12, 4, 8, 18, 35, 983334)]]}
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [homeassistant.components.binary_sensor.hikvision] Entity: Driveway - Motion, Options - Ignore: None, Delay: None
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of <Entity Driveway Motion: off>> on 5c137e18-ef30-11b4-8396-4cbd8fcf2330.Motion.1
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [homeassistant.components.binary_sensor.hikvision] Entity: Driveway - Tamper_Detection, Options - Ignore: None, Delay: None
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of <Entity Driveway Tamper Detection: off>> on 5c137e18-ef30-11b4-8396-4cbd8fcf2330.Tamper Detection.1
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [homeassistant.components.binary_sensor.hikvision] Entity: Driveway - Line_Crossing, Options - Ignore: None, Delay: None
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of <Entity Driveway Line Crossing: off>> on 5c137e18-ef30-11b4-8396-4cbd8fcf2330.Line Crossing.1
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [homeassistant.components.binary_sensor.hikvision] Entity: Driveway - Field_Detection, Options - Ignore: None, Delay: None
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of <Entity Driveway Field Detection: off>> on 5c137e18-ef30-11b4-8396-4cbd8fcf2330.Field Detection.1
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [homeassistant.components.binary_sensor.hikvision] Entity: Driveway - Face_Detection, Options - Ignore: None, Delay: None
2017-12-04 08:18:36 DEBUG (SyncWorker_10) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of <Entity Driveway Face Detection: off>> on 5c137e18-ef30-11b4-8396-4cbd8fcf2330.Face Detection.1
2017-12-04 08:18:44 WARNING (MainThread) [homeassistant.setup] Setup of media_player is taking over 10 seconds.
2017-12-04 08:18:46 WARNING (MainThread) [homeassistant.components.media_player] Setup of platform cast is taking over 10 seconds.
2017-12-04 08:18:53 DEBUG (Thread-3) [pyhik.hikvision] Stream Thread Started: Driveway, 5c137e18-ef30-11b4-8396-4cbd8fcf2330
2017-12-04 08:18:53 DEBUG (Thread-3) [pyhik.hikvision] Driveway Connection Successful.
2017-12-04 08:19:08 DEBUG (Thread-6) [pyhik.hikvision] Driveway Watchdog expired. Resetting connection.
2017-12-04 08:19:13 WARNING (Thread-3) [pyhik.hikvision] Driveway Connection Failed. Waiting 10s. Err: Watchdog failed, resetting connection.
2017-12-04 08:19:23 DEBUG (Thread-3) [pyhik.hikvision] Driveway Connection Successful.
Exception in thread Thread-3:
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/threading.py", line 916, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.6/threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.6/site-packages/pyhik/hikvision.py", line 378, in alert_stream
    tree = ET.fromstring(parse_string)
  File "/usr/local/lib/python3.6/xml/etree/ElementTree.py", line 1315, in XML
    return parser.close()
  File "<string>", line None
xml.etree.ElementTree.ParseError: no element found: line 1, column 430

2017-12-04 08:19:38 DEBUG (Thread-7) [pyhik.hikvision] Driveway Watchdog expired. Resetting connection.
2017-12-04 08:20:08 DEBUG (SyncWorker_6) [pyhik.hikvision] Disconnecting from stream: Driveway
2017-12-04 08:20:08 DEBUG (SyncWorker_6) [pyhik.hikvision] Event stream thread for Driveway is stopped
2017-12-04 08:20:08 WARNING (MainThread) [aiohttp.websocket] websocket connection is closing.
2017-12-04 08:20:08 WARNING (MainThread) [aiohttp.websocket] websocket connection is closing.

I too get a stream of videoloss events, but they do happen a second or two after. I don't remember exactly how frequently. I was just thinking if you wanted a more instant response, not that a second or two is really that big of deal.

It would be nice of the content length was correct. I guess if the root element was unique, you could read until the end element. You'd have to use expressions or just string matching. Seems like a kludge just to pick up the second or two.

FYI, I don't think I'll use it in HA, but this camera does support unattended and left baggage.

2017-12-04 08:18:35 WARNING (SyncWorker_10) [pyhik.hikvision] Sensor type "unattendedBaggage" is unsupported.
2017-12-04 08:18:35 WARNING (SyncWorker_10) [pyhik.hikvision] Sensor type "attendedBaggage" is unsupported.

[Laphroa1g]

I have a DS-2CD2342WD-I and this feature worked perfectly for months until I upgraded the camera to 5.5.0 build 170725 firmware version. It now does not receiver a single notification. Hikvision increased the security on the cameras in this 5.5.0 version and there are now web config menu options on the camera for features like RTSP Authentication and Web Authentication, where you have to choose between "digest and basic/digest" I have selected the latter, but I think that is not the issue because the logs show that HA is getting reports on the types of alarms enabled.

I'm not sure if I have the same issue as RandellHodges, but perhaps his new camera is also running 5.5.0?

I have pasted some logs from just after I restarted HA below. I am now running v0.59.0. If there is any other logs I can get to help please let me know.

2017-12-04 20:39:06 DEBUG (Thread-18) [pyhik.hikvision] Initializing new hikvision device at: http://192.168.0.16
2017-12-04 20:39:06 DEBUG (Thread-18) [pyhik.hikvision] Using Namespace: http://www.hikvision.com/ver20/XMLSchema
2017-12-04 20:39:06 DEBUG (Thread-18) [pyhik.hikvision] Processed 62b62c0c-4020-11b5-83fd-a4143770f88f as CAM Device.
2017-12-04 20:39:06 DEBUG (Thread-18) [pyhik.hikvision] Found events: {'VMD': [1], 'fielddetection': [1]}
2017-12-04 20:39:06 DEBUG (Thread-18) [pyhik.hikvision] Initialized Dictionary: {'Field Detection': [[False, 1, 0, datetime.datetime(2017, 12, 4, 20, 39, 6, 667804)]], 'Motion': [[False, 1, 0, datetime.datetime(2017, 12, 4, 20, 39, 6, 667796)]]}
2017-12-04 20:39:06 DEBUG (Thread-18) [homeassistant.components.binary_sensor.hikvision] Entity: Front Camera - Field_Detection, Options - Ignore: None, Delay: None
2017-12-04 20:39:06 DEBUG (Thread-18) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of > on 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-04 20:39:06 DEBUG (Thread-18) [homeassistant.components.binary_sensor.hikvision] Entity: Front Camera - Motion, Options - Ignore: None, Delay: None
2017-12-04 20:39:06 DEBUG (Thread-18) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of > on 62b62c0c-4020-11b5-83fd-a4143770f88f.Motion.1
2017-12-04 20:39:25 DEBUG (Thread-23) [pyhik.hikvision] Stream Thread Started: Front, 62b62c0c-4020-11b5-83fd-a4143770f88f
2017-12-04 20:39:25 DEBUG (Thread-23) [pyhik.hikvision] Front Connection Successful.
2017-12-04 20:39:40 DEBUG (Thread-37) [pyhik.hikvision] Front Watchdog expired. Resetting connection.
2017-12-04 20:39:44 WARNING (Thread-23) [pyhik.hikvision] Front Connection Failed. Waiting 10s. Err: Watchdog failed, resetting connection.
2017-12-04 20:39:54 DEBUG (Thread-23) [pyhik.hikvision] Front Connection Successful.
2017-12-04 20:40:09 DEBUG (Thread-39) [pyhik.hikvision] Front Watchdog expired. Resetting connection.

[mezz64]

@randellhodges Can you provide your firmware version? I've had reports from others with 5.5.0 having issues also.

If either of you run a curl on the event stream url do you receive a continuous stream of events or are there longer pauses, greater than 15s? The logs show the watchdog being triggered which uses the videoloss events to ensure the connection is kept alive, it seems like firmware 5.5.0 may have changed this behavior.

[randellhodges]

Version: V5.5.0 build 170725

It is a little hard notice a change curling the stream. I believe I was seeing them around 10 seconds. I saw one at 20 seconds, but it could be that I didn't notice the one before that.

[mezz64]

Ok, I think the problem may just be a combination of too strict a watchdog interval and a failure to clear the parse string variable after a disconnect.

I'll make the changes and push a new version to pypi for you to test out.

[mezz64]

Version 0.1.5 is now on pypi. You both can test by manually editing the hikvision.py file in your homeassistant\components\binary_sensor directory to point to the new version and restarting HASS.

[randellhodges]

I think that is working. I no longer see errors during startup. I see the binary sensors for the camera including the 2 new ones. I'll keep an eye on it and see if it starts acting up.

Edit: Not to be a nag, but I wonder, if these boundary are used for detecting the end of an event, I guess in an edge case, it could be 10 seconds or so to detect an event. With the Content-Length being flaky, the only other thing I can think of would be bit hack. :(

[mezz64]

I'll do some testing on trying the content-length instead of the boundary as end detection. If new firmware's are reducing the videoloss event frequency a 10s lag is definitely not a great option.

[mezz64]

Code has been changed to use the closing tag of the event notification to know when the event message is over. It's an easy fix that should fix your problem and it likely should have been that way in the first place anyway.

Changes are pushed to pypi as 0.1.6. Please test is out and let me know if it removes your lag and i'll submit a PR to HASS to bump the library version.

[Laphroa1g]

This is only working intermittently for me. I noticed that the camera sent me an email during the night, for an Intrusion detection, but Hass had not triggered anything. Debug pasted below, from when had last restarted Hass.

~$ cat /home/hass/.homeassistant/home-assistant.log
2017-12-09 15:28:09 DEBUG (Thread-3) [pyhik.hikvision] Initializing new hikvision device at: http://192.168.0.16
2017-12-09 15:28:09 DEBUG (Thread-3) [pyhik.hikvision] Using Namespace: http://www.hikvision.com/ver20/XMLSchema
2017-12-09 15:28:09 DEBUG (Thread-3) [pyhik.hikvision] Processed 62b62c0c-4020-11b5-83fd-a4143770f88f as CAM Device.
2017-12-09 15:28:09 DEBUG (Thread-3) [pyhik.hikvision] Found events: {'fielddetection': [1], 'VMD': [1]}
2017-12-09 15:28:09 DEBUG (Thread-3) [pyhik.hikvision] Initialized Dictionary: {'Field Detection': [[False, 1, 0, datetime.datetime(2017, 12, 9, 15, 28, 9, 531426)]], 'Motion': [[False, 1, 0, datetime.datetime(2017, 12, 9, 15, 28, 9, 531434)]]}
2017-12-09 15:28:09 DEBUG (Thread-3) [homeassistant.components.binary_sensor.hikvision] Entity: Front Camera - Field_Detection, Options - Ignore: None, Delay: None
2017-12-09 15:28:09 DEBUG (Thread-3) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of > on 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-09 15:28:09 DEBUG (Thread-3) [homeassistant.components.binary_sensor.hikvision] Entity: Front Camera - Motion, Options - Ignore: None, Delay: None
2017-12-09 15:28:09 DEBUG (Thread-3) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of > on 62b62c0c-4020-11b5-83fd-a4143770f88f.Motion.1
2017-12-09 15:28:27 DEBUG (Thread-23) [pyhik.hikvision] Stream Thread Started: Front, 62b62c0c-4020-11b5-83fd-a4143770f88f
2017-12-09 15:28:27 DEBUG (Thread-23) [pyhik.hikvision] Front Connection Successful.
2017-12-09 15:29:17 DEBUG (Thread-39) [pyhik.hikvision] Front Watchdog expired. Resetting connection.
2017-12-09 15:29:24 WARNING (Thread-23) [pyhik.hikvision] Front Connection Failed. Waiting 10s. Err: Watchdog failed, resetting connection.
2017-12-09 15:29:34 DEBUG (Thread-23) [pyhik.hikvision] Front Connection Successful.
2017-12-09 15:30:04 DEBUG (Thread-40) [pyhik.hikvision] Front Watchdog expired. Resetting connection.

I've just restarted Hass again and it says connection succesful.

:~$ cat /home/hass/.homeassistant/home-assistant.log
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Initializing new hikvision device at: http://192.168.0.16
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Using Namespace: http://www.hikvision.com/ver20/XMLSchema
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Processed 62b62c0c-4020-11b5-83fd-a4143770f88f as CAM Device.
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Found events: {'VMD': [1], 'fielddetection': [1]}
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Initialized Dictionary: {'Field Detection': [[False, 1, 0, datetime.datetime(2017, 12, 10, 10, 51, 2, 755186)]], 'Motion': [[False, 1, 0, datetime.datetime(2017, 12, 10, 10, 51, 2, 755178)]]}
2017-12-10 10:51:02 DEBUG (Thread-21) [homeassistant.components.binary_sensor.hikvision] Entity: Front Camera - Field_Detection, Options - Ignore: None, Delay: None
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of > on 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 10:51:02 DEBUG (Thread-21) [homeassistant.components.binary_sensor.hikvision] Entity: Front Camera - Motion, Options - Ignore: None, Delay: None
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of > on 62b62c0c-4020-11b5-83fd-a4143770f88f.Motion.1
2017-12-10 10:51:23 DEBUG (Thread-23) [pyhik.hikvision] Stream Thread Started: Front, 62b62c0c-4020-11b5-83fd-a4143770f88f
2017-12-10 10:51:23 DEBUG (Thread-23) [pyhik.hikvision] Front Connection Successful.

[mezz64]

@Laphroa1g Can you run a curl on your event stream and give me a ballpark on how frequently you see videoloss events? In old firmware's these events were constantly emitted when the stream was active so I was using them as a way to make sure the connection stayed alive. This behavior seems to have changed in the new firmware's.

[Laphroa1g]

I am getting this every 10 seconds.

<EventNotificationAlert version="2.0" xmlns="http://www.hikvision.com/ver20/XMLSchema"> <ipAddress>192.168.0.16</ipAddress> <portNo>80</portNo> <protocol>HTTP</protocol> <macAddress>a4:14:37:12:34:56</macAddress> <channelID>1</channelID> <dateTime>2017-12-11T22:21:47+00:00</dateTime> <activePostCount>0</activePostCount> <eventType>videoloss</eventType> <eventState>inactive</eventState> <eventDescription>videoloss alarm</eventDescription> <channelName>Front</channelName> </EventNotificationAlert> --boundary Content-Type: application/xml; charset="UTF-8" Content-Length: 514

It was working yesterday and then stopped. Last trigger I got to Hass was at 12:33, then there is the Watchdog failed logged at 13:48, and there were no further intrusion detections between these times. Log below, just in case it helps:

:~$ cat /home/hass/.homeassistant/home-assistant.log
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Initializing new hikvision device at: http://192.168.0.16
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Using Namespace: http://www.hikvision.com/ver20/XMLSchema
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Processed 62b62c0c-4020-11b5-83fd-a4143770f88f as CAM Device.
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Found events: {'VMD': [1], 'fielddetection': [1]}
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Initialized Dictionary: {'Field Detection': [[False, 1, 0, datetime.datetime(2017, 12, 10, 10, 51, 2, 755186)]], 'Motion': [[False, 1, 0, datetime.datetime(2017, 12, 10, 10, 51, 2, 755178)]]}
2017-12-10 10:51:02 DEBUG (Thread-21) [homeassistant.components.binary_sensor.hikvision] Entity: Front Camera - Field_Detection, Options - Ignore: None, Delay: None
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of > on 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 10:51:02 DEBUG (Thread-21) [homeassistant.components.binary_sensor.hikvision] Entity: Front Camera - Motion, Options - Ignore: None, Delay: None
2017-12-10 10:51:02 DEBUG (Thread-21) [pyhik.hikvision] Added update callback to <bound method HikvisionBinarySensor._update_callback of > on 62b62c0c-4020-11b5-83fd-a4143770f88f.Motion.1
2017-12-10 10:51:23 DEBUG (Thread-23) [pyhik.hikvision] Stream Thread Started: Front, 62b62c0c-4020-11b5-83fd-a4143770f88f
2017-12-10 10:51:23 DEBUG (Thread-23) [pyhik.hikvision] Front Connection Successful.
2017-12-10 11:56:04 DEBUG (Thread-23) [pyhik.hikvision] Front Update: Field Detection, [True, 1, 1, datetime.datetime(2017, 12, 10, 11, 56, 4, 841915)]
2017-12-10 11:56:04 DEBUG (Thread-23) [pyhik.hikvision] Update callback <bound method HikvisionBinarySensor._update_callback of > for sensor 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 11:56:04 DEBUG (Thread-23) [homeassistant.components.binary_sensor.hikvision] Callback signal from: 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 11:56:29 DEBUG (Thread-23) [pyhik.hikvision] Updating stale event Field Detection on CH(1)
2017-12-10 11:56:29 DEBUG (Thread-23) [pyhik.hikvision] Front Update: Field Detection, [False, 1, 17, datetime.datetime(2017, 12, 10, 11, 56, 29, 160346)]
2017-12-10 11:56:29 DEBUG (Thread-23) [pyhik.hikvision] Update callback <bound method HikvisionBinarySensor._update_callback of > for sensor 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 11:56:29 DEBUG (Thread-23) [homeassistant.components.binary_sensor.hikvision] Callback signal from: 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 12:32:55 DEBUG (Thread-23) [pyhik.hikvision] Front Update: Field Detection, [True, 1, 18, datetime.datetime(2017, 12, 10, 12, 32, 55, 106677)]
2017-12-10 12:32:55 DEBUG (Thread-23) [pyhik.hikvision] Update callback <bound method HikvisionBinarySensor._update_callback of > for sensor 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 12:32:55 DEBUG (Thread-23) [homeassistant.components.binary_sensor.hikvision] Callback signal from: 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 12:33:19 DEBUG (Thread-23) [pyhik.hikvision] Updating stale event Field Detection on CH(1)
2017-12-10 12:33:19 DEBUG (Thread-23) [pyhik.hikvision] Front Update: Field Detection, [False, 1, 34, datetime.datetime(2017, 12, 10, 12, 33, 19, 428965)]
2017-12-10 12:33:19 DEBUG (Thread-23) [pyhik.hikvision] Update callback <bound method HikvisionBinarySensor._update_callback of > for sensor 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 12:33:19 DEBUG (Thread-23) [homeassistant.components.binary_sensor.hikvision] Callback signal from: 62b62c0c-4020-11b5-83fd-a4143770f88f.Field Detection.1
2017-12-10 13:48:46 DEBUG (Thread-1140) [pyhik.hikvision] Front Watchdog expired. Resetting connection.
2017-12-10 13:49:22 WARNING (Thread-23) [pyhik.hikvision] Front Connection Failed. Waiting 10s. Err: Watchdog failed, resetting connection.
2017-12-10 13:49:32 DEBUG (Thread-23) [pyhik.hikvision] Front Connection Successful.
2017-12-10 13:50:02 DEBUG (Thread-1141) [pyhik.hikvision] Front Watchdog expired. Resetting connection.

[mezz64]

Does the connect - watchdog failed - resetting connection pattern continue to repeat or did it stop on the last line shown in the posted log?

[Laphroa1g]

Looking at the logs from last night it failed, reconnected 10 seconds later then failed and did not re-connect again, and there are no more logs for the last 6 hours.

2017-12-12 02:01:43 DEBUG (Thread-1386) [pyhik.hikvision] Front Watchdog expired. Resetting connection.
2017-12-12 02:01:50 WARNING (Thread-23) [pyhik.hikvision] Front Connection Failed. Waiting 10s. Err: Watchdog failed, resetting connection.
2017-12-12 02:02:00 DEBUG (Thread-23) [pyhik.hikvision] Front Connection Successful.
2017-12-12 02:02:30 DEBUG (Thread-1387) [pyhik.hikvision] Front Watchdog expired. Resetting connection.

[mezz64]

This looks like it's going to be tricky to track down. There are at least two things happening that shouldn't be, and I can't see any reason why.

• If you see videoloss events every 10s, the watchdog should never trigger.
• I can't figure out why the reconnect logic would get stuck the second time around since the same process is repeated from the initial disconnect.

If you're able to edit the pyhik library files something worth trying would be to increase the watchdog seconds on line 73 of the hikvision.py file to something much longer, like this:
self.watchdog = Watchdog(600.0, self.watchdog_handler)

If there is an issue with the connection to the camera this should still trigger, but we'll know for sure it's a connection problem and not an overactive watchdog process.

[Laphroa1g]

I made the change as suggested and set the Watchdog to 600, and the intrusion detection has now worked for the last 24 hours.
I set up "- platform: ping" in device manager to ping this camera and it has not stopped pinging once.

I have however noticed the following in the logs when you select Info under Developer Tools in the Hass frontend.

Error doing job: Fatal read error on socket transport
12:49 AM /srv/hass/lib/python3.5/site-packages/homeassistant/core.py (ERROR)
Failed to connect, retrying in 5.0s
12:14 AM /srv/hass/lib/python3.5/site-packages/pychromecast/socket_client.py (ERROR)
Error communicating with socket, resetting connection
12:14 AM /srv/hass/lib/python3.5/site-packages/pychromecast/socket_client.py (WARNING)
Error reading from socket.
12:14 AM /srv/hass/lib/python3.5/site-packages/pychromecast/socket_client.py (ERROR)

[mezz64]

That's great news on the watchdog, i'm thinking i'll up the default setting to 5min. That should be long enough to cover gaps in the stream, yet not too long to catch a disconnect in a reasonable amount of time.

It still means there is an issue in the reconnect logic though, i'll have to go through it again and ensure the thread flags are working correctly.

As to your other log errors, I think the pychromecast socket timeouts are fairly typical and don't necessarily point to any general network or connection issues. I see them occasionally myself.

[mezz64]

I've made some changes that hopefully clear up these issues for you both. Please update to version 0.1.7 and let me know if you run into any issues. If all ends up OK i'll pass the changes along to HASS.

[testermax]

Looking foward to this update to home assistant....pretty sure this is the reason I cant use the hikvision binary sensors for more than a day or so.
Good work :-)

[Laphroa1g]

It worked for over 24 hours then it expired again last night.

2017-12-21 01:29:24 DEBUG (Thread-10661) [pyhik.hikvision] Front Watchdog expired. Resetting connection.

[mezz64]

Looks like I need to rethink the reconnect logic. I've been busy with other things lately but will look at it as soon as I get a chance.

[ajhodges]

I'm not a user (yet) and am just browsing through the codebase for funsies, but it seems to me that you could possibly reduce some of the complexity of the reconnect/watchdog stuff by using something like this:
http://urllib3.readthedocs.io/en/latest/reference/urllib3.util.html#urllib3.util.retry.Retry
Relevant blog: https://www.peterbe.com/plog/best-practice-with-retries-with-requests

I'm not sure how well that plays with streaming but I haven't found anything to suggest that it wouldn't work.

Just a thought. Thanks for putting together this library - I just got a Hikvision doorbell and am hoping to be able to contribute to add the doorbell event to this!

[mezz64]

Thanks for the suggestion @ajhodges that method is definitely worth a shot. The original reason for the watchdog was sometimes in my testing the connection would remain active, but the stream would stop. I'm not sure that method would catch that scenario, but maybe I can combine the two.

[flamingm0e]

I have spent a couple of days trying to track down why my newest camera was not sending any events. Now I see why. It's not my Home Assistant going crazy on me. It was the stupid newer firmware. Glad I didn't upgrade the other cameras. This one just happened to come with V5.5.0 build 170725

The current version of Home Assistant is still running pyHik 0.1.4 also, so I assume we will need to get a PR put in if a fix is found.

[flamingm0e]

I am not sure what changed in 0.63.1 Home Assistant, but as of this morning, I am getting alerts from the camera with the updated firmware, and last night noticed some motion detection alerts in the logs.

It appears HASS is still using 0.1.4 also, so that seems strange to me.

[randellhodges]

I was still having this problem this morning with this camera. I found that I only had digest and not digest/basic for the security. I don't remember if this was the original problem or not. I know that, as of now, with all the cameras I am using, I no longer have this issue.

However, I have one of the doorbell cameras that I haven't yet hooked up, the DS-KB6003-WIP, which is a rebranded/firmwared Clare camera. I find no options, yet, to control the security and with postman it only connects with I select DIGEST.

Any way to add support for digest authentication? I'll put this request as a new issue later.

[ajhodges]

Hey @randellhodges, let me know if you have any better luck with the doorbell cam. Here's the issue I was seeing: #16

[randellhodges]

@ajhodges I haven't even connected it to HA yet. I was assuming that it wouldn't even connect since it appeared to require digest authentication.

I'm guessing we'll have to wait until they (hikvision) supports more of the standard API in their firmware, or we'll have to have special logic just for that camera.

I'll read more on that issue.

[flamingm0e]

so weird. after working for 2 days, it's broken again.

[AhSem]

I hit the similar issue as reported, xml.etree.ElementTree.ParseError: no element found: and after some debugging, I am pretty sure it was caused by these lines in the returned xml (alert stream)

--boundary
Content-Type: application/xml; charset="UTF-8"
Content-Length: 516

So what I did was change the following lines (line 388 to line 395 in hikvision.py) from:

if line:
    str_line = line.decode("utf-8")
    # New events start with --boundry
    if str_line.find('Content-Length') != -1:
        # Start of event message
        start_event = True
    elif str_line.find('</EventNotificationAlert>') != -1:
        # Message end found found

to

if line:
    **str_line = line.decode("utf-8", "ignore")**
    # New events start with --boundry
    **if str_line.find('<EventNotificationAlert') != -1:**
        # Start of event message
        start_event = True
        **parse_string += str_line**
    elif str_line.find('</EventNotificationAlert>') != -1:
        # Message end found found

What it does is actually looking for tag as start of event. Also, note that I have added "ignore" in line.decode("utf-8"). The reason is that for some unknown reason, I will hit decode error when there is event returned by the camera.

*Notes: after some experiments with different NVRs and Cameras, I can tell that different devices actually return different types of results. The ISAPI doesn't seem to be complete yet, and I believe long to go. The camera I was working with is Deep In View Thermal camera, which is relatively new.

[mezz64]

Please post a full sample from your alertstream. You seem to have the Content-Length tag so it should be a valid starting point. I'd also like to see what is being returned that would cause a decode error.

[AhSem]

--boundary
Content-Type: application/xml; charset="UTF-8"
Content-Length: 524
<EventNotificationAlert version="2.0" xmlns="http://www.hikvision.com/ver20/XMLSchema">
<ipAddress>172.26.248.216</ipAddress>
<portNo>80</portNo>
<protocol>HTTP</protocol>
<macAddress>a4:14:37:80:54:7c</macAddress>
<channelID>1</channelID>
<dateTime>2018-07-04T15:01:23+08:00</dateTime>
<activePostCount>0</activePostCount>
<eventType>videoloss</eventType>
<eventState>inactive</eventState>
<eventDescription>videoloss alarm</eventDescription>
<channelName>  Thermal_B_1</channelName>
</EventNotificationAlert>

[AhSem]

The original logic to start reading line after "Content-Length" should be correct. But when I did a simple print(str_line), I noticed the device emitted some machine codes (should be due to the encoding).

I think this is the reason we hit the xml element error.

• The device I try is using Firmware v5.5. I think previous version might not have the problem.

[AhSem]

Just want to share more information, the device's alert stream emits message in JSON as well. So if we start reading after Content-Length, it will hit error when trying to parse the message as XML format.

[ozett]

Just want to share more information, the device's alert stream emits message in JSON as well. So if we start reading after Content-Length, it will hit error when trying to parse the message as XML format.

how to get json? specificy URL?
would like some help, dont see how to get it... thx