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
71.34k stars 29.88k forks source link

Some integrations are slow to finish startup #75926

Closed hmmbob closed 1 year ago

hmmbob commented 2 years ago

The problem

SQL keeps topping my startup time list since 2022.8.0b0 (same on b3):

edit: it appears to be more generic than just SQL. I am seeing major startup delays on 2022.8 that don't show on 2022.7. At first I thought it was only the SQL sensor, but by comparing it looks like many integrations are way slower to start. First image is 2022.8, 2nd image is 2022.7. I expect multicrape and restful to be slower by nature (they'll never get close to 1 second), but these also doubled in startup time

Running container, no changes to the host or so between switching image versions. 2022.8: image

2022.7: 2022 7

What version of Home Assistant Core has the issue?

core-2022.8.0b0

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

Link to integration documentation on our website

Diagnostics information

No response

Example YAML snippet

Anything in the logs that might be useful for us?

Logger: homeassistant.bootstrap
Source: bootstrap.py:435
First occurred: 12:58:22 (1 occurrences)
Last logged: 12:58:22

Waiting on integrations to complete setup: sql, rest, hacs, mqtt, multiscrape, rituals_perfume_genie, xiaomi_miio, version, waze_travel_time, picnic, esphome

Logger: homeassistant.setup Source: runner.py:119 First occurred: 12:57:31 (2 occurrences) Last logged: 12:57:46

Setup of rest is taking over 10 seconds. Setup of multiscrape is taking over 10 seconds.

Additional information

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

Hey there @dgomes, @gjohansson-st, mind taking a look at this issue as it has been labeled with an integration (sql) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

sql documentation sql source (message by IssueLinks)

dgomes commented 2 years ago

Hi!

I would say that there isn't much that can be done, your query is simply very slow to run :(

hmmbob commented 2 years ago

Yet I never saw SQLin the toplist in 2022.7....

Let me see if I can do a rollback this weeked and see how long it takes on 2022.7.

hmmbob commented 2 years ago

Yeah, 2022.7 is within a second:

image

hmmbob commented 2 years ago

It appears that this is not specific to SQL sensor. Made it more general.

hmmbob commented 2 years ago

pyspy @bdraco

bdraco commented 2 years ago

Please zip up the svg and attach. GitHub removes all the useful data when you upload

Thanks

hmmbob commented 2 years ago

pyspy.zip Ah, didn't know. Here you go

hmmbob commented 2 years ago

2022.7.7 and 2022.8.0.b3.zip

@bdraco Nick, I've just ran sampling on both versions, keeping the environment as much the same as possible.

bdraco commented 2 years ago

It looks like the samples were not taken close enough to startup to get good data.

How long does startup take in total? You should get a number if you enable debug logging for homeassistant.bootstrap

The numbers include time waiting for dependencies so it could be a dependency of sql that is the problem not sql itself

Mariusthvdb commented 2 years ago

didnt know about that bootstrap logger, and its even faster than I said (45) it was in the beta channel

2022-07-31 22:43:24.838 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 33.76s

no time at all to startup a Py-Spy ....

hmmbob commented 2 years ago

How long does startup take in total? You should get a number if you enable debug logging for homeassistant.bootstrap

2022.8.0.b4:

2022-08-01 08:50:56.743 INFO (MainThread) [homeassistant.bootstrap] Setting up frontend: {'frontend'}
2022-08-01 08:50:57.168 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'frontend': <frontend: 0 / 1>, 'onboarding': <onboarding: 0 / 1>, 'person': <person: 2 / 0>}
2022-08-01 08:50:57.168 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'person': 0.007855}
2022-08-01 08:50:57.208 INFO (MainThread) [homeassistant.bootstrap] Setting up recorder: {'recorder'}
2022-08-01 08:50:57.274 INFO (MainThread) [homeassistant.bootstrap] Setting up stage 1: {'webhook', 'http', 'dhcp', 'cloud', 'zeroconf', 'websocket_api', 'ssdp', 'api', 'usb', 'network'}
2022-08-01 08:50:58.129 INFO (MainThread) [homeassistant.bootstrap] Setting up stage 2: {'input_select', 'rest', 'climate', 'rituals_perfume_genie', 'mobile_app', 'weather', 'onboarding', 'analytics', 'tag', 'repairs', 'scene', 'mqtt', 'media_source', 'device_automation', 'input_datetime', 'diagnostics', 'emulated_hue', 'input_button', 'sun', 'tts', 'picnic', 'esphome', 'sql', 'image', 'zwave_js', 'waze_travel_time', 'camera', 'binary_sensor', 'lovelace', 'spotcast', 'template', 'rest_command', 'cast', 'search', 'person', 'my', 'xiaomi_miio', 'trace', 'sensor', 'input_text', 'auth', 'philips_js', 'group', 'version', 'multiscrape', 'config', 'application_credentials', 'history', 'script', 'alert', 'backup', 'logbook', 'blueprint', 'automation', 'hacs', 'nfandroidtv', 'input_boolean', 'sonoff', 'google_assistant', 'notify', 'spotify', 'persistent_notification', 'hpprinter', 'system_health'}
2022-08-01 08:50:58.527 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'input_select': <input_select: 1 / 0>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'tag': <tag: 1 / 0>, 'scene': <scene: 5 / 0>, 'mqtt': <mqtt: 0 / 1>, 'media_source': <media_source: 1 / 0>, 'input_datetime': <input_datetime: 1 / 0>, 'emulated_hue': <emulated_hue: 0 / 1>, 'input_button': <input_button: 1 / 0>, 'tts': <tts: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'template': <template: 0 / 1>, 'cast': <cast: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'input_text': <input_text: 1 / 0>, 'philips_js': <philips_js: 0 / 1>, 'group': <group: 1 / 0>, 'version': <version: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'application_credentials': <application_credentials: 1 / 0>, 'script': <script: 0 / 1>, 'alert': <alert: 0 / 1>, 'backup': <backup: 0 / 1>, 'logbook': <logbook: 1 / 0>, 'automation': <automation: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'input_boolean': <input_boolean: 1 / 0>, 'sonoff': <sonoff: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'system_health': <system_health: 1 / 0>, 'climate': <climate: 1 / 0>, 'rest': <rest: 1 / 0>}
2022-08-01 08:50:58.527 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'input_select': 0.390439, 'tag': 0.374474, 'scene': 0.372421, 'scene.homeassistant': 0.372064, 'media_source': 0.366925, 'input_datetime': 0.362505, 'input_button': 0.361611, 'sun': 0.361256, 'sql': 0.359835, 'input_text': 0.329282, 'group': 0.327978, 'application_credentials': 0.323275, 'logbook': 0.299155, 'input_boolean': 0.29459, 'system_health': 0.291854, 'climate.toon_climate': 0.288099, 'scene.homeassistant_2': 0.282732, 'scene.homeassistant_3': 0.282544, 'scene.homeassistant_4': 0.282412, 'rest': 0.010235}
2022-08-01 08:51:01.830 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'input_select': <input_select: 1 / 0>, 'mobile_app': <mobile_app: 0 / 1>, 'input_datetime': <input_datetime: 1 / 0>, 'tts': <tts: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'template': <template: 0 / 1>, 'cast': <cast: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'input_text': <input_text: 1 / 0>, 'philips_js': <philips_js: 0 / 1>, 'version': <version: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'alert': <alert: 0 / 1>, 'backup': <backup: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'input_boolean': <input_boolean: 1 / 0>, 'sonoff': <sonoff: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'climate': <climate: 1 / 0>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:51:01.831 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'input_select': 3.694248, 'input_datetime': 3.666314, 'sql': 3.663644, 'input_text': 3.633091, 'input_boolean': 3.598399, 'climate.toon_climate': 3.591908, 'rest': 3.314044, 'rituals_perfume_genie': 2.969972, 'mqtt': 0.051529}
2022-08-01 08:51:03.176 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'version': <version: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'alert': <alert: 0 / 1>, 'backup': <backup: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'device_tracker': <device_tracker: 0 / 1>, 'zone': <zone: 1 / 0>, 'camera': <camera: 1 / 0>, 'light': <light: 1 / 0>}
2022-08-01 08:51:03.176 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 5.009132, 'rest': 4.659532, 'rituals_perfume_genie': 4.31546, 'mqtt': 1.397017, 'picnic': 1.17104, 'notify': 1.126792, 'zone': 1.086471, 'zwave_js': 0.691535, 'waze_travel_time': 0.687645, 'camera': 0.026049, 'light.mqtt': 0.02161}
2022-08-01 08:51:04.323 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:04.324 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 6.156559, 'rest': 5.806959, 'rituals_perfume_genie': 5.462887, 'mqtt': 2.544444, 'picnic': 2.318467, 'notify': 2.274219, 'waze_travel_time': 1.835072, 'xiaomi_miio': 1.099648, 'philips_js': 1.087522, 'version': 1.042285, 'multiscrape': 0.830847, 'hacs': 0.622962, 'sonoff': 0.376053}
2022-08-01 08:51:05.324 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:05.325 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 7.157516, 'rest': 6.807916, 'rituals_perfume_genie': 6.463844, 'mqtt': 3.545401, 'picnic': 3.319424, 'notify': 3.275176, 'waze_travel_time': 2.836029, 'xiaomi_miio': 2.100605, 'philips_js': 2.088479, 'version': 2.043242, 'multiscrape': 1.831804, 'hacs': 1.623919, 'sonoff': 1.37701}
2022-08-01 08:51:06.326 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:06.326 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 8.159284, 'rest': 7.809684, 'rituals_perfume_genie': 7.465612, 'mqtt': 4.547169, 'picnic': 4.321192, 'notify': 4.276944, 'waze_travel_time': 3.837797, 'xiaomi_miio': 3.102373, 'philips_js': 3.090247, 'version': 3.04501, 'multiscrape': 2.833572, 'hacs': 2.625687}
2022-08-01 08:51:07.327 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:07.328 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 9.160497, 'rest': 8.810897, 'rituals_perfume_genie': 8.466825, 'mqtt': 5.548382, 'picnic': 5.322405, 'notify': 5.278157, 'waze_travel_time': 4.83901, 'xiaomi_miio': 4.103586, 'version': 4.046223, 'multiscrape': 3.834785, 'hacs': 3.6269}
2022-08-01 08:51:08.329 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:08.329 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 10.161947, 'rest': 9.812347, 'rituals_perfume_genie': 9.468275, 'mqtt': 6.549832, 'picnic': 6.323855, 'notify': 6.279607, 'waze_travel_time': 5.84046, 'xiaomi_miio': 5.105036, 'version': 5.047673, 'multiscrape': 4.836235, 'hacs': 4.62835}
2022-08-01 08:51:08.518 WARNING (MainThread) [homeassistant.setup] Setup of rest is taking over 10 seconds.
2022-08-01 08:51:09.331 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:09.331 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 11.164251, 'rest': 10.814651, 'rituals_perfume_genie': 10.470579, 'mqtt': 7.552136, 'picnic': 7.326159, 'notify': 7.281911, 'waze_travel_time': 6.842764, 'xiaomi_miio': 6.10734, 'version': 6.049977, 'multiscrape': 5.838539, 'hacs': 5.630654}
2022-08-01 08:51:10.338 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:10.338 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 12.171072, 'rest': 11.821472, 'rituals_perfume_genie': 11.4774, 'mqtt': 8.558957, 'picnic': 8.33298, 'notify': 8.288732, 'waze_travel_time': 7.849585, 'xiaomi_miio': 7.114161, 'version': 7.056798, 'multiscrape': 6.84536, 'hacs': 6.637475}
2022-08-01 08:51:11.340 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:11.340 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 13.172951, 'rest': 12.823351, 'rituals_perfume_genie': 12.479279, 'mqtt': 9.560836, 'picnic': 9.334859, 'notify': 9.290611, 'waze_travel_time': 8.851464, 'xiaomi_miio': 8.11604, 'version': 8.058677, 'multiscrape': 7.847239, 'hacs': 7.639354}
2022-08-01 08:51:12.349 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:12.349 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 14.181717, 'rest': 13.832117, 'rituals_perfume_genie': 13.488045, 'mqtt': 10.569602, 'picnic': 10.343625, 'notify': 10.299377, 'waze_travel_time': 9.86023, 'xiaomi_miio': 9.124806, 'version': 9.067443, 'multiscrape': 8.856005, 'hacs': 8.64812}
2022-08-01 08:51:13.351 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:13.351 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 15.183788, 'rest': 14.834188, 'rituals_perfume_genie': 14.490116, 'mqtt': 11.571673, 'picnic': 11.345696, 'notify': 11.301448, 'waze_travel_time': 10.862301, 'xiaomi_miio': 10.126877, 'version': 10.069514, 'multiscrape': 9.858076, 'hacs': 9.650191}
2022-08-01 08:51:13.494 WARNING (MainThread) [homeassistant.setup] Setup of multiscrape is taking over 10 seconds.
2022-08-01 08:51:14.353 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>}
2022-08-01 08:51:14.353 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 16.185756, 'rest': 15.836156, 'rituals_perfume_genie': 15.492084, 'mqtt': 12.573641, 'picnic': 12.347664, 'notify': 12.303416, 'waze_travel_time': 11.864269, 'xiaomi_miio': 11.128845, 'version': 11.071482, 'multiscrape': 10.860044, 'hacs': 10.652159}
2022-08-01 08:51:15.389 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'cast': <cast: 0 / 1>, 'alert': <alert: 0 / 1>, 'rest': <rest: 1 / 0>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'notify': <notify: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>, 'weather': <weather: 1 / 0>, 'binary_sensor': <binary_sensor: 9 / 0>}
2022-08-01 08:51:15.389 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 17.221853, 'rest': 16.872253, 'rituals_perfume_genie': 16.528181, 'mqtt': 13.609738, 'picnic': 13.383761, 'notify': 13.339513, 'waze_travel_time': 12.900366, 'xiaomi_miio': 12.164942, 'version': 12.107579, 'multiscrape': 11.896141, 'hacs': 11.688256, 'weather.darksky': 0.110872, 'binary_sensor.group': 0.028682, 'binary_sensor.workday': 0.028429, 'binary_sensor.hpprinter': 0.006698, 'binary_sensor.mqtt': 0.005309, 'binary_sensor.rituals_perfume_genie': 0.004508, 'binary_sensor.version': 0.003373, 'binary_sensor.xiaomi_miio': 0.001045, 'binary_sensor.version_2': 0.0008, 'binary_sensor.sonoff': 0.000573}
2022-08-01 08:51:16.441 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'mobile_app': <mobile_app: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'alert': <alert: 0 / 1>, 'sensor': <sensor: 30 / 0>, 'button': <button: 13 / 0>, 'cast': <cast: 0 / 1>, 'switch': <switch: 1 / 0>, 'light': <light: 1 / 0>, 'binary_sensor': <binary_sensor: 1 / 0>, 'cover': <cover: 1 / 0>}
2022-08-01 08:51:16.441 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sql': 18.273712, 'mqtt': 14.661597, 'notify': 14.391372, 'binary_sensor.mqtt_2': 1.038706, 'spotify': 0.884633, 'sensor.dsmr_reader': 0.379438, 'sensor.darksky': 0.378488, 'switch.zwave_js': 0.017869, 'light.zwave_js': 0.016971, 'binary_sensor.zwave_js': 0.012817, 'cover.zwave_js': 0.006167}
2022-08-01 08:51:17.502 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'binary_sensor': <binary_sensor: 5 / 0>, 'sensor': <sensor: 25 / 0>}
2022-08-01 08:51:17.502 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'mqtt': 15.722658}
2022-08-01 08:51:17.740 DEBUG (MainThread) [homeassistant.bootstrap] Waiting for startup to wrap up
2022-08-01 08:51:18.672 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'binary_sensor': <binary_sensor: 5 / 0>, 'sensor': <sensor: 75 / 0>, 'switch': <switch: 8 / 0>, 'select': <select: 8 / 0>, 'light': <light: 1 / 0>, 'lock': <lock: 3 / 0>}
2022-08-01 08:51:18.672 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:51:19.152 DEBUG (MainThread) [homeassistant.bootstrap] Integration setup times: {'dhcp': 0.000769, 'persistent_notification': 0.000771, 'system_log': 0.000836, 'onboarding': 0.00129, 'binary_sensor': 0.002352, 'weather': 0.003097, 'logger': 0.003316, 'network': 0.003626, 'webhook': 0.003711, 'ssdp': 0.00402, 'image': 0.00479, 'frontend': 0.00487, 'lovelace': 0.005205, 'remote': 0.005383, 'spotcast': 0.007582, 'sensor': 0.01022, 'alert': 0.012841, 'backup': 0.01707, <Platform.MEDIA_PLAYER: 'media_player'>: 0.018523, 'auth': 0.019676, 'api': 0.022132, 'person': 0.024301, 'blueprint': 0.027294, 'http': 0.028707, 'device_automation': 0.040526, 'history': 0.045213, 'analytics': 0.045604, 'cloud': 0.048903, 'zeroconf': 0.049617, 'camera': 0.056867, 'trace': 0.059698, 'my': 0.060031, 'rest_command': 0.061432, 'recorder': 0.063115, <Platform.DEVICE_TRACKER: 'device_tracker'>: 0.067644, 'websocket_api': 0.097062, 'climate': 0.099981, 'diagnostics': 0.109478, 'nfandroidtv': 0.109634, 'xiaomi_cloud_map_extractor': 0.110709, 'config': 0.113358, 'cast': 0.116742, 'hpprinter': 0.133398, 'usb': 0.186661, 'search': 0.197572, 'systemmonitor': 0.252544, 'repairs': 0.332292, 'script': 0.333298, 'afvalinfo': 0.337228, 'workday': 0.363637, 'emulated_hue': 0.368306, 'logbook': 0.371821, <Platform.NUMBER: 'number'>: 0.379804, <Platform.FAN: 'fan'>: 0.383783, <Platform.VACUUM: 'vacuum'>: 0.393077, <Platform.LOCK: 'lock'>: 0.393928, <Platform.SIREN: 'siren'>: 0.395443, <Platform.SWITCH: 'switch'>: 0.396727, <Platform.COVER: 'cover'>: 0.400424, <Platform.SELECT: 'select'>: 0.402158, <Platform.ALARM_CONTROL_PANEL: 'alarm_control_panel'>: 0.403079, <Platform.BUTTON: 'button'>: 0.403994, 'history_stats': 0.406638, <Platform.HUMIDIFIER: 'humidifier'>: 0.40752, 'media_source': 0.427716, 'automation': 0.444427, <Platform.LIGHT: 'light'>: 0.468351, 'command_line': 0.503154, 'system_health': 0.620741, 'application_credentials': 0.670021, 'google_assistant': 0.70966, 'tag': 0.709791, 'tts': 0.797391, 'sun': 0.801464, 'template': 1.010735, 'dsmr_reader': 1.306042, 'zwave_js': 1.339718, 'zone': 1.411223, 'group': 1.686161, 'sonoff': 1.805106, 'darksky': 1.8704, 'spotify': 1.987764, 'esphome': 2.618316, 'mobile_app': 2.663388, 'philips_js': 3.28019, 'input_button': 3.620519, 'scene': 3.648194, 'toon_climate': 4.264318, 'input_boolean': 4.339234, 'input_text': 4.370574, 'input_datetime': 4.403557, 'input_select': 4.410697, 'homeassistant': 4.652071, 'hacs': 12.903506, 'multiscrape': 12.984997, 'version': 13.469731, 'xiaomi_miio': 13.802308, 'waze_travel_time': 14.085492, 'notify': 14.404536, 'picnic': 14.566564, 'rituals_perfume_genie': 18.029155, 'rest': 18.431897, 'sql': 18.610071, 'mqtt': 24.699267}
2022-08-01 08:51:19.152 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 23.02s

2022.7.7:

2022-08-01 08:57:02 INFO (MainThread) [homeassistant.bootstrap] Setting up stage 1: {'api', 'image', 'search', 'webhook', 'network', 'person', 'diagnostics', 'websocket_api', 'onboarding', 'cloud', 'http', 'frontend', 'config', 'analytics', 'device_automation', 'ssdp', 'zeroconf', 'usb', 'dhcp', 'system_log', 'auth', 'lovelace'}
2022-08-01 08:57:03 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'search': <search: 0 / 1>, 'network': <network: 0 / 1>, 'person': <person: 0 / 1>, 'onboarding': <onboarding: 0 / 1>, 'cloud': <cloud: 0 / 1>, 'frontend': <frontend: 0 / 1>, 'analytics': <analytics: 0 / 1>, 'ssdp': <ssdp: 0 / 1>, 'zeroconf': <zeroconf: 0 / 1>, 'usb': <usb: 0 / 1>, 'image': <image: 0 / 1>}
2022-08-01 08:57:03 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'diagnostics': 0.22453, 'config': 0.222665}
2022-08-01 08:57:03 INFO (MainThread) [homeassistant.bootstrap] Setting up stage 2: {'esphome', 'version', 'sensor', 'tag', 'hpprinter', 'media_source', 'spotcast', 'climate', 'philips_js', 'system_health', 'hacs', 'waze_travel_time', 'scene', 'mobile_app', 'camera', 'alert', 'rest_command', 'cast', 'google_assistant', 'mqtt', 'spotify', 'input_datetime', 'rest', 'input_boolean', 'input_text', 'sql', 'template', 'picnic', 'logbook', 'application_credentials', 'history', 'nfandroidtv', 'group', 'sonoff', 'multiscrape', 'input_button', 'notify', 'tts', 'persistent_notification', 'weather', 'blueprint', 'backup', 'automation', 'script', 'rituals_perfume_genie', 'zwave_js', 'xiaomi_miio', 'binary_sensor', 'my', 'trace', 'sun', 'input_select', 'emulated_hue'}
2022-08-01 08:57:04 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'esphome': <esphome: 0 / 1>, 'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'scene': <scene: 4 / 0>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'input_datetime': <input_datetime: 2 / 0>, 'rest': <rest: 0 / 1>, 'input_boolean': <input_boolean: 2 / 0>, 'input_text': <input_text: 2 / 0>, 'template': <template: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'group': <group: 2 / 0>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'input_button': <input_button: 1 / 0>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'input_select': <input_select: 2 / 0>, 'climate': <climate: 1 / 0>, 'emulated_hue': <emulated_hue: 1 / 0>}
2022-08-01 08:57:04 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'http': 0.609552, 'scene': 0.472727, 'scene.homeassistant': 0.472274, 'input_datetime': 0.442943, 'input_boolean': 0.440941, 'input_text': 0.436357, 'group': 0.406095, 'input_button': 0.405178, 'sun': 0.392457, 'input_select': 0.391695, 'climate.toon_climate': 0.386899, 'version': 0.355739, 'emulated_hue': 0.334389}
2022-08-01 08:57:05 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:05 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:06 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:06 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:07 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:07 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:08 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:08 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:09 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:09 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:10 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:10 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:11 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:11 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:12 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:12 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:13 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:13 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:14 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'hpprinter': <hpprinter: 0 / 1>, 'spotcast': <spotcast: 0 / 1>, 'philips_js': <philips_js: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:14 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:15 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'spotcast': <spotcast: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'waze_travel_time': <waze_travel_time: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'mqtt': <mqtt: 0 / 1>, 'rest': <rest: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>}
2022-08-01 08:57:15 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'philips_js': 0.017847}
2022-08-01 08:57:19 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'spotcast': <spotcast: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'google_assistant': <google_assistant: 0 / 1>, 'picnic': <picnic: 0 / 1>, 'nfandroidtv': <nfandroidtv: 0 / 1>, 'sonoff': <sonoff: 0 / 1>, 'multiscrape': <multiscrape: 0 / 1>, 'tts': <tts: 0 / 1>, 'backup': <backup: 0 / 1>, 'rituals_perfume_genie': <rituals_perfume_genie: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'camera': <camera: 1 / 0>, 'rest': <rest: 1 / 0>}
2022-08-01 08:57:19 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'philips_js': 3.750842, 'hacs': 3.649768, 'camera.xiaomi_cloud_map_extractor': 3.067261, 'mqtt': 0.207263, 'rest': 0.019387}
2022-08-01 08:57:20 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'spotcast': <spotcast: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'xiaomi_miio': <xiaomi_miio: 0 / 1>, 'spotify': <spotify: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'rest': <rest: 1 / 0>, 'multiscrape': <multiscrape: 1 / 0>, 'notify': <notify: 1 / 0>}
2022-08-01 08:57:20 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'hacs': 5.115769, 'rest': 1.485388, 'sonoff': 0.930845, 'multiscrape': 0.779845, 'notify': 0.702916, 'rituals_perfume_genie': 0.683083, <Platform.DEVICE_TRACKER: 'device_tracker'>: 0.643875, 'zwave_js': 0.023889}
2022-08-01 08:57:21 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'spotcast': <spotcast: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'alert': <alert: 0 / 1>, 'cast': <cast: 0 / 1>, 'rest': <rest: 1 / 0>, 'notify': <notify: 1 / 0>, 'binary_sensor': <binary_sensor: 3 / 0>, 'vacuum': <vacuum: 1 / 0>, 'tts': <tts: 1 / 0>, 'sensor': <sensor: 27 / 0>, 'switch': <switch: 2 / 0>, 'light': <light: 2 / 0>, 'button': <button: 2 / 0>}
2022-08-01 08:57:21 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'rest': 2.62961, 'sonoff': 2.075067, 'notify': 1.847138, 'binary_sensor.mqtt_2': 0.896985, 'spotify': 0.759522, 'vacuum.xiaomi_miio': 0.488561, 'tts': 0.46935, 'sensor.history_stats_2': 0.41828, 'sensor.dsmr_reader': 0.418069, 'sensor.systemmonitor': 0.417811, 'sensor.afvalinfo_2': 0.417042, 'sensor.darksky': 0.416811, 'sensor.sql': 0.368535, 'sensor.version': 0.365893, 'sensor.version_2': 0.365428, 'sensor.waze_travel_time': 0.346737, 'sensor.picnic': 0.344567, 'sensor.hacs': 0.339207, 'sensor.xiaomi_miio': 0.334362, 'sensor.rituals_perfume_genie': 0.331375, 'sensor.template': 0.294328, 'sensor.template_2': 0.294154, 'sensor.template_3': 0.047889, 'sensor.template_4': 0.047651, 'sensor.esphome': 0.008832, 'binary_sensor.esphome': 0.008573, 'switch.esphome': 0.008404, 'light.esphome': 0.008231, 'button.esphome': 0.00807, 'binary_sensor.esphome_2': 0.00761, 'button.esphome_2': 0.007416, 'sensor.esphome_2': 0.007223, 'switch.esphome_2': 0.007065, 'light.esphome_2': 0.006896, 'sensor.multiscrape': 0.001373, 'sensor.multiscrape_2': 0.001231}
2022-08-01 08:57:22 DEBUG (MainThread) [homeassistant.bootstrap] Waiting for startup to wrap up
2022-08-01 08:57:22 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'binary_sensor': <binary_sensor: 5 / 0>, 'sensor': <sensor: 1 / 0>}
2022-08-01 08:57:22 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'binary_sensor.mqtt_2': 1.902542, 'sensor.dsmr_reader': 1.423626}
2022-08-01 08:57:23 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'binary_sensor': <binary_sensor: 5 / 0>, 'sensor': <sensor: 75 / 0>, 'switch': <switch: 8 / 0>, 'select': <select: 8 / 0>, 'light': <light: 1 / 0>, 'lock': <lock: 3 / 0>}
2022-08-01 08:57:23 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:24 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {}
2022-08-01 08:57:24 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:25 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {}
2022-08-01 08:57:25 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {}
2022-08-01 08:57:26 DEBUG (MainThread) [homeassistant.bootstrap] Integration setup times: {'persistent_notification': 0.000454, 'logger': 0.00086, 'dhcp': 0.000901, 'usb': 0.001117, 'network': 0.001491, 'weather': 0.00396, 'frontend': 0.004276, 'websocket_api': 0.004934, 'binary_sensor': 0.005576, 'system_log': 0.005916, 'sensor': 0.005941, 'image': 0.006195, 'webhook': 0.007837, 'onboarding': 0.008215, 'camera': 0.010336, 'backup': 0.010988, <Platform.ALARM_CONTROL_PANEL: 'alarm_control_panel'>: 0.013624, <Platform.NUMBER: 'number'>: 0.014446, <Platform.SELECT: 'select'>: 0.014514, 'ssdp': 0.016207, 'api': 0.016466, 'spotcast': 0.016693, <Platform.FAN: 'fan'>: 0.017928, <Platform.VACUUM: 'vacuum'>: 0.018791, <Platform.LOCK: 'lock'>: 0.019839, 'trace': 0.021782, 'my': 0.022101, <Platform.COVER: 'cover'>: 0.022355, 'blueprint': 0.026133, 'script': 0.029674, 'command_line': 0.03312, <Platform.SIREN: 'siren'>: 0.033416, 'history': 0.034058, 'cloud': 0.037916, 'device_automation': 0.038161, 'analytics': 0.04598, 'zeroconf': 0.048397, 'automation': 0.049472, 'recorder': 0.061211, <Platform.MEDIA_PLAYER: 'media_player'>: 0.062037, 'rest_command': 0.067146, 'lovelace': 0.071496, 'alert': 0.073006, 'logbook': 0.088019, 'application_credentials': 0.105341, <Platform.BUTTON: 'button'>: 0.106475, <Platform.HUMIDIFIER: 'humidifier'>: 0.109292, 'cast': 0.11041, <Platform.REMOTE: 'remote'>: 0.114727, <Platform.SWITCH: 'switch'>: 0.120532, 'search': 0.136942, 'climate': 0.202717, 'auth': 0.218187, 'diagnostics': 0.225133, 'system_health': 0.253845, 'media_source': 0.262672, 'tag': 0.291222, <Platform.LIGHT: 'light'>: 0.291306, 'config': 0.34686, 'emulated_hue': 0.374541, 'person': 0.428103, 'sun': 0.441868, 'workday': 0.449949, 'input_button': 0.468291, 'systemmonitor': 0.492807, 'scene': 0.535993, 'group': 0.554669, 'sql': 0.587036, 'zone': 0.591321, 'tts': 0.5979, 'hpprinter': 0.609144, <Platform.DEVICE_TRACKER: 'device_tracker'>: 0.644179, 'homeassistant': 0.679856, 'toon_climate': 0.681942, 'http': 0.690762, 'input_select': 0.694589, 'input_text': 0.739138, 'google_assistant': 0.74184, 'input_boolean': 0.743604, 'input_datetime': 0.74547, 'afvalinfo': 0.858309, 'zwave_js': 0.883942, 'history_stats': 0.910227, 'waze_travel_time': 0.951331, 'nfandroidtv': 0.996361, 'picnic': 1.081595, 'template': 1.28932, 'dsmr_reader': 1.443437, 'mobile_app': 1.454181, 'spotify': 1.707783, 'xiaomi_miio': 1.758903, 'version': 1.83795, 'darksky': 1.84517, 'notify': 1.983025, 'multiscrape': 2.080697, 'rituals_perfume_genie': 2.232982, 'sonoff': 2.788648, 'xiaomi_cloud_map_extractor': 3.157992, 'rest': 3.890561, 'philips_js': 5.22175, 'hacs': 5.583675, 'esphome': 5.650715, 'mqtt': 6.014932}
2022-08-01 08:57:26 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 24.55s

Looks like total startup time is not too much changed, but some integrations suddenly take longer to setup

hmmbob commented 2 years ago

I don't know how to get closer to the startup with samples. What I'm doing now is...

bdraco commented 2 years ago

When I run it in a venv I use py-spy to start hass so I get data from the moment of startup. I realize that's probably impossible to do with os or containers

hmmbob commented 2 years ago

@bdraco got runs of 60 sec and 120 sec. Sampling more than 100/s would immediately lead to lagging errors, so I did not vary there.

You'll find each duration in a separate subfolder, with each subfolder containing runs for 2022.7 and 2022.8, both with and without browser open. There's also a text file with bootstrap logging per run (only last 2 messages)

pyspy-runs.zip

bdraco commented 2 years ago

Loading zha, and then mqtt is maxing out the cpu.

bdraco commented 2 years ago

Most of the overhead is loading python code which we can't make faster.

Are you using zha? It looks like its just the discovery of it thats causing it to load

hmmbob commented 2 years ago

I don't - I am using zigbee2mqtt. I have ignored ZHA.

ZHA may be discovered in these runs as they were venv runs and the USB device likely got detected. My normal container setup doesn't see the zigbee (or zwave) device though (it is not mapped to the container, as HA doesn't need it, as zigbee2mqtt handles it)

I don't think I have a big MQTT setup? image

All of it zigbee2mqtt.

Maxing out CPU is nice - running on a NUC so not the most underpowered system normally

bdraco commented 2 years ago

Its the overhead of loading the actual python code thats the problem.

I think we still load the whole integration even if its ignored. Maybe we can improve that

hmmbob commented 2 years ago

I noticed that Marius also had 'slowliness' issues, and MQTT scored high in his setup as well.

Thanks for al your help, much appreciated!

bdraco commented 2 years ago

I think we could change helpers/discovery_flow.py to check for ignored entries before starting the flow and bail early so the discovered integration never get loaded if its ignored on the next restart

hmmbob commented 2 years ago

Oh, if I understand you right that should give an impact for all ignored entries, across the board. That sounds like a nice win!

gieljnssns commented 1 year ago

I'm also seeing this problems. Every restart of HA all integrations are in another order.

Schermafbeelding 2022-10-10 om 12 48 39

If I can do something to gather more information...

bdraco commented 1 year ago

Not sure if this is still an issue, but if so it would be good to get another round of py-spys since a lot has changed since this was opened and there are some more options available to us to optimize this a bit more.

I suspect these two PRs will make a major difference for MQTT startup time: https://github.com/home-assistant/core/pull/88862 https://github.com/home-assistant/core/pull/88826

slovdahl commented 1 year ago

I'm still seeing slow startup of SQL among other things. Right now on 2023.3.3 running Home Assistant Container on an RPi 4. Only two MQTT devices and the MQTT integration doesn't seem to take too long to start. I'll try to get a py-spy.

image

slovdahl commented 1 year ago

I haven't forgotten about this, but I'm not able to get a py-spy at the moment because I'm also hit by https://github.com/benfred/py-spy/issues/552.

bdraco commented 1 year ago

No worries. Hopefully the py-spy bug gets sorted soon

bdraco commented 1 year ago

The problem, at least for most cases is likely fixed by https://github.com/home-assistant/core/pull/90335

Because sql startup blocked the event loop it was affecting nearly everything. Once that's fixed all integrations that start at the same time as sql should start much faster

bdraco commented 1 year ago

I'm also seeing this problems.

Every restart of HA all integrations are in another order.

Schermafbeelding 2022-10-10 om 12 48 39

If I can do something to gather more information...

It's likely you have a different integration blocking the event loop as well. Enabling debugpy might tell you what it is

gieljnssns commented 1 year ago

I think my issue was music assistant. The current beta is an add-on and for me it's much better now.

Scherm­afbeelding 2023-03-28 om 11 05 32
bdraco commented 1 year ago

I'm going to close this as all the known I/O in the event loop has been fixed.