home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.09k stars 30.18k forks source link

Reolink integration took 280 seconds to start #121367

Open Daniel-dev22 opened 3 months ago

Daniel-dev22 commented 3 months ago

The problem

Previously the issue causing reolink to take awhile to start was the firmware check it did. However it also appears that waiting on polling is causing an issue still. This will fail for me as I have home assistant behind https and have 0 plans to ever expose an http interface locally either.

The integration should not wait on this to start. It should setup them figure out what type of connection it will need to use to receive events from the camera.

2024-07-05 19:05:54.203 ERROR (MainThread) [homeassistant.components.reolink.host] Reolink Doorbell event long polling subscription lost: Host 192.168.2.11:443: failed to subscribe long_poll: Host 192.168.2.11:443: connection timeout exception.
2024-07-05 19:05:54.204 ERROR (MainThread) [homeassistant.components.reolink.host] Error while requesting ONVIF pull point: Host 192.168.2.11:443: failed to request pull point message, not yet subscribed

Screenshot_20240705_195058_Home Assistant

What version of Home Assistant Core has the issue?

2024.7.1

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

reolink

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2024-07-05 19:05:54.203 ERROR (MainThread) [homeassistant.components.reolink.host] Reolink Doorbell event long polling subscription lost: Host 192.168.2.11:443: failed to subscribe long_poll: Host 192.168.2.11:443: connection timeout exception.
2024-07-05 19:05:54.204 ERROR (MainThread) [homeassistant.components.reolink.host] Error while requesting ONVIF pull point: Host 192.168.2.11:443: failed to request pull point message, not yet subscribed


### Additional information

_No response_
home-assistant[bot] commented 3 months ago

Hey there @starkillerog, mind taking a look at this issue as it has been labeled with an integration (reolink) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `reolink` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign reolink` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)


reolink documentation reolink source (message by IssueLinks)

starkillerOG commented 2 months ago

Thanks for making the github issue, I will see if I can reproduce on my cams.

dangelsaurus commented 2 months ago

Same.

Core 2024.7.1 Supervisor 2024.06.2 Operating System 12.4 Frontend 20240705.0

image

Daniel-dev22 commented 2 months ago

Same.

Core 2024.7.1 Supervisor 2024.06.2 Operating System 12.4 Frontend 20240705.0

image

Do you also have home assistant behind https?

auanasgheps commented 2 weeks ago

immagine

I just got this today. Not 280 but definitely a lot of time.

My HA is exposed via HTTP (LAN only) mainly for this integration.

EDIT: The integration has reported that is unable to reach my HTTP endpoint. So it should be a problem on my side.

starkillerOG commented 2 weeks ago

I looked into this issue some more, the startup delay is not caused by the firmware check anymore. It is not caused by checking of the ONVIF subscriptions.

It must be caused by a timeout in actually subscribing to the ONVIF push/long polling. This is likely because HomeAssistant is not able to reach port 8000 on the camera (probably because of VLAN isolation). You will need to configure the VLAN such that it will allow traffic from HA to the camera port 8000.

It is unrelated to the HTTP vs HTTPS stuff which will not let the camera send pushes to HA.

starkillerOG commented 2 weeks ago

failed to subscribe long_poll: Host 192.168.2.11:443: connection timeout exception. This is the relevant part. This subscription is done on the ONVIF port of the camera (by default 8000).

Since this is a network configuration issue rather than a issue with the Reolink integration I will close this issue now.

If you do get this working after opening up port 8000, please let me know, than I can update the troubleshooting steps.

auanasgheps commented 2 weeks ago

Yeah, I did see something similar later in the day. The Reolink camera crashed (this is not good...) and the integration could not reach the camera.

Daniel-dev22 commented 2 weeks ago

I looked into this issue some more, the startup delay is not caused by the firmware check anymore. It is not caused by checking of the ONVIF subscriptions.

It must be caused by a timeout in actually subscribing to the ONVIF push/long polling. This is likely because HomeAssistant is not able to reach port 8000 on the camera (probably because of VLAN isolation). You will need to configure the VLAN such that it will allow traffic from HA to the camera port 8000.

It is unrelated to the HTTP vs HTTPS stuff which will not let the camera send pushes to HA.

Home assistant is sitting in a docker IPvlan on the cameras network and has full access to all ports.

Just proved this.

daniel@ubuntu:~$ sudo docker exec -it homeassistant nmap 192.168.2.11 Starting Nmap 7.95 ( https://nmap.org ) at 2024-09-20 13:54 EDT Nmap scan report for 192.168.2.11 Host is up (0.0074s latency). Not shown: 995 closed tcp ports (reset) PORT STATE SERVICE 80/tcp open http 443/tcp open https 554/tcp open rtsp 8000/tcp open http-alt 9000/tcp open cslistener MAC Address: 38:E7:C0:C3:4A:BF (Hui Zhou Gaoshengda Technology) Nmap done: 1 IP address (1 host up) scanned in 0.23 seconds

mwolter805 commented 1 week ago

Same issue... every time home assistant is restarted the reolink integration takes ~120 seconds to startup. Everything appears to work fine with the doorbell in HA, only issue is the integration's slow startup.

HA is a docker container with macvlan networking (all ports are open and there is no firewall). Firewall is a Unifi Dream Machine Pro, camera is on a separate VLAN than HA, all traffic is allowed from the doorbell to HA and vice versa. HA is behind a trafik reverse proxy. Home Assistant URL for Local network directs to the trafik proxy (http, not https).

starkillerOG commented 1 week ago

Please enable debug logging of the reolink integration, reload the reolink integration, wait the full 120+ seconds until it is fully started, stop the debug logging and post the resulting log.txt file here

Daniel-dev22 commented 1 week ago

Same issue... every time home assistant is restarted the reolink integration takes ~120 seconds to startup. Everything appears to work fine with the doorbell in HA, only issue is the integration's slow startup.

HA is a docker container with macvlan networking (all ports are open and there is no firewall). Firewall is a Unifi Dream Machine Pro, camera is on a separate VLAN than HA, all traffic is allowed from the doorbell to HA and vice versa. HA is behind a trafik reverse proxy. Home Assistant URL for Local network directs to the trafik proxy (http, not https).

Can the camera reach the traefik proxy IP?

mwolter805 commented 1 week ago

@starkillerOG Logs are attached

@Daniel-dev22 Yes, the traffic is allowed in firewall. home-assistant_reolink_2024-09-24T19-59-26.672Z.log

starkillerOG commented 1 week ago

@mwolter805 thats not a debug log, but a normal log. See https://www.home-assistant.io/docs/configuration/troubleshooting/#enabling-debug-logging

mwolter805 commented 1 week ago

@starkillerOG Didn't realize in logger I had reolink messages set at warning. Is this better? home-assistant_reolink_2024-09-25T13-40-29.687Z.log

starkillerOG commented 2 days ago

@mwolter805 I have investigated your debug log and found some surprising results. I did find the cause of the problem:

At 2024-09-25 06:37:17.980 a big request is send At 2024-09-25 06:37:48.305 the response to the big request is received, which includes "DingDongOpt" "rcv failed"

At 2024-09-25 06:37:49.743 'DingDongOpt' is re-send At 2024-09-25 06:38:45.761 DEBUG (MainThread) [reolink_aio.api] cmd ['DingDongOpt']: returned response code [-17]/['rcv failed'], retrying in 1.0 s

At 2024-09-25 06:38:46.762 'DingDongOpt' is re-send At 2024-09-25 06:39:16.870 DEBUG (MainThread) [reolink_aio.api] cmd ['DingDongOpt']: returned response code [-17]/['rcv failed'], retrying in 1.0 s

So retrieving the 'DingDongOpt' setting is taking about 120 seconds, causing the delay in startup you are seeing.

Earlier I already retrieve the DingDongList:

   {
      "cmd" : "GetDingDongList",
      "code" : 0,
      "value" : {
         "DingDongList" : {
            "maxPairNumber" : 5,
            "pairedlist" : [
               {
                  "deviceId" : 771319334,
                  "deviceName" : "Reolink Chime",
                  "netState" : 2
               },
               {
                  "deviceId" : 771335859,
                  "deviceName" : "",
                  "netState" : 1
               }
            ]
         }
      }
   },

Here you see that the Chime with ID 771335859 is currently not online (netState != 2). I can also see that the 'DingDongOpt' command emidiatly responds for the Chime with ID 771319334, but takes a long time to respond for the Chime with ID 771335859 which is offline.

So long story short: the statup delay is caused by the doorbell beeing unable to comunicate with one of the 2 chimes you coupled to the doorbell.

I will adjust the code such that the 'DingDongOpt' command will only be sent when a chime is actually online and reachable so this issue will not occur again.

In the meantime you can easily solve your issue by removing the chime which is not online from the Doorbell in the Reolink App. (Or make sure the chime becomes online). Not sure why the 2nd chime is offline, it may not be plugged into power, it maybe too far away from the doorbell.....

starkillerOG commented 2 days ago

This commit in the upstream reolink-aio library will solve the startup delay for Doorbells which have Chimes connected that are unreachable (offline): https://github.com/starkillerOG/reolink_aio/commit/29ca750f18c85626c709075b8392cb5a93bb02e0

mwolter805 commented 2 days ago

@starkillerOG thank you for looking into this.

Daniel-dev22 commented 2 days ago

I only have 1 chime I'm curious if I was having a similar issue. Will have to turn debug mode on and try and see what I see

starkillerOG commented 2 days ago

@Daniel-dev22 if you post the debug log I can look into it, but of course you can also see for yourself. At least now you know what to look for