search

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
73.65k stars 30.79k forks source link

HA Core loop crashing when ZHA starts since 2023.4 #91467

Closed nerthazrim closed 1 year ago

nerthazrim commented 1 year ago

The problem

Hi,

When upgrading HA Core to 2023.4.1 (and more recently, 2023.4.4), HA Core seems to crash at startup. More precisely, it crashes when ZHA starts. If I disable ZHA integration before upgrading, all goes well. When I enable ZHA after upgrade, HA Core crashes, restart, crashes, etc...

What version of Home Assistant Core has the issue?

core-2023.3.6

What was the last working version of Home Assistant Core?

core-2023.3.6

What type of installation are you running?

Home Assistant Supervised

Integration causing the issue

ZHA

Link to integration documentation on our website

https://www.home-assistant.io/integrations/zha/

Diagnostics information

I'm currently running HA Supervised, manually installed on a Raspberry Pi 3B running on Debian 11. Home Assistant 2023.3.6 Supervisor 2023.04.0 Frontend 20230309.1 - latest

configuration.yaml below

1 addon: Mosquitto Broker Integrations enabled: HACS, HASS.Agent, Supervisor, Home Connect, iRobot, Meteo, Mobile App, MQTT, Radio, RPI Power Checker, Shelly, Sun, UniFi Network, UniFi Protect, ViCare, ZHA On ZHA, I have multiple devices, mainly shades, 1 Zlinky and 2 Aqara door sensors.

I've had this configuration for more than 2 weeks now, running smoothly, all upgrades went well.

However, when upgrading HA Core to 2023.4.1 (and more recently, 2023.4.4), HA Core seems to crash at startup. More precisely, it crashes when ZHA starts. If I disable ZHA integration before upgrading, all goes well. When I enable ZHA after upgrade, HA Core crashes.

I'm a bit lost as I don't see anything useful in the HA logs when I start ZHA :(

Example YAML snippet

# Loads default set of integrations. Do not remove.
default_config:

# Load frontend themes from the themes folder
frontend:
  themes: !include_dir_merge_named themes

http:
  use_x_forwarded_for: true
  trusted_proxies:
    - 10.0.3.30
    - 2a0e:XXXX:XXXX::/48

# Text to speech
tts:
  - platform: google_translate

automation: !include automations.yaml
script: !include scripts.yaml
scene: !include scenes.yaml

recorder:
  db_url: mysql://hassio:XXXX@10.0.3.20/homeassistant?charset=utf8mb4
  purge_keep_days: 3650
  commit_interval: 60

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 1 year ago

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

Code owner commands Code owners of `zha` 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 zha` Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)

zha documentation zha source (message by IssueLinks)

bdraco commented 1 year ago

There is likely a cancellation that is propagating too high in the stack.

We would need the stack trace from the console log to be able to find and fix it.

nerthazrim commented 1 year ago

Hi,

Understood!

How would I be able to give you that? Put logging in debug mode then try the upgrade and send you the logs? Would that be enough?

bdraco commented 1 year ago

You could enable debugpy and than watch the console log when setting up zha

nerthazrim commented 1 year ago

Sorry for potential obvious questions but as my HA is running on RPI, any crash loop or restart is taking ages, I prefer to know exactly what to do before crashing my whole system :D

Would that be enough in configuration.yaml? Or do I need to do anything else before disabling zha, upgrade and enableing zha?

debugpy:
  start: true
  wait: true
bdraco commented 1 year ago 
debugpy:

Thats all that is needed

nerthazrim commented 1 year ago

Alright, so, running 2023.3.6:

  1. added the conf snippet "debugpy"
  2. disabled the ZHA integration
  3. started the update to 2023.4.4 from GUI (without backup)
  4. when HA started on 2023.4.4, everything looks fine
  5. restarted on that version, just to be safe
  6. started ZHA and crash loops start

Here are the logs from step 5. Logs are cleaned at each restart, all look the same. I don't see anything helpful, hope you will :(

2023-04-16 22:07:35.650 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-04-16 22:07:35.659 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration hass_agent which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-04-16 22:07:49.361 WARNING (MainThread) [homeassistant.components.debugpy] Listening for remote debug connection on 0.0.0.0:5678
2023-04-16 22:07:49.762 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component usb' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.101 seconds
2023-04-16 22:07:50.173 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component dhcp' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.367 seconds
2023-04-16 22:07:51.157 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component bluetooth' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load bluetooth.remote_scanners' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.776 seconds
2023-04-16 22:07:52.160 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component zeroconf' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.878 seconds
2023-04-16 22:07:52.458 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component ssdp' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.268 seconds
2023-04-16 22:07:55.605 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component cloud' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load cloud' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 2.800 seconds
2023-04-16 22:07:55.887 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component cloud' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.126 seconds
2023-04-16 22:08:01.087 WARNING (MainThread) [homeassistant.setup] Setup of bluetooth is taking over 10 seconds.
2023-04-16 22:08:05.618 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-344' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.147 seconds
2023-04-16 22:08:05.961 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-350' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.158 seconds
2023-04-16 22:08:07.988 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component bluetooth' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.124 seconds
2023-04-16 22:08:08.615 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component history' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.236 seconds
2023-04-16 22:08:09.777 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component logbook' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.162 seconds
2023-04-16 22:08:24.731 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component mqtt' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 13.946 seconds
2023-04-16 22:08:25.028 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2023-04-16 22:08:25.033 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2023-04-16 22:08:25.037 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds.
2023-04-16 22:08:25.041 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2023-04-16 22:08:25.043 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2023-04-16 22:08:25.045 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2023-04-16 22:08:25.050 WARNING (MainThread) [homeassistant.setup] Setup of schedule is taking over 10 seconds.
2023-04-16 22:08:25.056 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds.
2023-04-16 22:08:25.059 WARNING (MainThread) [homeassistant.setup] Setup of script is taking over 10 seconds.
2023-04-16 22:08:27.325 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component unifiprotect' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 2.019 seconds
2023-04-16 22:08:28.044 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component tts' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:216> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.180 seconds
2023-04-16 22:08:29.877 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup MQTT mqtt 58e6c6a439bf0199367895f8f89fe538' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 1.822 seconds
2023-04-16 22:08:30.621 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component cover' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <2 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.722 seconds
2023-04-16 22:08:31.504 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component hacs' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.620 seconds
2023-04-16 22:08:33.161 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component conversation' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.184 seconds
2023-04-16 22:08:33.378 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup udm-pro unifiprotect cb7c21744a386dadedb08241b0355879' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.109 seconds
2023-04-16 22:08:36.534 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component stream' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 2.986 seconds
2023-04-16 22:08:36.946 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component unifi' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load unifi_data' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.272 seconds
2023-04-16 22:08:39.684 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  hacs d2a50203d20d0fe0511d1d4927e70158' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 2.734 seconds
2023-04-16 22:08:41.683 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup Home met 10dc80fb2b1012876b1d1035b415fb00' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.605 seconds
2023-04-16 22:08:41.935 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component radio_browser' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.149 seconds
2023-04-16 22:08:42.151 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component shelly' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.211 seconds
2023-04-16 22:08:43.082 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  hacs d2a50203d20d0fe0511d1d4927e70158' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:864, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.885 seconds
2023-04-16 22:08:44.267 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component vicare' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.415 seconds
2023-04-16 22:08:44.667 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component tts' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.138 seconds
2023-04-16 22:08:45.285 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component home_connect' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.614 seconds
2023-04-16 22:08:45.927 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component mobile_app' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load mobile_app' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.168 seconds
2023-04-16 22:08:49.340 ERROR (SyncWorker_5) [homeassistant.util.logging] Exception in updated when handling msg on 'hass.agent/devices/LIBERTY': '{"serial_number":"82255396-88f2-4b64-b31a-8cb2cf63d1aa","device":{"identifiers":"hass.agent-LIBERTY","manufacturer":"LAB02 Research","model":"Microsoft Windows NT 10.0.22621.0","name":"LIBERTY","sw_version":"2022.14.0"},"apis":{"notifications":true,"media_player":true}}'
Traceback (most recent call last):
  File "/config/custom_components/hass_agent/__init__.py", line 147, in updated
    hass.async_create_task(handle_apis_changed(hass, entry, apis))
  File "/usr/src/homeassistant/homeassistant/core.py", line 526, in async_create_task
    task = self.loop.create_task(target, name=name)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 438, in create_task
    task = tasks.Task(coro, loop=self, name=name)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 755, in call_soon
    self._check_thread()
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 792, in _check_thread
    raise RuntimeError(
RuntimeError: Non-thread-safe operation invoked on an event loop other than the current one

2023-04-16 22:08:49.349 ERROR (SyncWorker_1) [homeassistant.util.logging] Exception in updated when handling msg on 'hass.agent/devices/LIBERTY': '{"serial_number":"82255396-88f2-4b64-b31a-8cb2cf63d1aa","device":{"identifiers":"hass.agent-LIBERTY","manufacturer":"LAB02 Research","model":"Microsoft Windows NT 10.0.22621.0","name":"LIBERTY","sw_version":"2022.14.0"},"apis":{"notifications":true,"media_player":true}}'
Traceback (most recent call last):
  File "/config/custom_components/hass_agent/__init__.py", line 147, in updated
    hass.async_create_task(handle_apis_changed(hass, entry, apis))
  File "/usr/src/homeassistant/homeassistant/core.py", line 526, in async_create_task
    task = self.loop.create_task(target, name=name)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 438, in create_task
    task = tasks.Task(coro, loop=self, name=name)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 755, in call_soon
    self._check_thread()
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 792, in _check_thread
    raise RuntimeError(
RuntimeError: Non-thread-safe operation invoked on an event loop other than the current one

2023-04-16 22:08:49.360 ERROR (SyncWorker_5) [homeassistant] Error doing job: Task was destroyed but it is pending!:   File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/util/logging.py", line 166, in wrapper
    func(*args)
  File "/config/custom_components/hass_agent/__init__.py", line 147, in updated
    hass.async_create_task(handle_apis_changed(hass, entry, apis))
  File "/usr/src/homeassistant/homeassistant/core.py", line 526, in async_create_task
    task = self.loop.create_task(target, name=name)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 438, in create_task
    task = tasks.Task(coro, loop=self, name=name)

2023-04-16 22:08:49.375 ERROR (SyncWorker_1) [homeassistant] Error doing job: Task was destroyed but it is pending!:   File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/util/logging.py", line 166, in wrapper
    func(*args)
  File "/config/custom_components/hass_agent/__init__.py", line 147, in updated
    hass.async_create_task(handle_apis_changed(hass, entry, apis))
  File "/usr/src/homeassistant/homeassistant/core.py", line 526, in async_create_task
    task = self.loop.create_task(target, name=name)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 438, in create_task
    task = tasks.Task(coro, loop=self, name=name)

2023-04-16 22:08:51.035 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup udm-pro unifiprotect cb7c21744a386dadedb08241b0355879' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.242 seconds
2023-04-16 22:08:52.753 WARNING (MainThread) [asyncio] Executing <Task pending name='EntityPlatform async_add_entities_for_entry binary_sensor.unifiprotect udm-pro unifiprotect cb7c21744a386dadedb08241b0355879' coro=<EntityPlatform.async_add_entities() running at /usr/src/homeassistant/homeassistant/helpers/entity_platform.py:455> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.880 seconds
2023-04-16 22:08:53.842 WARNING (MainThread) [asyncio] Executing <Task finished name='process integration platform diagnostics for unifiprotect' coro=<_async_process_single_integration_platform_component() done, defined at /usr/src/homeassistant/homeassistant/helpers/integration_platform.py:28> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.454 seconds
2023-04-16 22:08:55.695 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3036' coro=<HacsBase.startup_tasks() running at /config/custom_components/hacs/base.py:681> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:492> took 0.400 seconds
2023-04-16 22:08:55.906 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry flow cast f7969d6c8dcaab27a1674cb92976db6a' coro=<ConfigEntriesFlowManager._async_init() running at /usr/src/homeassistant/homeassistant/config_entries.py:858> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.105 seconds
2023-04-16 22:08:56.426 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.174 seconds
2023-04-16 22:08:56.983 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3083' coro=<HacsBase.async_get_category_repositories() running at /config/custom_components/hacs/base.py:903> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:864, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.106 seconds
2023-04-16 22:08:57.188 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3084' coro=<HacsBase.async_get_category_repositories() running at /config/custom_components/hacs/base.py:903> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:864, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.167 seconds
2023-04-16 22:08:57.381 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3087' coro=<BaseSelectorEventLoop._accept_connection2() running at /usr/local/lib/python3.10/asyncio/selector_events.py:213> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/asyncio/selector_events.py:191> took 0.154 seconds
2023-04-16 22:08:57.581 WARNING (MainThread) [asyncio] Executing <Handle _SelectorSocketTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.159 seconds
2023-04-16 22:08:58.204 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3031' coro=<async_setup_discovery_view.<locals>._async_discovery_start_handler() running at /usr/src/homeassistant/homeassistant/components/hassio/discovery.py:54> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:492> took 0.177 seconds
2023-04-16 22:08:58.682 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.108 seconds
2023-04-16 22:08:58.956 WARNING (MainThread) [asyncio] Executing <Task finished name='Task-3082' coro=<HacsBase.async_get_category_repositories() done, defined at /config/custom_components/hacs/base.py:898> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.249 seconds
2023-04-16 22:08:59.914 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.165 seconds
2023-04-16 22:09:00.208 WARNING (MainThread) [asyncio] Executing <Handle cancelled _SelectorSocketTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.195 seconds
2023-04-16 22:09:03.024 WARNING (MainThread) [asyncio] Executing <Task finished name='config entry flow cast f7969d6c8dcaab27a1674cb92976db6a' coro=<ConfigEntriesFlowManager._async_init() done, defined at /usr/src/homeassistant/homeassistant/config_entries.py:850> result=(<homeassistan... 0x7f77d65c90>, {'description_placeholders': None, 'flow_id': 'f7969d6c8dca...74cb92976db6a', 'handler': 'cast', 'reason': 'single_instance_allowed', ...}) created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 2.756 seconds
2023-04-16 22:09:03.486 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3108' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.420 seconds
2023-04-16 22:09:04.005 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.506 seconds
2023-04-16 22:09:04.967 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3083' coro=<HacsBase.async_get_category_repositories() running at /config/custom_components/hacs/base.py:903> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.263 seconds
2023-04-16 22:09:05.275 WARNING (MainThread) [asyncio] Executing <Handle _SelectorSocketTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.165 seconds
2023-04-16 22:09:05.649 WARNING (MainThread) [asyncio] Executing <Task finished name='Task-3083' coro=<HacsBase.async_get_category_repositories() done, defined at /config/custom_components/hacs/base.py:898> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.121 seconds
2023-04-16 22:09:06.258 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.135 seconds
2023-04-16 22:09:14.464 WARNING (MainThread) [asyncio] Executing <Task pending name='unifiprotect-discovery' coro=<async_start_discovery.<locals>._async_discovery() running at /usr/src/homeassistant/homeassistant/components/unifiprotect/discovery.py:33> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:545> took 7.826 seconds
2023-04-16 22:09:14.705 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.132 seconds
2023-04-16 22:09:16.190 WARNING (MainThread) [asyncio] Executing <Task finished name='config entry flow spotify 6871bda806c58cc35e47648ba2d71bea' coro=<ConfigEntriesFlowManager._async_init() done, defined at /usr/src/homeassistant/homeassistant/config_entries.py:850> result=(<homeassistan... 0x7f776c5a20>, {'description_placeholders': None, 'flow_id': '6871bda806c5...7648ba2d71bea', 'handler': 'spotify', 'reason': 'missing_credentials', ...}) created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 1.110 seconds
2023-04-16 22:09:16.551 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.133 seconds
2023-04-16 22:09:16.926 WARNING (MainThread) [asyncio] Executing <Handle _SelectorDatagramTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.207 seconds
2023-04-16 22:09:17.435 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3149' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.179 seconds
2023-04-16 22:09:17.950 WARNING (MainThread) [asyncio] Executing <Handle cancelled _SelectorSocketTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.103 seconds
2023-04-16 22:09:18.443 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.122 seconds
2023-04-16 22:09:19.095 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.115 seconds
2023-04-16 22:09:19.318 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.103 seconds
2023-04-16 22:09:20.510 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.108 seconds
2023-04-16 22:09:20.936 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.108 seconds
2023-04-16 22:09:21.283 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.278 seconds
2023-04-16 22:09:21.697 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.133 seconds
2023-04-16 22:09:22.075 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.152 seconds
2023-04-16 22:09:22.262 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.102 seconds
2023-04-16 22:09:22.816 WARNING (MainThread) [asyncio] Executing <Handle _SelectorDatagramTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.119 seconds
2023-04-16 22:09:27.182 WARNING (MainThread) [asyncio] Executing <Handle _SelectorSocketTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.105 seconds
2023-04-16 22:09:28.741 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.105 seconds
2023-04-16 22:09:31.674 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.117 seconds
2023-04-16 22:09:32.916 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.103 seconds
2023-04-16 22:09:34.374 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.156 seconds
2023-04-16 22:09:37.145 WARNING (MainThread) [asyncio] Executing <Task finished name='Task-3110' coro=<NetworkWatcher.async_discover() done, defined at /usr/src/homeassistant/homeassistant/components/dhcp/__init__.py:277> result=None created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.153 seconds
2023-04-16 22:09:37.366 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.103 seconds
2023-04-16 22:09:40.388 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.107 seconds
2023-04-16 22:09:46.000 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3149' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.110 seconds
2023-04-16 22:09:51.271 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3238' coro=<Entity.async_update_ha_state() running at /usr/src/homeassistant/homeassistant/helpers/entity.py:550> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.104 seconds
2023-04-16 22:09:52.560 WARNING (MainThread) [asyncio] Executing <Task finished name='websocket_api.async:websocket_get_translations' coro=<_handle_async_response() done, defined at /usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py:18> result=None created at /usr/src/homeassistant/homeassistant/core.py:545> took 0.109 seconds
2023-04-16 22:09:54.705 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.116 seconds
2023-04-16 22:09:55.157 WARNING (MainThread) [asyncio] Executing <Task pending name='websocket_api.async:config_entry_disable' coro=<_handle_async_response() running at /usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py:26> wait_for=<Task pending name='setup component zha' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:166> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:545> took 0.402 seconds
2023-04-16 22:09:55.379 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.102 seconds
2023-04-16 22:09:56.647 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 1.107 seconds
2023-04-16 22:10:03.478 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component zha' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 6.810 seconds
2023-04-16 22:10:03.797 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.256 seconds
2023-04-16 22:10:09.689 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  zha a3418e288c17071916d3f62c643d927e' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 5.758 seconds
2023-04-16 22:10:10.905 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.123 seconds
2023-04-16 22:10:11.530 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.138 seconds
2023-04-16 22:10:11.866 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.125 seconds
2023-04-16 22:10:12.423 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.352 seconds
2023-04-16 22:10:12.910 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.109 seconds
2023-04-16 22:10:13.272 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.127 seconds
2023-04-16 22:10:13.592 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.128 seconds
2023-04-16 22:10:15.678 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  zha a3418e288c17071916d3f62c643d927e' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/zigpy_zigate/uart.py:135> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.125 seconds
2023-04-16 22:10:16.059 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.181 seconds
2023-04-16 22:10:16.075 WARNING (MainThread) [zigpy_zigate.uart] Invalid length: 0, data: 9
2023-04-16 22:10:17.058 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.111 seconds
2023-04-16 22:10:18.146 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.123 seconds
2023-04-16 22:10:18.475 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.102 seconds
2023-04-16 22:10:21.698 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.100 seconds
2023-04-16 22:10:22.116 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.139 seconds
2023-04-16 22:10:23.183 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.101 seconds
2023-04-16 22:10:23.341 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2878' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.101 seconds
2023-04-16 22:10:23.963 WARNING (MainThread) [zigpy.application] Coordinator does not support energy scanning

All I do to have my system running fine again is run this: ha core update --version=2023.3.6 When the rollback is over, I re-enable ZHA and everything looks OK again

bdraco commented 1 year ago 
2023-04-16 22:08:49.340 ERROR (SyncWorker_5) [homeassistant.util.logging] Exception in updated when handling msg on 'hass.agent/devices/LIBERTY': '{"serial_number":"82255396-88f2-4b64-b31a-8cb2cf63d1aa","device":{"identifiers":"hass.agent-LIBERTY","manufacturer":"LAB02 Research","model":"Microsoft Windows NT 10.0.22621.0","name":"LIBERTY","sw_version":"2022.14.0"},"apis":{"notifications":true,"media_player":true}}'
Traceback (most recent call last):
  File "/config/custom_components/hass_agent/__init__.py", line 147, in updated
    hass.async_create_task(handle_apis_changed(hass, entry, apis))
  File "/usr/src/homeassistant/homeassistant/core.py", line 526, in async_create_task
    task = self.loop.create_task(target, name=name)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 438, in create_task
    task = tasks.Task(coro, loop=self, name=name)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 755, in call_soon
    self._check_thread()
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 792, in _check_thread
    raise RuntimeError(
RuntimeError: Non-thread-safe operation invoked on an event loop other than the current one

I'd try uninstall hass_agent and see if the problem goes away

nerthazrim commented 1 year ago

I'm currently trying to upgrade to 2023.4.5 with the HASS.Agent integration removed. ZHA is currently disabled, my RPI restarted on 2023.4.5 but it's stuck at this step at the moment:

2023-04-18 18:03:34.906 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_entity_id_last_updated_ts` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!

It's taking quite a while for a 250 MB table. I'm waiting to see if there's anything that pops up saying it's done. If not, in a few hours, I'll try to restart my RPI, see if these steps come back or not. If not, I'll try to re-enable ZHA

Anto79-ops commented 1 year ago

FYI @nerthazrim for your hass_agent issue/error message, you may wish to subscribe/comment to this issue. thanks.

nerthazrim commented 1 year ago

FYI @nerthazrim for your hass_agent issue/error message, you may wish to subscribe/comment to this issue. thanks.

Thanks! Please note that even though I can see this error at startup, my HASS Agent is working well on my laptop :) I don't think that the issue is coming from this but let's try

nerthazrim commented 1 year ago

To be on the safe side, I've disabled my recorder configuration snippet to disregard my mariaDB database and store the events locally on the RPI's FS.

Same behavior on 2023.4.5 with HASS.Agent disabled (EDIT: uninstalled, not disabled) and local recorder. HA crashes when ZHA is starting:

2023-04-18 18:32:03.175 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-04-18 18:32:03.187 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration hass_agent which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-04-18 18:32:10.628 WARNING (Recorder) [homeassistant.components.recorder.util] The system could not validate that the sqlite3 database at //config/home-assistant_v2.db was shutdown cleanly
2023-04-18 18:32:12.998 WARNING (MainThread) [homeassistant.components.debugpy] Listening for remote debug connection on 0.0.0.0:5678
2023-04-18 18:32:13.749 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component dhcp' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.478 seconds
2023-04-18 18:32:14.451 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component zeroconf' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.485 seconds
2023-04-18 18:32:15.152 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component bluetooth' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load bluetooth.remote_scanners' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.668 seconds
2023-04-18 18:32:15.361 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component ssdp' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.202 seconds
2023-04-18 18:32:19.360 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component cloud' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load cloud' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 3.661 seconds
2023-04-18 18:32:25.097 WARNING (MainThread) [homeassistant.setup] Setup of bluetooth is taking over 10 seconds.
2023-04-18 18:32:32.242 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component bluetooth' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.116 seconds
2023-04-18 18:32:33.045 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component history' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.341 seconds
2023-04-18 18:32:33.344 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component counter' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load counter' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.291 seconds
2023-04-18 18:32:34.141 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component logbook' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.267 seconds
2023-04-18 18:32:34.258 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component media_source' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.113 seconds
2023-04-18 18:32:35.153 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-616' coro=<_try_async_validate_config_item() running at /usr/src/homeassistant/homeassistant/components/automation/config.py:207> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.191 seconds
2023-04-18 18:32:35.983 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component conversation' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.313 seconds
2023-04-18 18:32:36.178 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup Volets RDC group eaaad56ba3c0edcdad96acb549b0dc94' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.184 seconds
2023-04-18 18:32:36.732 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component met' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.167 seconds
2023-04-18 18:32:37.982 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component hacs' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 1.246 seconds
2023-04-18 18:32:39.000 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component radio_browser' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.600 seconds
2023-04-18 18:32:40.114 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component shelly' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.721 seconds
2023-04-18 18:32:40.431 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component tts' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:216> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.160 seconds
2023-04-18 18:32:41.202 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component vicare' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.575 seconds
2023-04-18 18:32:41.815 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup Home met 10dc80fb2b1012876b1d1035b415fb00' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.486 seconds
2023-04-18 18:32:43.814 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component roomba' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 1.704 seconds
2023-04-18 18:32:46.171 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  hacs d2a50203d20d0fe0511d1d4927e70158' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 2.293 seconds
2023-04-18 18:33:02.313 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component mqtt' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 14.899 seconds
2023-04-18 18:33:03.196 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  hacs d2a50203d20d0fe0511d1d4927e70158' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:864, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.757 seconds
2023-04-18 18:33:03.324 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform group is taking over 10 seconds.
2023-04-18 18:33:03.329 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform group is taking over 10 seconds.
2023-04-18 18:33:03.333 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform group is taking over 10 seconds.
2023-04-18 18:33:03.744 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component unifi' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load unifi_data' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.230 seconds
2023-04-18 18:33:06.641 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component stream' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 2.700 seconds
2023-04-18 18:33:09.335 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component unifiprotect' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 2.474 seconds
2023-04-18 18:33:09.807 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2225' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.139 seconds
2023-04-18 18:33:10.578 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component home_connect' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.492 seconds
2023-04-18 18:33:11.859 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component mobile_app' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load mobile_app' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.170 seconds
2023-04-18 18:33:12.477 WARNING (MainThread) [homeassistant.config_entries] Config entry 'ShellyPlug_Servers' for shelly integration not ready yet: DeviceConnectionError(); Retrying in background
2023-04-18 18:33:12.622 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup udm-pro unifiprotect cb7c21744a386dadedb08241b0355879' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.107 seconds
2023-04-18 18:33:13.101 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup udm-pro unifiprotect cb7c21744a386dadedb08241b0355879' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.263 seconds
2023-04-18 18:33:13.952 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform vicare is taking over 10 seconds.
2023-04-18 18:33:15.428 WARNING (MainThread) [asyncio] Executing <Task finished name='Task-2673' coro=<EntityPlatform._async_add_entity() done, defined at /usr/src/homeassistant/homeassistant/helpers/entity_platform.py:501> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.101 seconds
2023-04-18 18:33:17.099 WARNING (MainThread) [asyncio] Executing <Task finished name='process integration platform diagnostics for unifiprotect' coro=<_async_process_single_integration_platform_component() done, defined at /usr/src/homeassistant/homeassistant/helpers/integration_platform.py:28> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.379 seconds
2023-04-18 18:33:17.751 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2982' coro=<FlowDispatcher._async_start() running at /usr/src/homeassistant/homeassistant/helpers/discovery_flow.py:95> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:492> took 0.279 seconds
2023-04-18 18:33:18.020 WARNING (Recorder) [homeassistant.components.recorder.migration] Database is about to upgrade from schema version: 35 to: 41
2023-04-18 18:33:18.040 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding columns context_id_bin, context_user_id_bin, context_parent_id_bin to table states. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:18.105 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding columns context_id_bin, context_user_id_bin, context_parent_id_bin to table events. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:18.150 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_events_context_id_bin` to table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:18.244 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_states_context_id_bin` to table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:19.703 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.974 seconds
2023-04-18 18:33:19.717 WARNING (Recorder) [homeassistant.components.recorder.migration] Upgrade to version 36 done
2023-04-18 18:33:19.723 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding columns event_type_id to table events. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:19.734 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_events_event_type_time_fired_ts` from table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:19.822 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_events_event_type_id_time_fired_ts` to table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:19.863 WARNING (Recorder) [homeassistant.components.recorder.migration] Upgrade to version 37 done
2023-04-18 18:33:19.870 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding columns metadata_id to table states. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:19.886 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_states_metadata_id_last_updated_ts` to table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.152 WARNING (Recorder) [homeassistant.components.recorder.migration] Upgrade to version 38 done
2023-04-18 18:33:20.156 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_events_event_type_time_fired_ts` from table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.180 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_events_event_type` from table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.202 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_events_event_type_time_fired` from table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.284 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_events_time_fired` from table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.408 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_events_context_user_id` from table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.483 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_events_context_parent_id` from table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.604 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_entity_id_last_updated` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.625 WARNING (MainThread) [asyncio] Executing <Task finished name='Task-3024' coro=<HacsBase.async_get_category_repositories() done, defined at /config/custom_components/hacs/base.py:898> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.289 seconds
2023-04-18 18:33:20.657 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_last_updated` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.706 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_entity_id` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.738 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_context_user_id` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.767 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_context_parent_id` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.808 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_created_domain` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:20.844 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_entity_id_created` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.009 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `states__state_changes` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.056 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `states__significant_changes` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.083 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_entity_id_created` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.114 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_statistics_statistic_id_start` from table `statistics`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.131 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_statistics_short_term_statistic_id_start` from table `statistics_short_term`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.163 WARNING (Recorder) [homeassistant.components.recorder.migration] Upgrade to version 39 done
2023-04-18 18:33:21.171 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_events_event_type_id` from table `events`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.188 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_states_metadata_id` from table `states`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.212 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_statistics_metadata_id` from table `statistics`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.258 WARNING (Recorder) [homeassistant.components.recorder.migration] Dropping index `ix_statistics_short_term_metadata_id` from table `statistics_short_term`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.355 WARNING (Recorder) [homeassistant.components.recorder.migration] Upgrade to version 40 done
2023-04-18 18:33:21.378 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_event_types_event_type` to table `event_types`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.388 WARNING (Recorder) [homeassistant.components.recorder.migration] Index ix_event_types_event_type already exists on event_types, continuing
2023-04-18 18:33:21.398 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_states_meta_entity_id` to table `states_meta`. Note: this can take several minutes on large databases and slow computers. Please be patient!
2023-04-18 18:33:21.408 WARNING (Recorder) [homeassistant.components.recorder.migration] Index ix_states_meta_entity_id already exists on states_meta, continuing
2023-04-18 18:33:21.441 WARNING (Recorder) [homeassistant.components.recorder.migration] Upgrade to version 41 done
2023-04-18 18:33:22.453 WARNING (MainThread) [asyncio] Executing <Task finished name='config entry flow cast e4cc02e50b28ebf957817c9662172d98' coro=<ConfigEntriesFlowManager._async_init() done, defined at /usr/src/homeassistant/homeassistant/config_entries.py:850> result=(<homeassistan... 0x7f856c0070>, {'description_placeholders': None, 'flow_id': 'e4cc02e50b28...17c9662172d98', 'handler': 'cast', 'reason': 'single_instance_allowed', ...}) created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 1.433 seconds
2023-04-18 18:33:23.474 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2225' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.101 seconds
2023-04-18 18:33:23.800 WARNING (MainThread) [asyncio] Executing <Task finished name='Task-3025' coro=<HacsBase.async_get_category_repositories() done, defined at /config/custom_components/hacs/base.py:898> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.303 seconds
2023-04-18 18:33:23.964 WARNING (MainThread) [asyncio] Executing <Task finished name='Task-3026' coro=<HacsBase.async_get_category_repositories() done, defined at /config/custom_components/hacs/base.py:898> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.122 seconds
2023-04-18 18:33:24.230 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2995' coro=<ConfigEntry.async_setup.<locals>.setup_again() running at /usr/src/homeassistant/homeassistant/config_entries.py:453> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:864, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:492> took 0.197 seconds
2023-04-18 18:33:24.530 WARNING (MainThread) [asyncio] Executing <Handle cancelled _SelectorSocketTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.129 seconds
2023-04-18 18:33:24.754 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.142 seconds
2023-04-18 18:33:25.312 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.103 seconds
2023-04-18 18:33:26.648 WARNING (MainThread) [asyncio] Executing <Task finished name='config entry flow spotify 9760b48273b88e497e4099bed37e7847' coro=<ConfigEntriesFlowManager._async_init() done, defined at /usr/src/homeassistant/homeassistant/config_entries.py:850> result=(<homeassistan... 0x7f842ca7a0>, {'description_placeholders': None, 'flow_id': '9760b48273b8...099bed37e7847', 'handler': 'spotify', 'reason': 'missing_credentials', ...}) created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 1.282 seconds
2023-04-18 18:33:27.063 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3078' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.235 seconds
2023-04-18 18:33:27.354 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry flow shelly 3e8e76c2a83165f5af9dfa29205b2181' coro=<ConfigEntriesFlowManager._async_init() running at /usr/src/homeassistant/homeassistant/config_entries.py:868> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.139 seconds
2023-04-18 18:33:27.953 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2995' coro=<ConfigEntry.async_setup.<locals>.setup_again() running at /usr/src/homeassistant/homeassistant/config_entries.py:453> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:492> took 0.134 seconds
2023-04-18 18:33:28.385 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.346 seconds
2023-04-18 18:33:28.531 WARNING (MainThread) [asyncio] Executing <Task pending name='call_later 10' coro=<Store._async_callback_delayed_write() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:260> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:492> took 0.130 seconds
2023-04-18 18:33:29.325 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.329 seconds
2023-04-18 18:33:29.497 WARNING (MainThread) [asyncio] Executing <Handle cancelled _SelectorSocketTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.132 seconds
2023-04-18 18:33:29.791 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.210 seconds
2023-04-18 18:33:30.172 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2995' coro=<ConfigEntry.async_setup.<locals>.setup_again() running at /usr/src/homeassistant/homeassistant/config_entries.py:453> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:492> took 0.167 seconds
2023-04-18 18:33:30.401 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry forward setup ShellyPlug_Servers shelly 85786a8de5d599725601f1a43cde403d binary_sensor' coro=<ConfigEntries.async_forward_entry_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:1408> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:864, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.174 seconds
2023-04-18 18:33:34.914 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3039' coro=<NetworkWatcher.async_discover() running at /usr/src/homeassistant/homeassistant/components/dhcp/__init__.py:280> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.117 seconds
2023-04-18 18:33:35.238 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.138 seconds
2023-04-18 18:33:35.539 WARNING (MainThread) [asyncio] Executing <Handle _SelectorDatagramTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.289 seconds
2023-04-18 18:33:37.278 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3039' coro=<NetworkWatcher.async_discover() running at /usr/src/homeassistant/homeassistant/components/dhcp/__init__.py:280> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 1.069 seconds
2023-04-18 18:34:09.176 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.122 seconds
2023-04-18 18:34:37.048 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2225' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.155 seconds
2023-04-18 18:34:43.582 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.104 seconds
2023-04-18 18:34:48.814 WARNING (MainThread) [asyncio] Executing <Task pending name='websocket_api.async:config_entry_disable' coro=<_handle_async_response() running at /usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py:26> wait_for=<Task pending name='setup component zha' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:166> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:545> took 0.252 seconds
2023-04-18 18:34:55.610 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component zha' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 6.578 seconds
2023-04-18 18:34:58.342 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  zha a3418e288c17071916d3f62c643d927e' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 2.588 seconds
2023-04-18 18:34:58.643 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.149 seconds
2023-04-18 18:35:00.565 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2924' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.116 seconds
2023-04-18 18:35:01.133 WARNING (MainThread) [zigpy_zigate.uart] Invalid length: 0, data: 9
2023-04-18 18:35:04.112 WARNING (MainThread) [asyncio] Executing <Handle SerialTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 1.215 seconds
2023-04-18 18:35:10.395 WARNING (MainThread) [zigpy.application] Coordinator does not support energy scanning
bdraco commented 1 year ago

Non-thread-safe operation means it will randomly cause a crash because it will modify the data in another thread and then that other thread goes to do something it it, it will fail in an unexpected way. In this case it's likely modifying the event loop scheduling so if that fails everything collapses

nerthazrim commented 1 year ago

Non-thread-safe operation means it will randomly cause a crash because it will modify the data in another thread and then that other thread goes to do something it it, it will fail in an unexpected way. In this case it's likely modifying the event loop scheduling so if that fails everything collapses Understood.

Still... HASS.Agent is uninstalled and I still have the same issue :( Sorry, made a mistake in my previous answer. HASS.Agent is uninstalled, not just disabled.

Any idea? :(

bdraco commented 1 year ago

Post another log without hass agent muddying the water

nerthazrim commented 1 year ago

My bad, I forgot that HASS.Agent is a custom integration and needed to be uninstalled also in HACS.

So, HASS.Agent totally uninstalled, recorder customization disabled (default settings now), same thing. I restarted my RPI running HA Core 2023.4.5 with ZHA, all good. I start ZHA and HA Core crashes:

2023-04-18 19:12:55.028 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-04-18 19:13:05.655 WARNING (MainThread) [asyncio] Executing <Task finished name='Task-224' coro=<RequestHandler._handle_request() done, defined at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:423> result=(<Response OK eof>, False) created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 1.366 seconds
2023-04-18 19:13:05.678 WARNING (MainThread) [homeassistant.components.debugpy] Listening for remote debug connection on 0.0.0.0:5678
2023-04-18 19:13:06.157 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component dhcp' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.283 seconds
2023-04-18 19:13:06.746 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-246' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.163 seconds
2023-04-18 19:13:07.666 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component bluetooth' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load bluetooth.remote_scanners' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.732 seconds
2023-04-18 19:13:08.451 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component zeroconf' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.603 seconds
2023-04-18 19:13:08.762 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component ssdp' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.197 seconds
2023-04-18 19:13:11.442 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component cloud' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load cloud' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 2.451 seconds
2023-04-18 19:13:17.611 WARNING (MainThread) [homeassistant.setup] Setup of bluetooth is taking over 10 seconds.
2023-04-18 19:13:24.501 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component bluetooth' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.118 seconds
2023-04-18 19:13:25.046 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component history' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.208 seconds
2023-04-18 19:13:25.852 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component logbook' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.164 seconds
2023-04-18 19:13:28.526 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component unifiprotect' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 2.241 seconds
2023-04-18 19:13:29.288 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component radio_browser' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.178 seconds
2023-04-18 19:13:30.053 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component hacs' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.760 seconds
2023-04-18 19:13:31.167 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component unifi' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load unifi_data' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.217 seconds
2023-04-18 19:13:33.162 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component roomba' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 1.869 seconds
2023-04-18 19:13:33.515 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup udm-pro unifiprotect cb7c21744a386dadedb08241b0355879' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.105 seconds
2023-04-18 19:13:33.685 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component tts' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:216> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.140 seconds
2023-04-18 19:13:35.989 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  hacs d2a50203d20d0fe0511d1d4927e70158' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 2.122 seconds
2023-04-18 19:13:38.931 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component stream' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 2.921 seconds
2023-04-18 19:13:40.690 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  hacs d2a50203d20d0fe0511d1d4927e70158' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:864, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.812 seconds
2023-04-18 19:13:40.911 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component hardware' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.106 seconds
2023-04-18 19:13:41.158 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component conversation' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.239 seconds
2023-04-18 19:13:41.682 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup Home met 10dc80fb2b1012876b1d1035b415fb00' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.463 seconds
2023-04-18 19:13:41.966 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup udm-pro unifiprotect cb7c21744a386dadedb08241b0355879' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.207 seconds
2023-04-18 19:13:43.273 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component vicare' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 1.024 seconds
2023-04-18 19:13:43.705 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component shelly' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.146 seconds
2023-04-18 19:13:59.453 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component mqtt' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 15.645 seconds
2023-04-18 19:13:59.589 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform roomba is taking over 10 seconds.
2023-04-18 19:13:59.592 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform roomba is taking over 10 seconds.
2023-04-18 19:14:00.126 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component home_connect' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.151 seconds
2023-04-18 19:14:01.039 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component mobile_app' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:256> wait_for=<Task pending name='Storage load mobile_app' coro=<Store._async_load() running at /usr/src/homeassistant/homeassistant/helpers/storage.py:124> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove(), <1 more>, Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.149 seconds
2023-04-18 19:14:05.569 WARNING (MainThread) [asyncio] Executing <Task finished name='process integration platform diagnostics for unifiprotect' coro=<_async_process_single_integration_platform_component() done, defined at /usr/src/homeassistant/homeassistant/helpers/integration_platform.py:28> result=None created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.373 seconds
2023-04-18 19:14:07.778 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3023' coro=<gather_with_concurrency.<locals>.sem_task() running at /usr/src/homeassistant/homeassistant/util/async_.py:176> wait_for=<Task pending name='config entry flow cast 99c11af67ad141b1ed4653f5c8cb29be' coro=<ConfigEntriesFlowManager._async_init() running at /usr/src/homeassistant/homeassistant/config_entries.py:850> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.881 seconds
2023-04-18 19:14:08.284 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-246' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.185 seconds
2023-04-18 19:14:08.548 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2769' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.250 seconds
2023-04-18 19:14:08.882 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry flow cast a0d52e980345480f586e3b8123ffd31b' coro=<ConfigEntriesFlowManager._async_init() running at /usr/src/homeassistant/homeassistant/config_entries.py:858> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:665> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.186 seconds
2023-04-18 19:14:14.264 WARNING (MainThread) [asyncio] Executing <Task pending name='unifiprotect-discovery' coro=<async_start_discovery.<locals>._async_discovery() running at /usr/src/homeassistant/homeassistant/components/unifiprotect/discovery.py:33> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:545> took 5.359 seconds
2023-04-18 19:14:14.633 WARNING (MainThread) [asyncio] Executing <Handle cancelled _SelectorSocketTransport._read_ready() created at /usr/local/lib/python3.10/asyncio/selector_events.py:254> took 0.112 seconds
2023-04-18 19:14:15.417 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3061' coro=<NetworkWatcher.async_discover() running at /usr/src/homeassistant/homeassistant/components/dhcp/__init__.py:280> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.10/asyncio/futures.py:385, Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.104 seconds
2023-04-18 19:14:15.751 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2769' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.288 seconds
2023-04-18 19:14:16.051 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3061' coro=<NetworkWatcher.async_discover() running at /usr/src/homeassistant/homeassistant/components/dhcp/__init__.py:280> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 0.109 seconds
2023-04-18 19:14:17.171 WARNING (MainThread) [asyncio] Executing <Task finished name='config entry flow cast a0d52e980345480f586e3b8123ffd31b' coro=<ConfigEntriesFlowManager._async_init() done, defined at /usr/src/homeassistant/homeassistant/config_entries.py:850> result=(<homeassistan... 0x7f64850190>, {'description_placeholders': None, 'flow_id': 'a0d52e980345...e3b8123ffd31b', 'handler': 'cast', 'reason': 'single_instance_allowed', ...}) created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 1.116 seconds
2023-04-18 19:14:17.667 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2769' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.117 seconds
2023-04-18 19:14:18.712 WARNING (MainThread) [asyncio] Executing <Task finished name='config entry flow spotify 46b6cb94cb77d86c08fd357f3abff1c8' coro=<ConfigEntriesFlowManager._async_init() done, defined at /usr/src/homeassistant/homeassistant/config_entries.py:850> result=(<homeassistan... 0x7f65738970>, {'description_placeholders': None, 'flow_id': '46b6cb94cb77...d357f3abff1c8', 'handler': 'spotify', 'reason': 'missing_credentials', ...}) created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 0.503 seconds
2023-04-18 19:14:18.828 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3109' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:433> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py:508> took 0.106 seconds
2023-04-18 19:14:21.914 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-3134' coro=<HacsIntegrationRepository.update_repository() running at /config/custom_components/hacs/utils/decorator.py:28> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:636> took 0.971 seconds
2023-04-18 19:14:24.520 WARNING (MainThread) [asyncio] Executing <Task finished name='websocket_api.async:hacs_repositories_list' coro=<_handle_async_response() done, defined at /usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py:18> result=None created at /usr/src/homeassistant/homeassistant/core.py:545> took 0.126 seconds
2023-04-18 19:15:05.467 WARNING (MainThread) [asyncio] Executing <Task pending name='websocket_api.async:config_entry_disable' coro=<_handle_async_response() running at /usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py:26> wait_for=<Task pending name='setup component zha' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:166> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:545> took 0.742 seconds
2023-04-18 19:15:11.259 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component zha' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:289> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:526> took 5.651 seconds
2023-04-18 19:15:13.720 WARNING (MainThread) [asyncio] Executing <Task pending name='config entry setup  zha a3418e288c17071916d3f62c643d927e' coro=<ConfigEntry.async_setup() running at /usr/src/homeassistant/homeassistant/config_entries.py:383> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.10/asyncio/tasks.py:720] created at /usr/local/lib/python3.10/asyncio/tasks.py:337> took 2.389 seconds
2023-04-18 19:15:14.856 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2769' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.118 seconds
2023-04-18 19:15:15.281 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2769' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 0.174 seconds
2023-04-18 19:15:17.009 WARNING (MainThread) [zigpy_zigate.uart] Invalid length: 0, data: 9
2023-04-18 19:15:19.348 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-2769' coro=<WSClient.running() running at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:95> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.10/asyncio/base_events.py:429> created at /usr/local/lib/python3.10/site-packages/aiounifi/websocket.py:81> took 1.147 seconds
2023-04-18 19:15:25.456 WARNING (MainThread) [zigpy.application] Coordinator does not support energy scanning
nerthazrim commented 1 year ago

And FYI: same behavior with HACS completely removed

Oh and I also have netdata running on the RPI. I've disabled it for my latest tests, so it does not seem to be some kind of interference coming from it

nerthazrim commented 1 year ago

I'm keeping my HA on latest version for now, with ZHA disabled, hoping you'll find something.

I'll have to revert to 2023.3.6 and working ZHA later today though. A big thank again for your time :)

nerthazrim commented 1 year ago

I've tried anything I could think of, unfortunately no good news. Still crash looping if updating HA Core higher than 2023.3 :(

puddly commented 1 year ago

What specific ZiGate are you using and on what hardware?

I'm seeing this in your log:

2023-04-18 18:35:01.133 WARNING (MainThread) [zigpy_zigate.uart] Invalid length: 0, data: 9
nerthazrim commented 1 year ago

Hi @puddly,

I'm using a PiZigate+, on firmware 13, plugged on my RPI 3B.

puddly commented 1 year ago

The (nearly deprecated) PiZiGate+ is unique in that it requires GPIO toggling to boot up. However, once that is done, it works just like any other serial device. From your log, it looks like the ZiGate starts up fine and ZHA is able to initialize.

Can you enable ZHA debug logging? https://www.home-assistant.io/integrations/zha/#debug-logging.

nerthazrim commented 1 year ago

Here you go, hoping you'll find something: https://pastebin.com/e7PVMHJ2

FYI: I disabled the HASS.Agent integration and the recorder to my mariadb, nothing else. And ZHA initially, obviously. I updated to 2023.4.5, rebooted the whole RPI, then enabled ZHA when HA was fully started.

What do you mean by "nearly depecrated"? Should I open an issue on their github asking for something specific?

Thanks again!

Bkl741 commented 1 year ago

Hi,

I have the same problem and I was suspected zigate. When i started with HA and ZHA I have to rollback to a previous firmware to appairing zigate.

puddly commented 1 year ago

What specific ZiGate are you running and on what hardware?

Bkl741 commented 1 year ago

I’m running zigate v1 with firmware 3.21 on freebox delta with virtualization

puddly commented 1 year ago

ZiGate USB or PiZiGate? Also, can you gather debug logs?

Bkl741 commented 1 year ago

Zigate usb. In logs I have nothing else that :

Logger: homeassistant.components.recorder.util Source: components/recorder/util.py:238 Integration: Recorder First occurred: 12:06:18 (1 occurrences) Last logged: 12:06:18

The system could not validate that the sqlite3 database at //config/home-assistant_v2.db was shutdown cleanly