log time delay of domain setup in info level 8000 #7808
Conversation
* when setup problems appear, it's difficult to debug which are the components that took a lot to set up. This minimal change goes further than the 'slow setup warning' and measures the setup time interval for each domain.
|
Origin of this PR: After some changes and a big update, I went from 40secs to 750 secs!! of setup time, with no clues and a lot of 'slow' domain setups, and I missed some info about the time needed for each domain. It turned out to be the recorder, which was a mysql db in other machine (a NAS). Changing to a local mysql fixed my setup time to 30s. |
|
I'm not sure how helpfull that is. We have no controll over the asnyc loop, so you timestamp is not realy correct. The same problem is with the warnings. You had track that problem with this change? Look also into helper/entity.py to see how messure need to look for work correct. |
|
@pvizeli, you mean like this? from timeit import default_timer as timer
start = timer()
...
...
finally:
warn_task.cancel()
end = timer()
_LOGGER.info("Setup of domain %s took %.1f seconds.", domain, end - start)I know it is not a good measure, and the time consumed by each domain is going to be variable, but in my experience with the headache I described, this pseudo-measure helped me to see where the problem was. As you are now logging the starting point of each domain setup in the info level, I thought it could be useful for other people to log also the end point, so has it be for me. I normally don't use the info level with components.setup, but when making changes, or upgrading, I usually activate some more logging. |
|
For me is okay, @balloob ? |
|
It's fine with me but I think that the info about component setup time might not be as interesting compared to the info on a per platform basis? https://github.com/home-assistant/home-assistant/blob/dev/homeassistant/helpers/entity_component.py#L147-L173 |
|
@balloob, I could do the same per platform, or only per platform, as requested. logger:
default: warn
logs:
# for the per-domain msg:
homeassistant.setup: info
# for the per-platform msg:
components.XXXX.YYYY: info |
|
We always print info and higher (error etc). Only debug is not printed to the console. |
Description:
When setup problems appear in a complex config, it's difficult to debug which are the components that took a lot to set up. This minimal change goes further than the 'slow setup warning' and measures the setup time interval for each domain.
Example entry for
configuration.yaml(if applicable):