pnbruckner / ha-entity-tz

Home Assistant Entity Time Zone Sensor
The Unlicense
3 stars 0 forks source link

long setup times (possibly causing other timing related problems.) #4

Closed Mariusthvdb closed 8 months ago

Mariusthvdb commented 8 months ago

running debugpy because BDraco asked me while we were trying to find the root cause of some severe timing loggings, we noticed these:

2024-02-12 18:04:13.813 WARNING (MainThread) [asyncio] Executing <Task pending name='setup component entity_tz' coro=<_async_setup_component() running at /usr/src/homeassistant/homeassistant/setup.py:366> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/core.py:633> took 8.793 seconds

2024-02-12 18:05:18.088 WARNING (MainThread) [asyncio] Executing <Handle init_etz_data.<locals>.update_zones(<Event core_config_updated[L]>) at /config/custom_components/entity_tz/helpers.py:110 created at /usr/src/homeassistant/homeassistant/core.py:601> took 8.867 seconds

I seem to recall when you started this new integration, you mentioned downloading an external library, or expected it to be available already because HA uses it also.

Not sure anymore, but please have a look if this could be improved?

thanks, Marius

pnbruckner commented 8 months ago

You're thinking of the composite integration when it had the time zone features. It would load the selected timezonefinder package itself rather than letting HA do it automatically via the manifest.json file. That does not apply here.

The times you're seeing are a result of determining the time zone for each configured HA zone. It does this to decide which zones to list in the config flow. It needs to do this when it first starts (i.e., when the integration is set up), but also whenever any zone changes or when the core config changes. For each zone it makes a call to a timezonefinder method, which apparently takes a while.

Currently this is done in a callback, but it should probably be done in a coroutine which yields for each call to the timezonefinder method. I'll add this to my TO DO list...

pnbruckner commented 8 months ago

I'll release this change in 1.0.2 momentarily. Give it a try and let me know if it helps. It won't make the setup of the integration go any faster, but it shouldn't be hogging the MainThread anymore while it's determining each zone's time zone.

Mariusthvdb commented 8 months ago

thanks Phil, and sorry to be confusing with Composite...

would it make any difference to leave out the address entity? or is that all done in 1 go. (I could possibly live without the address as it is also provided by the mobile_app integration) leaving your integration only to calculate the timezone related entities in that case.

Id rather not, an have it all sourced by the same integration obviously.

pnbruckner commented 8 months ago

Addresses are determined by the geopy package's Nominatim class, and time zones are determined by the timezonefinder package's TimezoneFinder class. The problem was related to the use of the latter, not the former. Bottom line, no, it would not make any difference.

bdraco commented 8 months ago

I don't know this library very well, but if time zone is always the same for a specific lat/long maybe its possible to cache the lat/long to tz lookup in get_tz?

Something like.....

    return _get_time_zone_for_lat_lng(etz_data(hass).tzf, lat, lng)

@lru_cache
def _get_time_zone_for_lat_lng(tzf: TimezoneFinder, lat: float, lng: float) -> tzinfo | None:
    tz_name = tzf.timezone_at(lat=lat, lng=lng)
    if tz_name is None:
        return None
    return dt_util.get_time_zone(tz_name)
bdraco commented 8 months ago

It definitely helped to break things up 👍 I think that operation is expensive though. You can see the impact is stretched out now and doesn't block the event loop for as long with the new log Marius sent:

2024-02-13 17:34:21.717 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.225 seconds
2024-02-13 17:34:21.954 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.223 seconds
2024-02-13 17:34:22.488 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.225 seconds
2024-02-13 17:34:22.733 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.227 seconds
2024-02-13 17:34:27.821 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.218 seconds
2024-02-13 17:34:28.059 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.231 seconds
2024-02-13 17:34:28.728 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.228 seconds
2024-02-13 17:34:28.965 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.229 seconds
2024-02-13 17:34:31.594 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.294 seconds
2024-02-13 17:34:31.991 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.319 seconds
2024-02-13 17:34:35.161 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.342 seconds
2024-02-13 17:34:35.555 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.322 seconds
2024-02-13 17:34:36.572 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.275 seconds
2024-02-13 17:34:40.281 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.406 seconds
2024-02-13 17:34:40.585 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.276 seconds
2024-02-13 17:34:41.398 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.252 seconds
2024-02-13 17:34:43.574 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.241 seconds
2024-02-13 17:34:43.815 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.233 seconds
2024-02-13 17:34:44.687 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.261 seconds
2024-02-13 17:34:44.988 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.286 seconds
2024-02-13 17:34:45.563 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.265 seconds
2024-02-13 17:34:45.831 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.255 seconds
2024-02-13 17:34:46.329 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.266 seconds
2024-02-13 17:34:46.606 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.259 seconds
2024-02-13 17:34:48.372 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.262 seconds
2024-02-13 17:34:48.642 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.259 seconds
2024-02-13 17:34:49.350 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.267 seconds
2024-02-13 17:34:49.602 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.237 seconds
2024-02-13 17:34:50.063 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.231 seconds
2024-02-13 17:34:50.449 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.232 seconds
2024-02-13 17:34:50.691 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.233 seconds
2024-02-13 17:34:51.126 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.251 seconds
2024-02-13 17:34:51.368 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.233 seconds
2024-02-13 17:34:51.814 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.231 seconds
2024-02-13 17:34:52.061 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.231 seconds
2024-02-13 17:34:52.649 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.231 seconds
2024-02-13 17:34:52.910 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.228 seconds
2024-02-13 17:34:53.307 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.229 seconds
2024-02-13 17:34:53.549 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.225 seconds
2024-02-13 17:34:53.922 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.223 seconds
2024-02-13 17:34:54.157 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.225 seconds
2024-02-13 17:34:54.537 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.219 seconds
2024-02-13 17:34:54.888 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.239 seconds
2024-02-13 17:34:55.207 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.287 seconds
2024-02-13 17:34:55.553 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.223 seconds
2024-02-13 17:34:55.794 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.221 seconds
2024-02-13 17:34:56.099 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.236 seconds
2024-02-13 17:34:56.366 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.225 seconds
2024-02-13 17:34:56.755 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.224 seconds
2024-02-13 17:34:56.991 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.220 seconds
2024-02-13 17:34:57.366 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.244 seconds
2024-02-13 17:34:57.670 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.228 seconds
2024-02-13 17:34:57.908 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.224 seconds
2024-02-13 17:34:58.251 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.231 seconds
2024-02-13 17:34:58.621 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.227 seconds
2024-02-13 17:34:58.980 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.221 seconds
2024-02-13 17:34:59.229 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.242 seconds
2024-02-13 17:34:59.565 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.224 seconds
2024-02-13 17:35:00.031 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.224 seconds
2024-02-13 17:35:00.992 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.223 seconds
2024-02-13 17:35:01.226 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.227 seconds
2024-02-13 17:35:01.832 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.220 seconds
2024-02-13 17:35:02.085 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.223 seconds
2024-02-13 17:35:02.661 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.225 seconds
2024-02-13 17:35:03.538 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.223 seconds
2024-02-13 17:35:03.775 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.224 seconds
2024-02-13 17:35:04.823 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.224 seconds
2024-02-13 17:35:08.462 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.237 seconds
2024-02-13 17:35:09.632 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.223 seconds
2024-02-13 17:35:10.479 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.223 seconds
2024-02-13 17:35:10.958 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.233 seconds
2024-02-13 17:35:11.359 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.268 seconds
2024-02-13 17:35:12.742 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.226 seconds
2024-02-13 17:35:13.379 WARNING (MainThread) [asyncio] Executing <Task pending name='listen core_config_updated' coro=<init_etz_data.<locals>.update_zones() running at /config/custom_components/entity_tz/helpers.py:119> cb=[set.remove()] created at /usr/src/homeassistant/homeassistant/core.py:597> took 0.226 seconds
2024-02-13 17:37:33.063 WARNING (MainThread) [asyncio] Executing <Task finished name='Entity update' coro=<async_setup_entry.<locals>.update_from_entity() done, defined at /config/custom_components/entity_tz/__init__.py:78> result=None created at /usr/src/homeassistant/homeassistant/core.py:652> took 0.247 seconds
2024-02-13 17:42:34.475 WARNING (MainThread) [asyncio] Executing <Task finished name='Entity update' coro=<async_setup_entry.<locals>.update_from_entity() done, defined at /config/custom_components/entity_tz/__init__.py:78> result=None created at /usr/src/homeassistant/homeassistant/core.py:652> took 0.261 seconds
2024-02-13 17:47:34.329 WARNING (MainThread) [asyncio] Executing <Task finished name='Entity update' coro=<async_setup_entry.<locals>.update_from_entity() done, defined at /config/custom_components/entity_tz/__init__.py:78> result=None created at /usr/src/homeassistant/homeassistant/core.py:652> took 0.293 seconds
pnbruckner commented 8 months ago

I can definitely add the caching. AFAIK, the results shouldn't be different over time for the same inputs.

I probably should also ignore core_config_updated events that don't have any data (i.e., those first two that get issued for some reason, but don't really mean anything has changed.)

pnbruckner commented 8 months ago

The only problem with using lru_cache is, this function is also called whenever the main entity changes state. So, as the entity moves, the cache will be flushed out with new lat/lon values. Then the next time the zones need to be updated, their locations will probably not be in the cache anymore.

I do cache lat/lon values when using geopy's Nominatim class. In that case I'm actually using alru_cache, and I update the cache size dynamically. And I limit the resolution of lat & lon to four digits (which is about 11 meters.) Maybe I can do something similar for TimezoneFinder.timezone_at, too. Hmm...

pnbruckner commented 8 months ago

Released as 1.1.0. Let me know how it works for you.

pnbruckner commented 8 months ago

FYI, if you enable debug logging for entity_tz, it will spit out cache statistics for both caches (using the cache_info methods.) E.g.:

2024-02-13 15:34:05.715 DEBUG (MainThread) [custom_components.entity_tz] Location cache: CacheInfo(hits=50, misses=54, maxsize=112, currsize=54)
2024-02-13 15:34:05.715 DEBUG (MainThread) [custom_components.entity_tz.helpers] Time zone cache: CacheInfo(hits=48, misses=65, maxsize=128, currsize=65)