Provide api to see which integrations are being loaded

homeassistant/bootstrap.py

@@ -20,14 +20,17 @@
 from homeassistant.const import REQUIRED_NEXT_PYTHON_DATE, REQUIRED_NEXT_PYTHON_VER
 from homeassistant.exceptions import HomeAssistantError
 from homeassistant.helpers import area_registry, device_registry, entity_registry
+from homeassistant.helpers.dispatcher import async_dispatcher_send
 from homeassistant.helpers.typing import ConfigType
 from homeassistant.setup import (
     DATA_SETUP,
     DATA_SETUP_STARTED,
+    DATA_SETUP_TIME,
     async_set_domains_to_be_loaded,
     async_setup_component,
 )
 from homeassistant.util.async_ import gather_with_concurrency
+import homeassistant.util.dt as dt_util
 from homeassistant.util.logging import async_activate_log_queue_handler
 from homeassistant.util.package import async_get_user_site, is_virtual_env
 
@@ -42,6 +45,8 @@
 DATA_LOGGING = "logging"
 
 LOG_SLOW_STARTUP_INTERVAL = 60
+SLOW_STARTUP_CHECK_INTERVAL = 1
+SIGNAL_BOOTSTRAP_INTEGRATONS = "bootstrap_integrations"
 
 STAGE_1_TIMEOUT = 120
 STAGE_2_TIMEOUT = 300
@@ -380,38 +385,43 @@ def _get_domains(hass: core.HomeAssistant, config: dict[str, Any]) -> set[str]:
     return domains
 
 
-async def _async_log_pending_setups(
-    hass: core.HomeAssistant, domains: set[str], setup_started: dict[str, datetime]
-) -> None:
+async def _async_watch_pending_setups(hass: core.HomeAssistant) -> None:
     """Periodic log of setups that are pending for longer than LOG_SLOW_STARTUP_INTERVAL."""
+    loop_count = 0
+    setup_started: dict[str, datetime] = hass.data[DATA_SETUP_STARTED]
     while True:
-        await asyncio.sleep(LOG_SLOW_STARTUP_INTERVAL)
-        remaining = [domain for domain in domains if domain in setup_started]
+        now = dt_util.utcnow()
+        remaining_with_setup_started = {
+            domain: (now - setup_started[domain]).total_seconds()
+            for domain in setup_started
+        }
+        _LOGGER.debug("Integration remaining: %s", remaining_with_setup_started)
+        async_dispatcher_send(
+            hass, SIGNAL_BOOTSTRAP_INTEGRATONS, remaining_with_setup_started
+        )
+        await asyncio.sleep(SLOW_STARTUP_CHECK_INTERVAL)
+        loop_count += SLOW_STARTUP_CHECK_INTERVAL
 
-        if remaining:
+        if loop_count >= LOG_SLOW_STARTUP_INTERVAL and setup_started:
             _LOGGER.warning(
                 "Waiting on integrations to complete setup: %s",
-                ", ".join(remaining),
+                ", ".join(setup_started),
             )
+            loop_count = 0
         _LOGGER.debug("Running timeout Zones: %s", hass.timeout.zones)
 
 
 async def async_setup_multi_components(
     hass: core.HomeAssistant,
     domains: set[str],
     config: dict[str, Any],
-    setup_started: dict[str, datetime],
 ) -> None:
     """Set up multiple domains. Log on failure."""
     futures = {
         domain: hass.async_create_task(async_setup_component(hass, domain, config))
         for domain in domains
     }
-    log_task = asyncio.create_task(
-        _async_log_pending_setups(hass, domains, setup_started)
-    )
     await asyncio.wait(futures.values())
-    log_task.cancel()
     errors = [domain for domain in domains if futures[domain].exception()]
     for domain in errors:
         exception = futures[domain].exception()
@@ -427,7 +437,11 @@ async def _async_set_up_integrations(
     hass: core.HomeAssistant, config: dict[str, Any]
 ) -> None:
     """Set up all the integrations."""
-    setup_started = hass.data[DATA_SETUP_STARTED] = {}
+    hass.data[DATA_SETUP_STARTED] = {}
+    setup_time = hass.data[DATA_SETUP_TIME] = {}
+
+    log_task = asyncio.create_task(_async_watch_pending_setups(hass))
+
     domains_to_setup = _get_domains(hass, config)
 
     # Resolve all dependencies so we know all integrations
@@ -476,14 +490,14 @@ async def _async_set_up_integrations(
     # Load logging as soon as possible
     if logging_domains:
         _LOGGER.info("Setting up logging: %s", logging_domains)
-        await async_setup_multi_components(hass, logging_domains, config, setup_started)
+        await async_setup_multi_components(hass, logging_domains, config)
 
     # Start up debuggers. Start these first in case they want to wait.
     debuggers = domains_to_setup & DEBUGGER_INTEGRATIONS
 
     if debuggers:
         _LOGGER.debug("Setting up debuggers: %s", debuggers)
-        await async_setup_multi_components(hass, debuggers, config, setup_started)
+        await async_setup_multi_components(hass, debuggers, config)
 
     # calculate what components to setup in what stage
     stage_1_domains = set()
@@ -524,9 +538,7 @@ async def _async_set_up_integrations(
             async with hass.timeout.async_timeout(
                 STAGE_1_TIMEOUT, cool_down=COOLDOWN_TIME
             ):
-                await async_setup_multi_components(
-                    hass, stage_1_domains, config, setup_started
-                )
+                await async_setup_multi_components(hass, stage_1_domains, config)
         except asyncio.TimeoutError:
             _LOGGER.warning("Setup timed out for stage 1 - moving forward")
 
@@ -539,12 +551,21 @@ async def _async_set_up_integrations(
             async with hass.timeout.async_timeout(
                 STAGE_2_TIMEOUT, cool_down=COOLDOWN_TIME
             ):
-                await async_setup_multi_components(
-                    hass, stage_2_domains, config, setup_started
-                )
+                await async_setup_multi_components(hass, stage_2_domains, config)
         except asyncio.TimeoutError:
             _LOGGER.warning("Setup timed out for stage 2 - moving forward")
 
+    log_task.cancel()
+    _LOGGER.debug(
+        "Integration setup times: %s",
+        {
+            integration: timedelta.total_seconds()
+            for integration, timedelta in sorted(
+                setup_time.items(), key=lambda item: item[1].total_seconds()  # type: ignore
+            )
+        },
+    )
+
     # Wrap up startup
     _LOGGER.debug("Waiting for startup to wrap up")
     try:

homeassistant/components/device_tracker/legacy.py

@@ -38,7 +38,7 @@
 )
 from homeassistant.helpers.restore_state import RestoreEntity
 from homeassistant.helpers.typing import ConfigType, GPSType
-from homeassistant.setup import async_prepare_setup_platform
+from homeassistant.setup import async_prepare_setup_platform, async_start_setup
 from homeassistant.util import dt as dt_util
 from homeassistant.util.yaml import dump
 
@@ -221,48 +221,54 @@ def type(self):
 
     async def async_setup_legacy(self, hass, tracker, discovery_info=None):
         """Set up a legacy platform."""
-        LOGGER.info("Setting up %s.%s", DOMAIN, self.name)
-        try:
-            scanner = None
-            setup = None
-            if hasattr(self.platform, "async_get_scanner"):
-                scanner = await self.platform.async_get_scanner(
-                    hass, {DOMAIN: self.config}
-                )
-            elif hasattr(self.platform, "get_scanner"):
-                scanner = await hass.async_add_executor_job(
-                    self.platform.get_scanner, hass, {DOMAIN: self.config}
-                )
-            elif hasattr(self.platform, "async_setup_scanner"):
-                setup = await self.platform.async_setup_scanner(
-                    hass, self.config, tracker.async_see, discovery_info
-                )
-            elif hasattr(self.platform, "setup_scanner"):
-                setup = await hass.async_add_executor_job(
-                    self.platform.setup_scanner,
-                    hass,
-                    self.config,
-                    tracker.see,
-                    discovery_info,
-                )
-            else:
-                raise HomeAssistantError("Invalid legacy device_tracker platform.")
-
-            if setup:
-                hass.config.components.add(f"{DOMAIN}.{self.name}")
-
-            if scanner:
-                async_setup_scanner_platform(
-                    hass, self.config, scanner, tracker.async_see, self.type
+        full_name = f"{DOMAIN}.{self.name}"
+        LOGGER.info("Setting up %s", full_name)
+        with async_start_setup(hass, [full_name]):
+            try:
+                scanner = None
+                setup = None
+                if hasattr(self.platform, "async_get_scanner"):
+                    scanner = await self.platform.async_get_scanner(
+                        hass, {DOMAIN: self.config}
+                    )
+                elif hasattr(self.platform, "get_scanner"):
+                    scanner = await hass.async_add_executor_job(
+                        self.platform.get_scanner, hass, {DOMAIN: self.config}
+                    )
+                elif hasattr(self.platform, "async_setup_scanner"):
+                    setup = await self.platform.async_setup_scanner(
+                        hass, self.config, tracker.async_see, discovery_info
+                    )
+                elif hasattr(self.platform, "setup_scanner"):
+                    setup = await hass.async_add_executor_job(
+                        self.platform.setup_scanner,
+                        hass,
+                        self.config,
+                        tracker.see,
+                        discovery_info,
+                    )
+                else:
+                    raise HomeAssistantError("Invalid legacy device_tracker platform.")
+
+                if setup:
+                    hass.config.components.add(full_name)
+
+                if scanner:
+                    async_setup_scanner_platform(
+                        hass, self.config, scanner, tracker.async_see, self.type
+                    )
+                    return
+
+                if not setup:
+                    LOGGER.error(
+                        "Error setting up platform %s %s", self.type, self.name
+                    )
+                    return
+
+            except Exception:  # pylint: disable=broad-except
+                LOGGER.exception(
+                    "Error setting up platform %s %s", self.type, self.name
                 )
-                return
-
-            if not setup:
-                LOGGER.error("Error setting up platform %s %s", self.type, self.name)
-                return
-
-        except Exception:  # pylint: disable=broad-except
-            LOGGER.exception("Error setting up platform %s %s", self.type, self.name)
 
 
 async def async_extract_config(hass, config):

homeassistant/components/notify/__init__.py

@@ -16,7 +16,7 @@
 import homeassistant.helpers.config_validation as cv
 from homeassistant.helpers.service import async_set_service_schema
 from homeassistant.loader import async_get_integration, bind_hass
-from homeassistant.setup import async_prepare_setup_platform
+from homeassistant.setup import async_prepare_setup_platform, async_start_setup
 from homeassistant.util import slugify
 from homeassistant.util.yaml import load_yaml
 
@@ -289,47 +289,52 @@ async def async_setup_platform(
             _LOGGER.error("Unknown notification service specified")
             return
 
-        _LOGGER.info("Setting up %s.%s", DOMAIN, integration_name)
-        notify_service = None
-        try:
-            if hasattr(platform, "async_get_service"):
-                notify_service = await platform.async_get_service(
-                    hass, p_config, discovery_info
-                )
-            elif hasattr(platform, "get_service"):
-                notify_service = await hass.async_add_executor_job(
-                    platform.get_service, hass, p_config, discovery_info
-                )
-            else:
-                raise HomeAssistantError("Invalid notify platform.")
-
-            if notify_service is None:
-                # Platforms can decide not to create a service based
-                # on discovery data.
-                if discovery_info is None:
-                    _LOGGER.error(
-                        "Failed to initialize notification service %s", integration_name
+        full_name = f"{DOMAIN}.{integration_name}"
+        _LOGGER.info("Setting up %s", full_name)
+        with async_start_setup(hass, [full_name]):
+            notify_service = None
+            try:
+                if hasattr(platform, "async_get_service"):
+                    notify_service = await platform.async_get_service(
+                        hass, p_config, discovery_info
+                    )
+                elif hasattr(platform, "get_service"):
+                    notify_service = await hass.async_add_executor_job(
+                        platform.get_service, hass, p_config, discovery_info
                     )
+                else:
+                    raise HomeAssistantError("Invalid notify platform.")
+
+                if notify_service is None:
+                    # Platforms can decide not to create a service based
+                    # on discovery data.
+                    if discovery_info is None:
+                        _LOGGER.error(
+                            "Failed to initialize notification service %s",
+                            integration_name,
+                        )
+                    return
+
+            except Exception:  # pylint: disable=broad-except
+                _LOGGER.exception("Error setting up platform %s", integration_name)
                 return
 
-        except Exception:  # pylint: disable=broad-except
-            _LOGGER.exception("Error setting up platform %s", integration_name)
-            return
-
-        if discovery_info is None:
-            discovery_info = {}
+            if discovery_info is None:
+                discovery_info = {}
 
-        conf_name = p_config.get(CONF_NAME) or discovery_info.get(CONF_NAME)
-        target_service_name_prefix = conf_name or integration_name
-        service_name = slugify(conf_name or SERVICE_NOTIFY)
+            conf_name = p_config.get(CONF_NAME) or discovery_info.get(CONF_NAME)
+            target_service_name_prefix = conf_name or integration_name
+            service_name = slugify(conf_name or SERVICE_NOTIFY)
 
-        await notify_service.async_setup(hass, service_name, target_service_name_prefix)
-        await notify_service.async_register_services()
+            await notify_service.async_setup(
+                hass, service_name, target_service_name_prefix
+            )
+            await notify_service.async_register_services()
 
-        hass.data[NOTIFY_SERVICES].setdefault(integration_name, []).append(
-            notify_service
-        )
-        hass.config.components.add(f"{DOMAIN}.{integration_name}")
+            hass.data[NOTIFY_SERVICES].setdefault(integration_name, []).append(
+                notify_service
+            )
+            hass.config.components.add(f"{DOMAIN}.{integration_name}")
 
         return True