fwestenberg / reolink_dev

Home Assistant Reolink addon
MIT License
550 stars 102 forks source link

Home Assistant error: "Host 192.168.110.xxx error renewing the Reolink subscription" #550

Open rainbowbreeze opened 2 years ago

rainbowbreeze commented 2 years ago

Describe the bug I've 4 Reolink RLC-811A connected directly to my LAN (no NVR). 192.168.110.121, .122, .124, .125 All the four cameras have the same firmware version, and configurations I've configured all of them under HA using the reolink_dev custom integration

For two of them the following error continues to pop up in HA logs

Host 192.168.110.124 error renewing the Reolink subscription
Host 192.168.110.122 error renewing the Reolink subscription

I removed the cameras, and re-added them, and I get the same error. Interestingly enough, .121 and .125 don't show the error.

Environment: Please provide useful information about your environment, like:

Additional context Here the debug logs from HA with the error happens (username and pwd obscured):

2022-08-15 15:55:24.109 DEBUG (MainThread) [reolink.subscription_manager] Host 192.168.110.124: Connection error Cannot connect to host 192.168.110.124:8000 ssl:default [Connect call failed ('192.168.110.124', 8000)]
2022-08-15 15:55:24.109 ERROR (MainThread) [custom_components.reolink_dev.base] Host 192.168.110.124 error renewing the Reolink subscription
2022-08-15 15:55:24.113 DEBUG (MainThread) [reolink.subscription_manager] Reolink host 192.168.110.124 (Subscription) request data:
<soap:Envelope xmlns:add="http://www.w3.org/2005/08/addressing" xmlns:b="http://docs.oasis-open.org/wsn/b-2" xmlns:soap="http://www.w3.org/2003/05/soap-envelope">
<soap:Header><wsse:Security soap:mustUnderstand="true" xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd"
xmlns:wsu="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd">
<wsse:UsernameToken wsu:Id="UsernameToken-3839ddc1-4bf7-4ae8-a24d-4fc09e707dd6">
<wsse:Username>XXXXXXXXX</wsse:Username>
<wsse:Password Type="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-username-token-profile-1.0#PasswordDigest">XXXXXXXXX</wsse:Password>
<wsse:Nonce EncodingType="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-soap-message-security-1.0#Base64Binary">X21BCn+NQzufUwa4LPr+wQ==</wsse:Nonce>
<wsu:Created>2022-08-15T13:55:24.000Z</wsu:Created>
</wsse:UsernameToken>
</wsse:Security>
</soap:Header>
<soap:Body>
<b:Subscribe>
<b:ConsumerReference>
<add:Address>http://192.168.100.6:8123/api/webhook/84118dfcafa7b202eaaeba6c5dc8b5b19a2b65d3ba6a5f1d1157a4e234122e91</add:Address>
</b:ConsumerReference>
<b:InitialTerminationTime>PT15M</b:InitialTerminationTime>
</b:Subscribe>
</soap:Body>
</soap:Envelope>
2022-08-15 15:55:24.119 DEBUG (MainThread) [reolink.subscription_manager] Host 192.168.110.122: Connection error Cannot connect to host 192.168.110.122:8000 ssl:default [Connect call failed ('192.168.110.122', 8000)]
2022-08-15 15:55:24.120 ERROR (MainThread) [custom_components.reolink_dev.base] Host 192.168.110.122 error renewing the Reolink subscription
2022-08-15 15:55:24.125 DEBUG (MainThread) [reolink.subscription_manager] Reolink host 192.168.110.122 (Subscription) request data:
<soap:Envelope xmlns:add="http://www.w3.org/2005/08/addressing" xmlns:b="http://docs.oasis-open.org/wsn/b-2" xmlns:soap="http://www.w3.org/2003/05/soap-envelope">
<soap:Header><wsse:Security soap:mustUnderstand="true" xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd"
xmlns:wsu="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd">
<wsse:UsernameToken wsu:Id="UsernameToken-c7d3f96f-9919-44b3-9a9c-a026fe7f6a0f">
<wsse:Username>XXXXXXXXX</wsse:Username>
<wsse:Password Type="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-username-token-profile-1.0#PasswordDigest">XXXXXXXXX</wsse:Password>
<wsse:Nonce EncodingType="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-soap-message-security-1.0#Base64Binary">/Jiu5g5UQCCNabTVLzTKwg==</wsse:Nonce>
<wsu:Created>2022-08-15T13:55:24.000Z</wsu:Created>
</wsse:UsernameToken>
</wsse:Security>
</soap:Header>
<soap:Body>
<b:Subscribe>
<b:ConsumerReference>
<add:Address>http://192.168.100.6:8123/api/webhook/4ac8c0a4c42b2841ff18f2cd9eb77344463a90dfc62ea073fc060174a64229e5</add:Address>
</b:ConsumerReference>
<b:InitialTerminationTime>PT15M</b:InitialTerminationTime>
</b:Subscribe>
</soap:Body>
</soap:Envelope>
2022-08-15 15:55:24.131 DEBUG (MainThread) [reolink.subscription_manager] Host 192.168.110.124: Connection error Cannot connect to host 192.168.110.124:8000 ssl:default [Connect call failed ('192.168.110.124', 8000)]
2022-08-15 15:55:24.160 DEBUG (MainThread) [reolink.subscription_manager] Host 192.168.110.122: Connection error Cannot connect to host 192.168.110.122:8000 ssl:default [Connect call failed ('192.168.110.122', 8000)]

Happy to provide additional debug info if needed.

rainbowbreeze commented 2 years ago

I also saw there is a very long standing ussue similar to mine, with issue #110 , but in that issue people have a mix of NVR and direct connected cameras. In my case, I've no NVR at all.

GewoonRoy commented 2 years ago

I see you are using firmware v3.1.0.956 for the cameras. Just to check and you probably already checked it yourself but do you have the ports open for ONVIF for all cameras?

I also have the error Host 192.168.110.122 error renewing the Reolink subscription with firmware v3.1.0.956. I downgraded the firmware on the camera but it something you don't really want. Any help from others is appreciated with the error "renewing the Reolink subscription". I thought the error message could have something to do with the SSL certificate but i could be totally wrong here.

Electronlibre2012 commented 2 years ago

hello, same problem here, i have a nvr410 and 4 cameras, i read several post and decide to uninstall/install again without https and ssl certificat as it is mention in the doc, no change, still the same error and seems my motions sensor in ha doesnt work anymore.

No response from the dev? @fwestenberg is there something we can do for you to solve this please? which logs do you need? thanks

EDIT : sorry...my bad...i have not activate "ONVIF" after update of the NVR...it works now EDIT2 : crash again, no more motion sensor working

EDIT3 : integrate my cameras with https enable and port 443, work like a charm without errors...................

LAST EDIT : after 4 hours...no more sensors working...

EDIT 19/08/2022 : it seems that rename the motion sensors entities in HA (i have 6 camera now on the NVR) cause problems. I rename them in the NVR and redo HACS AddOn and Integration in HA and it works. NVR Just disconnect every 3-5 hours or reboot i dont know, cant see anything in the NVR logs or in HA, just motions sensors "unavailable" for 2 minutes, and 2 minutes is the time to reboot the NVR...perhaps i am wrong.

Electronlibre2012 commented 2 years ago

Hello,

last update of NVR 410 as a new https option :

image

is someone know if it will be helpfull to put the homeassistant certificate?

leroyloren commented 2 years ago

I've been seeing this behavior for a long time as well, I've noticed it happens every hour, probably some token expiration from the camera side?

obrazek 2022-08-17 16:35:28.051 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-08-17 16:35:28.106 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-08-17 16:35:28.114 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription 2022-08-17 17:00:41.044 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-08-17 17:00:41.119 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-08-17 17:00:41.126 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription 2022-08-17 17:25:58.058 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-08-17 17:25:58.111 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-08-17 17:25:58.118 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription 2022-08-17 17:36:03.131 ERROR (MainThread) [custom_components.reolink_dev] Unexpected error fetching reolink.Prijezd data: Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 205, in _async_refresh self.data = await self._async_update_data() File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 164, in _async_update_data return await self.update_method() File "/config/custom_components/reolink_dev/__init__.py", line 98, in async_update_data await base.update_states() File "/config/custom_components/reolink_dev/base.py", line 256, in update_states await self._api.get_states() File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 460, in get_states response = await self.send(body) File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 1721, in send raise CredentialsInvalidError() reolink.exceptions.CredentialsInvalidError

radimnemecek commented 2 years ago

I've been seeing this behavior for a long time as well, I've noticed it happens every hour, probably some token expiration from the camera side?

obrazek

`2022-08-17 16:35:28.051 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request

2022-08-17 16:35:28.106 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request

2022-08-17 16:35:28.114 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription

2022-08-17 17:00:41.044 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request

2022-08-17 17:00:41.119 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request

2022-08-17 17:00:41.126 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription

2022-08-17 17:25:58.058 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request

2022-08-17 17:25:58.111 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request

2022-08-17 17:25:58.118 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription

2022-08-17 17:36:03.131 ERROR (MainThread) [custom_components.reolink_dev] Unexpected error fetching reolink.Prijezd data:

Traceback (most recent call last):

File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 205, in _async_refresh

self.data = await self._async_update_data()

File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 164, in _async_update_data

return await self.update_method()

File "/config/custom_components/reolink_dev/init.py", line 98, in async_update_data

await base.update_states()

File "/config/custom_components/reolink_dev/base.py", line 256, in update_states

await self._api.get_states()

File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 460, in get_states

response = await self.send(body)

File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 1721, in send

raise CredentialsInvalidError()

reolink.exceptions.CredentialsInvalidError`

I have the same problem. Every hour, the camera is temporarily unavailable. I have noticed this problem since version 2022.8. I've been using a Reolink camera for about half a year without a problem. I have model RLC-511, firmware v3.0.0.142_20121803.

Electronlibre2012 commented 2 years ago

@radaoggy hello, have you got a NVR or only cameras?

i have finally understand what happened to me : the NVR stop recording randomly ten or more a day, each time almost 2 minutes, so it means that there is a bug in the NVR or he is faulty...i have contacted the reolink support...wait and see, i give us the logs of the NVR...

Home Assistant is not the problem and reolink-dev either not! that the NVR...or a bug in the NVR software...i will come back here to give feedback

radimnemecek commented 2 years ago

Hi, I have only camera.

Electronlibre2012 commented 2 years ago

Hi, I have only camera.

thanks,

and for how long please?

for me it s exactly dead for 1 minute and exactly every 2 hours...too precise...its a token expiration like you said above...so strange its so precise and cyclic

sometimes it works for 4 hours without dead video or sensor but never more than 4 hours.

Sure its not related to HA and Reolink-dev, its a problem with cameras. I have 6 D520 and you, which model please? ok you notice that above RLC-511, firmware v3.0.0.142_20121803

JimStar commented 2 years ago

Same issue, with RLN8-410 NVR and four RLC-822A cameras (all four connected through this NVR). It constantly loses sensors to "Unavailable" state, and then back to "Clear" again, then all good for some time, getting "Detected" notifications, then "Unavailable" again and the cycle repeats... Without any precise timing-pattern in my case - sometimes every minute, sometimes half an hour... Using direct local IP address for HA, so DNS can't be a cause here.

Just installed the latest Reolink firmware to all cameras (v3.1.0.956_22041507 from May 20th 2022) and to NVR (v3.0.0.200_22081500 from August 17th 2022). No difference, still the same issue... Loses a lot of movement-events because of this, while direct Android push-notifications from the NVR itself to Reolink Android App come without losing any movement-events. So I still can not rely on notifications from Home Assistant in any important use-cases... but really would like to switch to HA for that...

Please feel free to let me know if you like me to test something specific on my end. I'll do my best to help you debug this...

Electronlibre2012 commented 2 years ago

Hello @JimStar ,

if you look at Reolink App , Android or PC, have you grey parts in timeline ? grey parts are no recording time so no sensors too... I think the problem is not in HA or in reolinkDev , the problem is the NVR stop recording and loose sensor, it takes 1mn for me every 2 or 3 hours, its time the NVR takes to reboot...

I have contacted Reolink support but they gived so many possibilities for resolves the problem, like HDD, the network, ect....

wait for your informations,

have a nice day

JimStar commented 2 years ago

Nope, no grey parts on the timeline, neither in Android nor in PC app (see the screenshot). And I have 24/7 recording enabled for all four cameras, so they record to the disk all the time no matter if there is movement detected or not.

BTW, maybe the precise time-periods you get could be somehow related to the "part size" setting of the Reolink NVR, which I suppose is a length of each file it creates when records non-stop (you can see these "chunks" above the timeline on my screenshot for example)... In this case the NVR should somehow seamlessly save a current chunk and start a new one... Maybe some interruption happens in that moment... But if that is the case - I would expect it would affect the push-notifications to Android too, but it sill never loses any movement-events in its Android App, it only happens in Home Assistant for me...

Screenshot_20220829-151416_Reolink

JimStar commented 2 years ago

The log is full of errors from reolink_dev.

Screen Shot 2022-08-29 at 17 45 36

This is the top-most one of this list for example, Python traceback. Let me know if you'd need logs in a text-form...

Screen Shot 2022-08-29 at 17 48 49
JimStar commented 2 years ago

... and the log is just full of those:

Screen Shot 2022-08-29 at 17 59 09
JimStar commented 2 years ago

...and more...

Screen Shot 2022-08-29 at 18 02 11
JimStar commented 2 years ago

I'm not sure so far (just a first quick look at this), but the tracebacks look like some Python errors on reolink_dev side, not on the NVR side...

JimStar commented 2 years ago

I see a lot of those:

Screen Shot 2022-08-29 at 18 17 31

Looks like some empty or broken Json response is returned by Reolink NVR to the calling Reolink-Python code. And the Reolink code just blindly passes this broken response to json.loads(response) which in turn stumbles on this Json... At least those are my first thoughts after quick look at this Reolink's get_all_motion_states() Python-API code:

Screen Shot 2022-08-29 at 19 03 23
JimStar commented 2 years ago

Another thought: I see that in the previous logs I posted here, the period of reolink_dev flooding the Reolink NVR with requests is like 40 milliseconds, at least this is the time-period I see between the warning-records of some "empty results"... Could it be that the NVR just gets over-flooded by network-requests (taking into account it needs to do a lot of other job besides answering to API requests), and just gives up with some responses or just sends back some broken responses sometimes... Just a quick assumption...

JimStar commented 2 years ago

It looks like in the Reolink-API's separate get_motion_state() call it is done properly in contrast to get_all_motion_states(): it first checks if the response is empty before passing it to json.loads(response). So in this case it would not fail with traceback in the logs. But this still could not be the main reason, maybe there are some more factors affecting these sensor losses (like possible over-flooding mentioned above)...

Screen Shot 2022-08-29 at 20 00 20

PS. Sorry for this shitload of a brainstorm in the ticket, but I'm really dedicated to get this finally fixed. ;)

JimStar commented 2 years ago

...and I see there is no proper exit with return value in the get_all_motion_states() and no call to clear_token() in the exception case... Could possibly the lack of clear_token() be the problem with motion-callbacks getting lost sometimes?.. Just a thought... So just to check it out I've changed the get_all_motion_states() to be similar to get_motion_state() with all the checks... Will see how it goes with this...

Screen Shot 2022-08-29 at 21 04 07
JimStar commented 2 years ago

Looks like my patch fixed this issue, at least partially. I don't see a shitload of errors and warnings every 40ms in the log anymore - at least for the 10 minutes I had before I left home to my work-office, and I did not see any "Unavailable" states of sensors anymore. And the log is clean of all the previous ton of messages from reolink_dev, so this patch definitely fixed at least these errors logged... There are still few errors logged by reolink_dev during start-up, and I will investigate them further after I'm back home. But so far I've already created a pull-request to the reolink Python package this reolink_dev depends on (you can see it mentioned by GitHub above).

The log is much cleaner now, at least for the 10 minutes I had in the morning to watch it... :) Cameras report movements properly and without any losses, I checked it several times walking in front of them... This is the full content of all the Home Assistant log, just a few lines with errors from reolink_dev during start-up and nothing else:

Screen Shot 2022-08-30 at 05 39 00
Electronlibre2012 commented 2 years ago

Wahoo! thats a brainstorming!

Dont be sorry, you are the first one who search and found something interesting...well done!

Where is this file please? im under HassOS dont sure i can modify...

JimStar commented 2 years ago

It is /usr/local/share/homeassistant/lib/python3.10/site-packages/reolink/camera_api.py (I run HA as a TrueNAS jail-plugin) but I think should be similar in HassOS too.

But if you patch this file in-place - don't forget to remove all the __pycache__ directories both under /usr/local/share/homeassistant/lib/python3.10/site-packages/reolink and <HA config dir>/custom_components/reolink_dev recursively, and then restart the Home Assistant. Otherwise either it'll not see your changes, or the component would not start properly.

JimStar commented 2 years ago

I will be able to have a look at the full-day logs of running HA with this patch only in about 3 hours - just finishing my workday soon and preparing to go long way home (I'm in NZ, so it's a middle of a day here). So I will let here know later today if the logs got same warnings/errors again from reolink_dev... or if the sensors experienced "Unavailable" state again during the day... But there was definitely a clear effect of my patch already seen in the morning in just 10 minutes of running the HA - because usually I got a shitload of warnings/errors in the logs from reolink_dev in 10 minutes... but after a patch it was just a few during start-up and then quiet... and all cameras' motion-detection working in HA without losses...

Electronlibre2012 commented 2 years ago

thanks @JimStar

today i notice that i have only 4 grey period yesterday in my time line...i do nothing for that... : first 6 hours, 2nd 4 hours, 3d after 5 hours, seems its no more periodicaly now...perhaps i will try to change the HDD...i reduce the the pack duration to 30mn to see if something changes...

I notice also that there is a lot of user for HA (192.168.1.50 is my HassOs Nuc) : image dont understand why there is a lot of same admin and IP, its an history log?

JimStar commented 2 years ago

OK, there is not even one "error renewing the Reolink subscription" record anymore in the whole log of the day. And my wife told me the whole day all the cameras notified her about all the people and vehicles around the house. I'm not sure though if she didn't notice some detection losses or there wasn't any...

But there is still a bunch of cryptic "Failed to get results for Search, JSON data was was empty?" records in the log. Plus I still see few "Unavailable" states of the sensors popping up during the day. So I will be investigating other issues further... I want this to be completely stable, so that I could trust those sensors...

JimStar commented 2 years ago

Yea, I can see that this "Failed to get results..." message is thrown by the send_search() function that really sends a network request to the NVR! And the fact that I see them with time period of 40 milliseconds! between them in the log means this code just spams the NVR device by a ton of network requests... making it some kind of a "deny of service" attack for the NVR... taking into account the NVR should still do a job of managing all the detections from cameras, collect and write all the streams into disk files, etc... Maybe this could be a reason NVR sometimes does not respond properly and the sensors become "Unavailable"... I will be checking this assumption now...

leroyloren commented 2 years ago

Just FYI, this behavior happens even without NVR, I have an 810A with the latest firmware.

cpainchaud commented 2 years ago

I have published 0.56 just now. For your information my cameras are crashing all day long since firmware 3.1+ so I am not sure to what extent these changes will really fix the issues.

JimStar commented 2 years ago

Thank you, @cpainchaud! No, this pull-request will definitely not fix the main issue, it just makes a log a little cleaner. ;)

I think I've just found some glue to what's happening... debugging it now... Will need some time to investigate this, I only have 1-2 hours in evenings for that... In short: two issues. One very simple (SOAP issue), one more complex (same reason as a reason of mess with camera/NVR names when there are more than one camera). But looks like both fixable on the reolink_dev side, at least I was just a couple of minutes ago able to get a completely stable subscription after some temporary changes in the code... Will be back with a pull-request as soon as I'm done with it (if all turns out to be doable of course). ;)

Electronlibre2012 commented 2 years ago

hello everybody,

@JimStar thanks for you effort to solved the problems, that will be great!

have a nice day

Electronlibre2012 commented 2 years ago

After 0.56 upgrade i have the following error, never seen before :

first one :

Logger: reolink.camera_api
Source: custom_components/reolink_dev/base.py:278
Integration: Reolink IP camera ([documentation](https://github.com/fwestenberg/reolink_dev), [issues](https://github.com/fwestenberg/reolink_dev/issues))
First occurred: 17:07:16 (73 occurrences)
Last logged: 17:11:09
Host: 192.168.1.174: Failed to get results for Search, JSON data was was empty?

second one:

Logger: homeassistant
Source: custom_components/reolink_dev/base.py:533
Integration: Reolink IP camera ([documentation](https://github.com/fwestenberg/reolink_dev), [issues](https://github.com/fwestenberg/reolink_dev/issues))
First occurred: 17:11:07 (2 occurrences)
Last logged: 17:11:07
Error doing job: Task exception was never retrieved

Traceback (most recent call last):
  File "/config/custom_components/reolink_dev/sensor.py", line 163, in handle_event
    await self._hass.async_add_job(self._update_event_range)
  File "/config/custom_components/reolink_dev/sensor.py", line 132, in _update_event_range
    end = searchtime_to_datetime(file["EndTime"], start.tzinfo)
  File "/config/custom_components/reolink_dev/base.py", line 533, in searchtime_to_datetime
    return dt.datetime(
ValueError: year 0 is out of range

and just 1 time each after HA restart :

Logger: custom_components.reolink_dev.base
Source: custom_components/reolink_dev/base.py:423
Integration: Reolink IP camera ([documentation](https://github.com/fwestenberg/reolink_dev), [issues](https://github.com/fwestenberg/reolink_dev/issues))
First occurred: 16:41:39 (1 occurrences)
Last logged: 16:41:39
Host 192.168.1.174 error renewing the Reolink subscription
Logger: reolink.subscription_manager
Source: custom_components/reolink_dev/base.py:422
Integration: Reolink IP camera ([documentation](https://github.com/fwestenberg/reolink_dev), [issues](https://github.com/fwestenberg/reolink_dev/issues))
First occurred: 16:41:39 (1 occurrences)
Last logged: 16:41:39
Subscription process ended with wrong HTTP status: 400: Bad Request

At least its only after HA restart ;)

JimStar commented 2 years ago

It's not related to my patch... But the first one and the last two - exactly those that should be fixed by the patch I work on right now. I already know what the problem is, just a lot of changes in the code should be made to make it work with NVRs properly too. Hope @cpainchaud would not make too much changes to master branch in parallel, to not have the nightmare of fixing all the merge-conflicts later... :)

JimStar commented 2 years ago

The above linked pull-request is still not the main one that should fix this subscription issue. But it still could affect some cameras that expect the WSN protocol strictly followed...

The main patch fixing the issues from this ticket will follow later...

Electronlibre2012 commented 2 years ago

thanks

Le mer. 31 août 2022, 23:56, Jim Star @.***> a écrit :

The above linked pull-request is still not the main one that should fix this subscription issue. But it still could affect some cameras that expect the WSN protocol strictly followed...

The main patch fixing the issues from this ticket will follow later...

— Reply to this email directly, view it on GitHub https://github.com/fwestenberg/reolink_dev/issues/550#issuecomment-1233360157, or unsubscribe https://github.com/notifications/unsubscribe-auth/AL4SIWND3HWTGKECPO7YMB3V362HFANCNFSM56SPMLMA . You are receiving this because you commented.Message ID: @.***>

JimStar commented 2 years ago

@rainbowbreeze or any others who have several cameras with direct connection (without NVR), and who has similar "subscription" errors in the log.

Could you please check that you have ONVIF enabled in all of your cameras? So that this reason could be completely eliminated from possible causes?
I'm asking because I've already found the exact cause of all these problems in the NVR case, but I want to be sure that it would work for directly connected cameras too...

leroyloren commented 2 years ago

Yeah,

But the camera is also connected to the NVR, I just use it directly through the POE Switch to control it

obrazek

JimStar commented 2 years ago

@leroyloren What is the reason you don't connect to the NVR from HA, but the camera directly?

leroyloren commented 2 years ago

For my purpose, I use a motion sensor (which triggers the recognition plate number in front of the garage.)

I don't need events from other cameras in the house, and it also feels faster to me because there is another intermediate element missing.

JimStar commented 2 years ago

Do you have same subscription errors in the log, like others here?..
If yes, could you please attach a log-file with debug-info here? You can enable it by this in configuration:

logger:
  default: warning
  logs:
    custom_components.reolink_dev: debug
    reolink: debug
leroyloren commented 2 years ago

after PR there are far less errors in the log, but still sensors become unavailable at intervals.

Ok, I can turn on the debug log.

This is the standard log from tonight.

*_edit: Sorry, the events of 1.9. 3:00 a.m. (+-) don't take it seriously, it was a Mikrotik upgrade._**

2022-09-01 02:18:27.041 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-09-01 02:18:27.101 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-09-01 02:18:27.109 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription 2022-09-01 02:20:27.054 ERROR (MainThread) [custom_components.reolink_dev] Timeout fetching reolink.Prijezd.motion_states data 2022-09-01 03:11:27.054 ERROR (MainThread) [custom_components.reolink_dev.binary_sensor] Motion states could not be queried from API 2022-09-01 03:11:27.097 ERROR (MainThread) [custom_components.reolink_dev.binary_sensor] Traceback (most recent call last): File "/config/custom_components/reolink_dev/binary_sensor.py", line 122, in handle_event await self._base.api.get_all_motion_states() File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 608, in get_all_motion_states response = await self.send(body) File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 1705, in send async with session.post( File "/usr/local/lib/python3.10/site-packages/aiohttp/client.py", line 1138, in __aenter__ self._resp = await self._coro File "/usr/local/lib/python3.10/site-packages/aiohttp/client.py", line 535, in _request conn = await self._connector.connect( File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 542, in connect proto = await self._create_connection(req, traces, timeout) File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 907, in _create_connection _, proto = await self._create_direct_connection(req, traces, timeout) File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 1175, in _create_direct_connection transp, proto = await self._wrap_create_connection( File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 986, in _wrap_create_connection return await self._loop.create_connection(*args, **kwargs) # type: ignore[return-value] # noqa File "/usr/local/lib/python3.10/asyncio/base_events.py", line 1049, in create_connection sock = await self._connect_sock( File "/usr/local/lib/python3.10/asyncio/base_events.py", line 960, in _connect_sock await self.sock_connect(sock, address) File "/usr/local/lib/python3.10/asyncio/selector_events.py", line 500, in sock_connect return await fut asyncio.exceptions.CancelledError 2022-09-01 03:13:27.004 ERROR (MainThread) [custom_components.reolink_dev] Timeout fetching reolink.Prijezd.motion_states data 2022-09-01 03:13:42.043 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-09-01 03:13:42.095 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-09-01 03:13:42.103 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription 2022-09-01 03:15:27.004 ERROR (MainThread) [custom_components.reolink_dev] Timeout fetching reolink.Prijezd.motion_states data 2022-09-01 03:20:45.115 ERROR (MainThread) [custom_components.reolink_dev] Error requesting reolink.Prijezd data: Cannot connect to host 10.75.7.120:80 ssl:default [Connect call failed ('10.75.7.120', 80)] 2022-09-01 03:21:01.179 ERROR (MainThread) [custom_components.reolink_dev.binary_sensor] Motion states could not be queried from API 2022-09-01 03:21:01.188 ERROR (MainThread) [custom_components.reolink_dev.binary_sensor] Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 986, in _wrap_create_connection return await self._loop.create_connection(*args, **kwargs) # type: ignore[return-value] # noqa File "/usr/local/lib/python3.10/asyncio/base_events.py", line 1064, in create_connection raise exceptions[0] File "/usr/local/lib/python3.10/asyncio/base_events.py", line 1049, in create_connection sock = await self._connect_sock( File "/usr/local/lib/python3.10/asyncio/base_events.py", line 960, in _connect_sock await self.sock_connect(sock, address) File "/usr/local/lib/python3.10/asyncio/selector_events.py", line 500, in sock_connect return await fut File "/usr/local/lib/python3.10/asyncio/selector_events.py", line 535, in _sock_connect_cb raise OSError(err, f'Connect call failed {address}') OSError: [Errno 113] Connect call failed ('10.75.7.120', 80) The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/config/custom_components/reolink_dev/binary_sensor.py", line 122, in handle_event await self._base.api.get_all_motion_states() File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 608, in get_all_motion_states response = await self.send(body) File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 1705, in send async with session.post( File "/usr/local/lib/python3.10/site-packages/aiohttp/client.py", line 1138, in __aenter__ self._resp = await self._coro File "/usr/local/lib/python3.10/site-packages/aiohttp/client.py", line 535, in _request conn = await self._connector.connect( File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 542, in connect proto = await self._create_connection(req, traces, timeout) File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 907, in _create_connection _, proto = await self._create_direct_connection(req, traces, timeout) File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 1206, in _create_direct_connection raise last_exc File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 1175, in _create_direct_connection transp, proto = await self._wrap_create_connection( File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 992, in _wrap_create_connection raise client_error(req.connection_key, exc) from exc aiohttp.client_exceptions.ClientConnectorError: Cannot connect to host 10.75.7.120:80 ssl:default [Connect call failed ('10.75.7.120', 80)] 2022-09-01 03:22:02.491 ERROR (MainThread) [custom_components.reolink_dev.binary_sensor] Motion states could not be queried from API 2022-09-01 03:22:02.503 ERROR (MainThread) [custom_components.reolink_dev.binary_sensor] Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 986, in _wrap_create_connection return await self._loop.create_connection(*args, **kwargs) # type: ignore[return-value] # noqa File "/usr/local/lib/python3.10/asyncio/base_events.py", line 1064, in create_connection raise exceptions[0] File "/usr/local/lib/python3.10/asyncio/base_events.py", line 1049, in create_connection sock = await self._connect_sock( File "/usr/local/lib/python3.10/asyncio/base_events.py", line 960, in _connect_sock await self.sock_connect(sock, address) File "/usr/local/lib/python3.10/asyncio/selector_events.py", line 500, in sock_connect return await fut File "/usr/local/lib/python3.10/asyncio/selector_events.py", line 535, in _sock_connect_cb raise OSError(err, f'Connect call failed {address}') OSError: [Errno 113] Connect call failed ('10.75.7.120', 80) The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/config/custom_components/reolink_dev/binary_sensor.py", line 122, in handle_event await self._base.api.get_all_motion_states() File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 608, in get_all_motion_states response = await self.send(body) File "/usr/local/lib/python3.10/site-packages/reolink/camera_api.py", line 1705, in send async with session.post( File "/usr/local/lib/python3.10/site-packages/aiohttp/client.py", line 1138, in __aenter__ self._resp = await self._coro File "/usr/local/lib/python3.10/site-packages/aiohttp/client.py", line 535, in _request conn = await self._connector.connect( File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 542, in connect proto = await self._create_connection(req, traces, timeout) File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 907, in _create_connection _, proto = await self._create_direct_connection(req, traces, timeout) File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 1206, in _create_direct_connection raise last_exc File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 1175, in _create_direct_connection transp, proto = await self._wrap_create_connection( File "/usr/local/lib/python3.10/site-packages/aiohttp/connector.py", line 992, in _wrap_create_connection raise client_error(req.connection_key, exc) from exc aiohttp.client_exceptions.ClientConnectorError: Cannot connect to host 10.75.7.120:80 ssl:default [Connect call failed ('10.75.7.120', 80)] 2022-09-01 03:23:32.003 ERROR (MainThread) [custom_components.reolink_dev] Timeout fetching reolink.Prijezd.motion_states data 2022-09-01 09:38:49.052 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-09-01 09:38:49.119 WARNING (MainThread) [reolink.subscription_manager] Subscription process ended with wrong HTTP status: 400: Bad Request 2022-09-01 09:38:49.126 ERROR (MainThread) [custom_components.reolink_dev.base] Host 10.75.7.120 error renewing the Reolink subscription 2022-09-01 09:40:32.004 ERROR (MainThread) [custom_components.reolink_dev] Timeout fetching reolink.Prijezd.motion_states data

JimStar commented 2 years ago

Thank you!
Standard log lacks some important info though... Would be helpful if you had enabled debug, and waited for ~20 minutes after HA restart before copying logs... If you have time for all this of course, don't worry please if not.
And would be helpful if you attached the file, 'cause this formatting is kinda not very readable... especially if there would be a lot of debugging info in it... :)

leroyloren commented 2 years ago

Ok, when I have space, I will create and attach a debug log :-)

Thanks.

Electronlibre2012 commented 2 years ago

since one and a half day i have no more "camera_xxxx_motion_sensor unavailable",

i have check "auto reboot" at 3am every day and select "30mn recording" instead of initial 60mn.

Perhaps the auto reboot did the trick, because i have no more "grey" period in timeline, just one, 1mn long, at 3am, what is expected with the reboot.

JimStar commented 2 years ago

How many cameras you have?

Electronlibre2012 commented 2 years ago

i have 4 camera D500 (kit NVR410 + 4 cams) and 1 D520 probably add the sixth (D520) in next weeks.

Confirm that no more grey space since i check auto reboot at 3 am, almost 3 days now.

leroyloren commented 2 years ago

Ok, when I have space, I will create and attach a debug log :-)

Thanks.

debug log 10:00-15:00 (+-) home-assistant.log

For example 12:32:48 is cam unavailable

obrazek

JimStar commented 2 years ago

@leroyloren Thank you!

JimStar commented 2 years ago

@leroyloren
Your issue with direct camera connection is different from NVR problems I had (despite sometimes looking similar in log messages). But I think I've been able to fix this too. Still need some time to finish/polish all the changes...
What seems weird to me - Reolink has a lot "more better" ONVIF WSN support in their new cameras, than in their NVRs (at least it's the case for my RLN8-410 NVR). It looks to me like completely different development teams are working on their cameras' and NVRs' firmwares.
So there is definitely some sense in connecting HA directly to cameras bypassing NVR, like you do (you get less problems even with current version of reolink_nvr). At least it's definitely the case for my RLN8-410 that I've got deeply investigated while debugging all this...

pod31 commented 2 years ago

Hello, I have update my RLC-822A camera to firmware v3.1.0.956_22041507, and now the motion sensors are unavailable (no NVR). Renew the integration not resolve the problem. Logs says :