longer setup timings related to Spook integration

[Mariusthvdb]

What version of Spook are you using?

2.2.1

What version of Home Assistant are you using?

2024.2.x

The problem

running debugpy on Bdraco request reveals several integrations reporting longer setup timings. Per request, I report those in separate issues, here the ones mentioning Spook

maybe its not caused by Spook, and it is in fact a HA issue, please close then and Ill report in Ha.

Anything in the logs? Paste it here!

2024-02-12 18:06:31.364 WARNING (MainThread) [asyncio] Executing <Task finished name='debouncer cooldown=3, immediate=False' coro=<AbstractSpookRepair.async_activate.<locals>._async_inspect() done, defined at /config/custom_components/spook/repairs.py:139> result=None created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.741 seconds
2024-02-12 18:06:35.222 WARNING (MainThread) [asyncio] Executing <Task finished name='debouncer cooldown=3, immediate=False' coro=<AbstractSpookRepair.async_activate.<locals>._async_inspect() done, defined at /config/custom_components/spook/repairs.py:139> result=None created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.695 seconds
2024-02-12 18:06:40.181 WARNING (MainThread) [asyncio] Executing <Task finished name='debouncer cooldown=3, immediate=False' coro=<AbstractSpookRepair.async_activate.<locals>._async_inspect() done, defined at /config/custom_components/spook/repairs.py:139> result=None created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.728 seconds

[bdraco]

Its likely one or more of these that has the slowdown. I haven't dug through them yet though

custom_components/spook/ectoplasms/automation/repairs/unknown_area_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/automation/repairs/unknown_device_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/automation/repairs/unknown_entity_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/automation/repairs/unknown_service_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/group/repairs/unknown_members.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/integration/repairs/unknown_source.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/lovelace/repairs/unknown_entity_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/proximity/repairs/unknown_ignored_zones.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/proximity/repairs/unknown_tracked_entities.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/proximity/repairs/unknown_zone.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/scene/repairs/unknown_entity_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/script/repairs/unknown_area_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/script/repairs/unknown_device_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/script/repairs/unknown_entity_references.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/switch_as_x/repairs/unknown_source.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/trend/repairs/unknown_source.py:    async def async_inspect(self) -> None:
custom_components/spook/ectoplasms/utility_meter/repairs/unknown_source.py:    async def async_inspect(self) -> None:

[bdraco]

Looking at them, the answer may be that they are going to be expensive and thats just the way it is. Inspect could probably be deferred to happen after the started event though (if it doesn't already)

[frenck]

They run after the started event, (repairs are not attached before that) as before that, they don't have much use to run (integrations aren't loaded).

They might be expensive at times, and I am sure optimizations are still possible. They should (individually) only run if possible data of interest changes for each of them. Eg, when a new integration loads, and automation changes, registry updates and things like that. As those events can rapidly follow up on each other, they are debounced.

[bdraco]

Looking at the look Marius sent: They happen after 2024-02-12 18:05:09.043 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 106.19s so it shouldn't be affecting startup.

This one seems lower priority to optimize

[Anto79-ops]

I experienced exactly the same thing based on turning on debugpy, and thought it was that.

I had three updates from spook that I still did not add as I was waiting for another reason to restart my system (enabling debugpy was that reason).

@bdraco has my logs from the slow startup, if you want to confirm the same issues or not?

[frenck]

Honestly... it is not an issue :)

[bdraco]

It looks like the util code runs a bit more than expected in a 60s period. I haven't investigated why yet though.

[frenck]

Oh that makes tons of sense, let me fix that quickly.

[Mariusthvdb]

Just fyi, the above findings are with the 3 devices disabled, Spook is only enabled because of the need for its services dis/enable config_entry.

[frenck]

@Mariusthvdb These are not related to the devices Spook creates. These are the repair inspections.