HomeAssistant-Tapo-Control icon indicating copy to clipboard operation
HomeAssistant-Tapo-Control copied to clipboard

Bug: C310 Motion sensor stops working or becomes unavailable

Open dankocrnkovic opened this issue 3 years ago • 45 comments

Describe the bug Motion sensor stops reporting state change after some time. (daily). Stream still works. Sometimes motion sensor in HA reports unavailabe and somtimes it just stays in off state. Motion is still detected on camera and recordings work on Android Tapo app.

Reseting motion detection on camera or rebooting camera does not help. Only HA restart recovers motion detection state change.

I have explicitly opened ports on firewall 2020,554,443,1024 but result is the same.

Log No log entries.


**Camera (please complete the following information):**
C310

**Using stream component**
Yes

**Camera works through onvif component OR different cameras work in general**
Camera and motion detection works in Android Tapo app.

**Camera has all attributes filled out properly in developer tools**
yes

**HASS Environment**
Supervised HA OS (RP 4)

dankocrnkovic avatar Apr 21 '21 14:04 dankocrnkovic

Hello @dankocrnkovic

I have pushed a version with debug logs into main branch. Please download that manually (not available on HACS) and configure logger to log debug for this component.

logger:
  default: critical
  logs:
    custom_components.tapo_control: debug

On a first successful motion detection you should see a message "Found event which doesn't have entity yet, adding binary sensor!".

When it happens the next time, please restart the camera without restarting home assistant and post all the logs here (ideally from the time when it was still working).

JurajNyiri avatar Apr 22 '21 08:04 JurajNyiri

Hell @JurajNyiri Is this change included in new release: 3.3.1w ?

danko

dankocrnkovic avatar Apr 22 '21 17:04 dankocrnkovic

Hello yes it is.

JurajNyiri avatar Apr 22 '21 18:04 JurajNyiri

@JurajNyiri Yesterday just about after finishing posting this issue, there was a firmware update for C310 camera in Tapo App. Its been 24 hours that I didnt restart HA (I had to later today to update and enable logging). In this 24 hour sensor was working. Usually I would have this problem twice a day. So maybe firmware fixed something. I will monitor this and report.

But, I'm confused now as you stated with latest update that new firmware version is 1.1.7, but my version from yesterday is 1.0.14 Build 210118 Rel.58915n(4555)

dankocrnkovic avatar Apr 22 '21 20:04 dankocrnkovic

My version on C200 is 1.1.7 Build 210406. Yours seems to be from January. Maybe they have different versions for C310 or are rolling it out in phases which is a common practice. That build seems to be pretty old though.

For motion sensor onvif event manager from home assistant is used, which is keeping itself alive during camera restarts, connection loss etc, so most likely change will be needed on Home Assistant side.

Before that we need to determine the cause though that's why I added the debugging.

There might be a way how to work around it until it is fixed or it might be something I missed. Either way we will find out when it happens again.

As for replicating, I tried many things to try and replicate it - reconnect camera, reboot, disconnect it for a while... it always recovered properly so its really hard to debug without it happening.

JurajNyiri avatar Apr 22 '21 21:04 JurajNyiri

home-assistant.zip Here it is. It happend. I noticed around 14:45. Rebooted camera and nothing changed. I noticed in log that it reports everything is ok. But, motion is not detected. In Tapo App motion is detected and all i ok.

Its a big log.

Last recorded video on motion in on 14:54:42 This is camera Reboot 2021-04-23 14:57:43 ERROR (stream_worker) [homeassistant.components.stream.worker] Error demuxing stream: 2021-04-23 14:58:12 ERROR (MainThread) [custom_components.tapo_control] HTTPSConnectionPool(host='192.168.3.4', port=443): Max retries exceeded with url: /stok=5e44aa5a80dab7c7f9e3e14841323312/ds (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f6a2f9400>: Failed to establish a new connection: [Errno 113] Host is unreachable'))

d.

dankocrnkovic avatar Apr 23 '21 13:04 dankocrnkovic

I waited till now (5 hours) and nothing new happened. So I restarted HA. After restart sensor was unavailable until first motion detected and now sensor is reporting ok. I attached new log that shows this. home-assistant.log

dankocrnkovic avatar Apr 23 '21 17:04 dankocrnkovic

That confirms my belief that the Home Assistant event manager is not able to recover properly.

logger:
  default: critical
  logs:
    custom_components.tapo_control: debug
    homeassistant.components.onvif: debug

Lets add debug for it and observe how it behaves when it stops working.

This is an example of successful recovery on camera reboot:

2021-04-23 21:40:15 WARNING (MainThread) [homeassistant.components.onvif] Failed to fetch ONVIF PullPoint subscription messages for '28f39a982d2634f6aa21be4917158645_tapo_events': [Errno 61] Connect call failed ('192.168.100.70', 1025)
2021-04-23 21:40:19 DEBUG (MainThread) [custom_components.tapo_control] Finished fetching Tapo resource status data in 68.889 seconds
2021-04-23 21:40:20 DEBUG (MainThread) [homeassistant.components.onvif] Restarted ONVIF PullPoint subscription for '28f39a982d2634f6aa21be4917158645_tapo_events'
2021-04-23 21:40:29 DEBUG (MainThread) [custom_components.tapo_control] async_update_data - entry

Lets see what does it do when it stops receiving events. Once we have that information we can move forward and create a bug report on Home Assistant and/on workaround it via integration somehow.

JurajNyiri avatar Apr 23 '21 19:04 JurajNyiri

Are you sure that log category is homeassistant.components.onvif?

This is from my configuration.yaml: logger: default: warning logs: custom_components.tapo_control: debug homeassistant.components.onvif: debug

There is no log record after HA restart, camera reboot, tapo app motion detection, and now I noticed that sensor is not working again. No log.

dankocrnkovic avatar Apr 24 '21 09:04 dankocrnkovic

Hello yes I tested it before sending. Try to add it, make motion so that sensor shows up and reboot camera, you should get log from onvif.

JurajNyiri avatar Apr 24 '21 09:04 JurajNyiri

Hi I have the samme Issue I added the logs option to configuration.yaml , rebooted HA and cameras It seems to me that the motion sensor is unavailable since the cam detect a movement.....then the sensor became available, but after some time is unavailable again (some idle time ?) I have a log https://pastebin.com/mdTcBs1p

Akkor70 avatar Apr 24 '21 18:04 Akkor70

Did you add log also for onvif? I can't see anything from it in the logs and there should be something there where it attempts to recover.

  1. Add logs for tapo and onvif as described above
  2. Restart hass
  3. Make a motion so that sensor shows up
  4. Reboot camera via service (once camera is up, and or when motion is detected again, there should be a log from onvif, you can verify that here)
  5. Make a motion so that sensor shows up
  6. Keep camera with privacy mode off, basically don't change anything on the camera since point 4
  7. When it stops detecting motion correctly, post all the logs

JurajNyiri avatar Apr 24 '21 19:04 JurajNyiri

Did you add log also for onvif? I can't see anything from it in the logs and there should be something there where it attempts to recover.

  1. Add logs for tapo and onvif as described above
  2. Restart hass
  3. Make a motion so that sensor shows up
  4. Reboot camera via service (once camera is up, and or when motion is detected again, there should be a log from onvif, you can verify that here)
  5. Make a motion so that sensor shows up
  6. Keep camera with privacy mode off, basically don't change anything on the camera since point 4
  7. When it stops detecting motion correctly, post all the logs

I made all steps as descrbed, the only mismatch is that I rebboted the cam from Tapo App I'll wait the movement sensor stop working to post the log again........

Akkor70 avatar Apr 24 '21 19:04 Akkor70

Please verify that the log for onvif is working. Without it waiting for logs from tapo brings no new information.

JurajNyiri avatar Apr 24 '21 19:04 JurajNyiri

Please verify that the log for onvif is working. Without it waiting for logs from tapo brings no new information.

This is my config

logger:
  default: critical
  logs:
    homeassistant.components.automations: debug
    custom_components.tapo_control: debug
    homeassistant.components.onvif: debug

Akkor70 avatar Apr 24 '21 19:04 Akkor70

  1. Add logs for tapo and onvif as described above
  2. Restart hass
  3. Make a motion so that sensor shows up
  4. Reboot camera via service (once camera is up, and or when motion is detected again, there should be a log from onvif, you can verify that here)
  5. Make a motion so that sensor shows up
  6. Keep camera with privacy mode off, basically don't change anything on the camera since point 4
  7. When it stops detecting motion correctly, post all the logs

JurajNyiri avatar Apr 24 '21 19:04 JurajNyiri

  1. Add logs for tapo and onvif as described above
  2. Restart hass
  3. Make a motion so that sensor shows up
  4. Reboot camera via service (once camera is up, and or when motion is detected again, there should be a log from onvif, you can verify that here)
  5. Make a motion so that sensor shows up
  6. Keep camera with privacy mode off, basically don't change anything on the camera since point 4
  7. When it stops detecting motion correctly, post all the logs

Onvif log is working becouse when I restart the camera from service I got this

2021-04-24 22:06:02 ERROR (stream_worker) [libav.tcp] Connection to tcp://192.168.1.61:554?timeout=5000000 failed: Operation timed out
2021-04-24 22:06:04 ERROR (stream_worker) [libav.tcp] Connection to tcp://192.168.1.85:554?timeout=5000000 failed: Operation timed out
2021-04-24 22:06:13 WARNING (MainThread) [homeassistant.components.onvif] Failed to fetch ONVIF PullPoint subscription messages for 'f2b5148ba1da55a033b8c575a149f9a3_tapo_events':
2021-04-24 22:06:19 ERROR (MainThread) [custom_components.tapo_control] HTTPSConnectionPool(host='192.168.1.85', port=443): Max retries exceeded with url: /stok=4d1a9607399fb6d9094cb3198f9d1ede/ds (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f25e342af40>: Failed to establish a new connection: [Errno 111] Connection refused'))
2021-04-24 22:06:19 DEBUG (MainThread) [custom_components.tapo_control] Finished fetching Tapo resource status data in 31.489 seconds
2021-04-24 22:06:19 ERROR (stream_worker) [libav.tcp] Connection to tcp://192.168.1.85:554?timeout=5000000 failed: Connection refused
2021-04-24 22:06:20 WARNING (MainThread) [homeassistant.components.onvif] Failed to fetch ONVIF PullPoint subscription messages for '5a7801df5d943ccdbf8adc8dea0cc7c0_tapo_events':
2021-04-24 22:06:20 WARNING (MainThread) [homeassistant.components.onvif] Failed to restart ONVIF PullPoint subscription for '5a7801df5d943ccdbf8adc8dea0cc7c0_tapo_events'. Retrying
2021-04-24 22:06:21 WARNING (MainThread) [homeassistant.components.onvif] Failed to restart ONVIF PullPoint subscription for 'f2b5148ba1da55a033b8c575a149f9a3_tapo_events'. Retrying

Now I'll wait the sensor stop working to post log

Akkor70 avatar Apr 24 '21 20:04 Akkor70

I was able to replicate this, by disconnecting HOST from network.

Home Assistant onvif event manager is no longer able to reconnect.

2021-04-24 23:00:06 WARNING (MainThread) [homeassistant.components.onvif] Failed to restart ONVIF PullPoint subscription for 'c38ba820a0eddb08cda53d5bea952b9e_tapo_events'. Retrying

on repeat.

Figuring out next steps...

JurajNyiri avatar Apr 24 '21 21:04 JurajNyiri

So after investigating, I have found out that it doesn't seem to be the same case.

  1. Disconnected HASS host
  2. Reconnected HASS host after a minute
  3. Onvif was failing to recover as described above
  4. Rebooted camera
  5. Onvif recovered

P̶l̶e̶a̶s̶e̶ ̶d̶o̶w̶n̶l̶o̶a̶d̶ ̶a̶n̶d̶ ̶r̶e̶n̶a̶m̶e̶ ̶e̶v̶e̶n̶t̶.̶t̶x̶t̶ ̶i̶n̶t̶o̶ ̶e̶v̶e̶n̶t̶.̶p̶y̶ ̶a̶n̶d̶ ̶p̶l̶a̶c̶e̶ ̶i̶n̶t̶o̶ ̶y̶o̶u̶r̶ ̶p̶i̶p̶3̶ ̶l̶i̶b̶r̶a̶r̶i̶e̶s̶ ̶f̶o̶l̶d̶e̶r̶,̶ ̶i̶n̶t̶o̶ ̶ site-packages/homeassistant/components/onvif/event.py ̶.̶ ̶O̶n̶ ̶h̶a̶s̶s̶.̶i̶o̶ ̶i̶t̶s̶ ̶s̶t̶o̶r̶e̶d̶ ̶i̶n̶s̶i̶d̶e̶ ̶t̶h̶e̶ c̶o̶n̶t̶a̶i̶n̶e̶r̶ ̶i̶t̶s̶e̶l̶f̶.̶

I̶t̶ ̶i̶s̶ ̶t̶h̶e̶ ̶s̶a̶m̶e̶ ̶e̶v̶e̶n̶t̶.̶p̶y̶ ̶a̶s̶ ̶p̶r̶o̶v̶i̶d̶e̶d̶ ̶b̶y̶ ̶H̶o̶m̶e̶ ̶A̶s̶s̶i̶s̶t̶a̶n̶t̶,̶ ̶b̶u̶t̶ ̶w̶i̶t̶h̶ ̶a̶ ̶t̶o̶n̶ ̶m̶o̶r̶e̶ ̶d̶e̶b̶u̶g̶ ̶m̶e̶s̶s̶a̶g̶e̶s̶ ̶I̶ ̶a̶d̶d̶e̶d̶.̶

Current debugging process:

  1. Download and install https://github.com/JurajNyiri/HomeAssistant-Tapo-Control/tree/experimental branch manually.
  2. Add logs for tapo and onvif component
logger:
  default: critical
  logs:
    custom_components.tapo_control: debug
    homeassistant.components.onvif: debug
  1. Restart hass
  2. Make a motion so that sensor shows up. You should see logs like 2021-04-24 23:53:50 DEBUG (MainThread) [homeassistant.components.onvif] async_start 1 and 2021-04-24 23:53:50 DEBUG (MainThread) [custom_components.tapo_control] Setting up onvif...
  3. Reboot camera via service
  4. Make a motion so that sensor shows up
  5. Don't change anything on the camera, dont move it, dont touch it.
  6. When it stops detecting motion correctly, note time
  7. Reboot camera, note time of reboot
  8. Try to make a ton of motion etc etc, so that it has a possibility to recover, leave it be for 5 min, do a ton of motion again.

If its still not recovered by that point, please post logs and times you noted down. @Akkor70 @dankocrnkovic

JurajNyiri avatar Apr 24 '21 21:04 JurajNyiri

I simply can not get onvif logs :( Rebooted camera via service and nothing new in log.

@Akkor70 did you manage to go forward with debugging?

d.

dankocrnkovic avatar Apr 26 '21 15:04 dankocrnkovic

I simply can not get onvif logs :( Rebooted camera via service and nothing new in log.

@Akkor70 did you manage to go forward with debugging?

d.

I'm waiting for motion sensor stop working

Akkor70 avatar Apr 26 '21 16:04 Akkor70

As I cant get logs to work, Motion stop reporting today and I just restarted HA without rebooting camera. And it recovered after HA restart. So, its not in camera problem as it seams.

d.

dankocrnkovic avatar Apr 27 '21 17:04 dankocrnkovic

@dankocrnkovic its a Home Assistant issue (99% probably not this integration), we just need to narrow it down and then workaround it and/or create an issue/fix for Home Assistant.

JurajNyiri avatar Apr 27 '21 21:04 JurajNyiri

Hey @Akkor70 any updates with the logs?

JurajNyiri avatar May 06 '21 23:05 JurajNyiri

No man I'm in trouble with HA atm I'll post asap

Akkor70 avatar May 06 '21 23:05 Akkor70

Seems to be the same issue with my C200 with newest firmware and newest Tapo integration

monotonus avatar May 21 '21 20:05 monotonus

@monotonus we need logs i described above to proceed with this as i cannot replicate it

JurajNyiri avatar Jun 04 '21 21:06 JurajNyiri

@JurajNyiri Just to report... In the last month, I did not had any problems. Maybe something changed in HA core.

dankocrnkovic avatar Jun 05 '21 10:06 dankocrnkovic

@dankocrnkovic that is possible as integration is using onvif provided by hass.. Also there were a couple of updates to firmware which might have helped. Let's keep this open for a few more weeks to see if anyone is still facing issues.

JurajNyiri avatar Jun 05 '21 11:06 JurajNyiri

Hi, I am using C200 and facing the same issue. The sensor stops reporting motion sometimes. Like - currently I am seeing it is not reporting motion for last 3 hours. But the app is notifying me perfectly. At that moment, if I restart HASS, the sensor becomes unavailable and then I have to delete and re-add the camera. I am also unable to debug the logs, not coming! Using HASS core of version 2021.06.05. I am using the camera as baby monitor, so this motion sensor is really important one :(

raihatneloy avatar Jun 17 '21 16:06 raihatneloy