Onvif causes Home Assistant to fail to start on 0.113.0 / 0.113.1

JurajNyiri commented 4 years ago

The problem

When I update from 0.112.4 to 0.113.0 or 0.113.1 Home Assistant loads but is stuck on message "is not ready yet". After 10 minutes, it rolls back to 0.112.4 with following message in supervisor:

20-07-25 10:42:03 INFO (SyncWorker_7) [supervisor.docker.homeassistant] Start homeassistant homeassistant/raspberrypi4-homeassistant with version 0.113.1
20-07-25 10:42:18 INFO (MainThread) [supervisor.homeassistant] Home Assistant pip installation in progress
20-07-25 10:43:20 INFO (MainThread) [supervisor.homeassistant] Home Assistant pip installation done
20-07-25 10:43:25 INFO (MainThread) [supervisor.homeassistant] Home Assistant pip installation in progress
20-07-25 10:46:57 INFO (MainThread) [supervisor.homeassistant] Home Assistant pip installation done
20-07-25 10:56:59 WARNING (MainThread) [supervisor.homeassistant] Don't wait anymore of Home Assistant startup!
20-07-25 10:56:59 CRITICAL (MainThread) [supervisor.homeassistant] HomeAssistant update fails -> rollback!
20-07-25 10:56:59 INFO (MainThread) [supervisor.homeassistant] Update Home Assistant to version 0.112.4
20-07-25 10:56:59 INFO (SyncWorker_5) [supervisor.docker.interface] Update image homeassistant/raspberrypi4-homeassistant:0.113.1 to homeassistant/raspberrypi4-homeassistant:0.112.4
20-07-25 10:56:59 INFO (SyncWorker_5) [supervisor.docker.interface] Pull image homeassistant/raspberrypi4-homeassistant tag 0.112.4.

I added following to config and was watching the logs.

logger:
  default: info
  logs:
    homeassistant.core: debug

The relevant parts are below in Traceback/Error logs section

Environment

Home Assistant Core release with the issue: 0.113.0, 0.113.1
Last working Home Assistant Core release (if known): 0.112.4
Operating environment (OS/Container/Supervised/Core): Home Assistant OS, RPI 4
Integration causing this issue: onvif
Link to integration documentation on our website: https://www.home-assistant.io/integrations/onvif/

Problem-relevant `configuration.yaml`

None.

Traceback/Error logs

2020-07-25 12:50:04 DEBUG (MainThread) [homeassistant.core] Waited 60 seconds for task: <Task pending name='Task-246099' coro=<EventManager.async_pull_messages() running at /usr/src/homeassistant/homeassistant/components/onvif/event.py:128> wait_for=<Future pending cb=[BaseSelectorEventLoop._sock_write_done(26)(), <TaskWakeupMethWrapper object at 0x9a7260d0>()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.8/asyncio/tasks.py:507]>
2020-07-25 12:50:04 DEBUG (MainThread) [homeassistant.core] Waited 60 seconds for task: <Task pending name='Task-246125' coro=<EventManager.async_pull_messages() running at /usr/src/homeassistant/homeassistant/components/onvif/event.py:128> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.8/asyncio/tasks.py:884, <TaskWakeupMethWrapper object at 0x9a454d18>()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.8/asyncio/tasks.py:507]>
2020-07-25 12:50:04 DEBUG (MainThread) [homeassistant.core] Waited 60 seconds for task: <Task pending name='Task-246121' coro=<EventManager.async_pull_messages() running at /usr/src/homeassistant/homeassistant/components/onvif/event.py:128> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.8/asyncio/tasks.py:884, <TaskWakeupMethWrapper object at 0xa86bd298>()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.8/asyncio/tasks.py:507]>
2020-07-25 12:51:05 DEBUG (MainThread) [homeassistant.core] Waited 60 seconds for task: <Task pending name='Task-336937' coro=<EventManager.async_pull_messages() running at /usr/src/homeassistant/homeassistant/components/onvif/event.py:128> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.8/asyncio/tasks.py:884, <TaskWakeupMethWrapper object at 0x9b5e95e0>()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.8/asyncio/tasks.py:507]>
2020-07-25 12:51:05 DEBUG (MainThread) [homeassistant.core] Waited 60 seconds for task: <Task pending name='Task-336934' coro=<EventManager.async_pull_messages() running at /usr/src/homeassistant/homeassistant/components/onvif/event.py:128> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.8/asyncio/tasks.py:884, <TaskWakeupMethWrapper object at 0x9b5e98b0>()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.8/asyncio/tasks.py:507]>
2020-07-25 12:51:05 DEBUG (MainThread) [homeassistant.core] Waited 60 seconds for task: <Task pending name='Task-336930' coro=<EventManager.async_pull_messages() running at /usr/src/homeassistant/homeassistant/components/onvif/event.py:128> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.8/asyncio/tasks.py:884, <TaskWakeupMethWrapper object at 0x9a23e5b0>()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.8/asyncio/tasks.py:507]>

2020-07-25 12:56:11 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/onvif/event.py", line 128, in async_pull_messages
    await self.async_renew()
  File "/usr/src/homeassistant/homeassistant/components/onvif/event.py", line 113, in async_renew
    await self._subscription.Renew(termination_time)
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/bindings.py", line 12, in send
    response = await client.transport.post_xml(
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/transport.py", line 107, in post_xml
    response = await self.post(address, message, headers)
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/transport.py", line 90, in post
    response = await self.session.post(
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client.py", line 504, in _request
    await resp.start(conn)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 847, in start
    message, payload = await self._protocol.read()  # type: ignore  # noqa
  File "/usr/local/lib/python3.8/site-packages/aiohttp/streams.py", line 591, in read
    await self._waiter
aiohttp.client_exceptions.ClientOSError: [Errno 104] Connection reset by peer
2020-07-25 12:56:11 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/onvif/event.py", line 128, in async_pull_messages
    await self.async_renew()
  File "/usr/src/homeassistant/homeassistant/components/onvif/event.py", line 113, in async_renew
    await self._subscription.Renew(termination_time)
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/bindings.py", line 12, in send
    response = await client.transport.post_xml(
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/transport.py", line 107, in post_xml
    response = await self.post(address, message, headers)
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/transport.py", line 90, in post
    response = await self.session.post(
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client.py", line 504, in _request
    await resp.start(conn)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 847, in start
    message, payload = await self._protocol.read()  # type: ignore  # noqa
  File "/usr/local/lib/python3.8/site-packages/aiohttp/streams.py", line 591, in read
    await self._waiter
aiohttp.client_exceptions.ClientOSError: [Errno 104] Connection reset by peer
2020-07-25 12:56:41 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/onvif/event.py", line 128, in async_pull_messages
    await self.async_renew()
  File "/usr/src/homeassistant/homeassistant/components/onvif/event.py", line 113, in async_renew
    await self._subscription.Renew(termination_time)
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/bindings.py", line 12, in send
    response = await client.transport.post_xml(
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/transport.py", line 107, in post_xml
    response = await self.post(address, message, headers)
  File "/usr/local/lib/python3.8/site-packages/zeep/asyncio/transport.py", line 90, in post
    response = await self.session.post(
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client.py", line 504, in _request
    await resp.start(conn)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 847, in start
    message, payload = await self._protocol.read()  # type: ignore  # noqa
  File "/usr/local/lib/python3.8/site-packages/aiohttp/streams.py", line 591, in read
    await self._waiter
aiohttp.client_exceptions.ClientOSError: [Errno 104] Connection reset by peer

Additional information

I noticed that Iam also getting all sensor templates as unknown for some reason, not sure if it is related. If I take value_template and copy paste it to template editor it works and returns expected value. However, the sensor is always undefined.

probot-home-assistant[bot] commented 4 years ago

onvif documentation onvif source _{^{(message by IssueLinks)}}

probot-home-assistant[bot] commented 4 years ago

Hey there @hunterjm, mind taking a look at this issue as its been labeled with an integration (onvif) you are listed as a codeowner for? Thanks! _{^{(message by CodeOwnersMention)}}

sagitt commented 4 years ago

same here, removing onvif upgrade works.

litinoveweedle commented 4 years ago

Same on Supervised HA 113.1 - not able to finish starting, when removed onvif integration HA restarts without issue. Nothing corresponding in logs even with debug level.

litinoveweedle commented 4 years ago

I can confirm, that after applying manually your patch to my 113.1 installation, HA starts without problems with onvif integration and devices. Thank you very much.

home-assistant / core