Log message: Failed to set up service call interceptors, falling back to event-reactive mode

[ShadowRep]

Happens since 2024.3.0.

Traceback (most recent call last): File "/config/custom_components/adaptive_lighting/switch.py", line 1670, in __init__ setup_service_call_interceptor( File "/config/custom_components/adaptive_lighting/hass_utils.py", line 40, in setup_service_call_interceptor raise RuntimeError(msg) RuntimeError: Intercept failed because service light.turn_on is not registered

[Chaoscontrol]

Same here. Shows up on every reboot consistently.

[goodlucknow]

Seeing the same error.

edit: I am no longer seeing the error with every restart, but still intermittently. Only change is having newly added some other integrations and I wonder if that has affected the order in which they start on boot. From the error it sounds like adaptive lighting is coming up before homeassistant has fully started?

[diegocjorge]

Seeing the same error.

edit: I am no longer seeing the error with every restart, but still intermittently. Only change is having newly added some other integrations and I wonder if that has affected the order in which they start on boot. From the error it sounds like adaptive lighting is coming up before homeassistant has fully started?

I'm also experiencing this issue. When it happens, the error shows up in the log before other warnings:

2024-03-21 15:46:20.563 WARNING (MainThread) [custom_components.adaptive_lighting.switch] Failed to set up service call interceptors, falling back to event-reactive mode
Traceback (most recent call last):
File "/config/custom_components/adaptive_lighting/switch.py", line 1670, in __init__
setup_service_call_interceptor(
File "/config/custom_components/adaptive_lighting/hass_utils.py", line 40, in setup_service_call_interceptor
raise RuntimeError(msg)
RuntimeError: Intercept failed because service light.turn_on is not registered
2024-03-21 15:46:28.625 WARNING (MainThread) [homeassistant.helpers.frame] Detected that custom integration 'hacs' accesses hass.components.frontend. This is deprecated and will stop working in Home Assistant 2024.9, it should be updated to import functions used from frontend directly at custom_components/hacs/frontend.py, line 68: hass.components.frontend.async_register_built_in_panel(, please create a bug report at https://github.com/hacs/integration/issues
2024-03-21 15:46:28.702 WARNING (MainThread) [homeassistant.setup] Setup of battery_notes is taking over 10 seconds.

A possible fix would be to retry setting up service call interceptors after a small delay?

[th3w1zard1]

Anyone know the last version where this issue didn't happen?

[Zuz666]

I have the same issue. I wrote the code to find a solution. Try to see if it helps in solving the problem..

diff --git a/custom_components/adaptive_lighting/hass_utils.py b/custom_components/adaptive_lighting/hass_utils.py
index c87d481..6f2e4d7 100644
--- a/custom_components/adaptive_lighting/hass_utils.py
+++ b/custom_components/adaptive_lighting/hass_utils.py
@@ -1,5 +1,6 @@
 """Utility functions for HA core."""

+import asyncio
 import logging
 from collections.abc import Awaitable, Callable

@@ -11,33 +12,40 @@ from .adaptation_utils import ServiceData
 _LOGGER = logging.getLogger(__name__)

-def setup_service_call_interceptor(
+async def setup_service_call_interceptor(
     hass: HomeAssistant,
     domain: str,
     service: str,
     intercept_func: Callable[[ServiceCall, ServiceData], Awaitable[None] | None],
 ) -> Callable[[], None]:
-    """Inject a function into a registered service call to preprocess service data.

-    The injected interceptor function receives the service call and a writeable data dictionary
-    (the data of the service call is read-only) before the service call is executed.
-    """
-    try:
-        # HACK: Access protected attribute of HA service registry.
-        # This is necessary to replace a registered service handler with our
-        # proxy handler to intercept calls.
-        registered_services = (
-            hass.services._services  # pylint: disable=protected-access
-        )
-    except AttributeError as error:
-        msg = (
-            "Intercept failed because registered services are no longer"
-            " accessible (internal API may have changed)"
-        )
-        raise RuntimeError(msg) from error
-
-    if domain not in registered_services or service not in registered_services[domain]:
-        msg = f"Intercept failed because service {domain}.{service} is not registered"
+    for _ in range(10):
+        """Inject a function into a registered service call to preprocess service data.            
+                                                                                                   
+        The injected interceptor function receives the service call and a writeable data dictionary
+        (the data of the service call is read-only) before the service call is executed.           
+        """                                                                                        
+        try:                                                                                       
+            # HACK: Access protected attribute of HA service registry.                             
+            # This is necessary to replace a registered service handler with our                   
+            # proxy handler to intercept calls.                                                    
+            registered_services = (                                                                
+                hass.services._services  # pylint: disable=protected-access                        
+            )                                                                                      
+        except AttributeError as error:                                                            
+            msg = (                                                                                
+                "Intercept failed because registered services are no longer"                       
+                " accessible (internal API may have changed)"                                      
+            )                                                                                      
+            raise RuntimeError(msg) from error                                                     
+                                                                                                   
+        if domain in registered_services and service in registered_services[domain]:
+            break
+        else:
+            if _ < 9:  # Avoid sleeping after the last attempt
+                await asyncio.sleep(1)
+    else:  # If the loop completes without breaking
+        msg = f"Intercept failed because service {domain}.{service} is not registered after 10 attempts"
         raise RuntimeError(msg)

     existing_service = registered_services[domain][service]
diff --git a/custom_components/adaptive_lighting/switch.py b/custom_components/adaptive_lighting/switch.py
index 2b23c71..6eafbb6 100644
--- a/custom_components/adaptive_lighting/switch.py
+++ b/custom_components/adaptive_lighting/switch.py
@@ -425,8 +425,11 @@ async def async_setup_entry(  # noqa: PLR0915
         await hass.config_entries.async_remove(config_entry.entry_id)
         return

+
     if (manager := data.get(ATTR_ADAPTIVE_LIGHTING_MANAGER)) is None:
+        # WORKAROUND: wait HA to init services
         manager = AdaptiveLightingManager(hass)
+        await manager.register_interceptors()
         data[ATTR_ADAPTIVE_LIGHTING_MANAGER] = manager

     sleep_mode_switch = SimpleSwitch(
@@ -1676,10 +1679,12 @@ class AdaptiveLightingManager:

         self._proactively_adapting_contexts: dict[str, str] = {}

+    async def register_interceptors(self):
+
         try:
             self.listener_removers.append(
-                setup_service_call_interceptor(
-                    hass,
+                await setup_service_call_interceptor(
+                    self.hass,
                     LIGHT_DOMAIN,
                     SERVICE_TURN_ON,
                     self._service_interceptor_turn_on_handler,
@@ -1687,8 +1692,8 @@ class AdaptiveLightingManager:
             )

             self.listener_removers.append(
-                setup_service_call_interceptor(
-                    hass,
+                await setup_service_call_interceptor(
+                    self.hass,
                     LIGHT_DOMAIN,
                     SERVICE_TOGGLE,
                     self._service_interceptor_turn_on_handler,

[Zuz666]

A possible fix would be to retry setting up service call interceptors after a small delay?

@diegocjorge, maybe, the code is shown above.

[Chaoscontrol]

I haven't been seeing the error for some days/weeks now.

[RoboMagus]

Got the same issue since the last major HA update. Seems like the startup optimizations may cause Adaptive Lighting to be initialized before its dependencies are up or something.

[Marck]

Same error here. @basnijholt can you take a look at this?

[th3w1zard1]

A last known working AL version and HA version would be a great asset in determining the cause, if anyone can happen upon that information.

[bdraco]

You likely want light as an after_dep

[bdraco]

https://developers.home-assistant.io/docs/creating_integration_manifest?_highlight=after_dep#after-dependencies

[basnijholt]

Thanks a lot @bdraco. I fixed this in https://github.com/basnijholt/adaptive-lighting/pull/999 and released 1.21.3.

[TermeHansen]

@basnijholt I just installed 1.21.3 and still see the warning in my homeassistant log?!?

HA version 2024.5.3 (in docker)

homeassistant  | 2024-05-16 08:42:45.800 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration adaptive_lighting which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
homeassistant  | 2024-05-16 08:42:47.883 WARNING (MainThread) [custom_components.adaptive_lighting.switch] Failed to set up service call interceptors, falling back to event-reactive mode

$ cat config/custom_components/adaptive_lighting/manifest.json 
{
  "domain": "adaptive_lighting",
  "name": "Adaptive Lighting",
  "after_dependencies": ["light"],
  "codeowners": ["@basnijholt", "@RubenKelevra", "@th3w1zard1", "@protyposis"],
  "config_flow": true,
  "dependencies": [],
  "documentation": "https://github.com/basnijholt/adaptive-lighting#readme",
  "iot_class": "calculated",
  "issue_tracker": "https://github.com/basnijholt/adaptive-lighting/issues",
  "requirements": ["ulid-transform"],
  "version": "1.21.3"
}

[Zuz666]

@basnijholt I just installed 1.21.3 and still see the warning in my homeassistant log?!?

Me too...

@TermeHansen please check the warings with this manifest file:

{
  "domain": "adaptive_lighting",
  "name": "Adaptive Lighting",
  "codeowners": ["@basnijholt", "@RubenKelevra", "@th3w1zard1", "@protyposis"],
  "config_flow": true,
  "dependencies": [
    "light"
  ],
  "documentation": "https://github.com/basnijholt/adaptive-lighting#readme",
  "iot_class": "calculated",
  "issue_tracker": "https://github.com/basnijholt/adaptive-lighting/issues",
  "requirements": ["ulid-transform"],
  "version": "1.21.3"
}

[TermeHansen]

@Zuz666 no warnings :)

[basnijholt]

@bdraco, adding after_dependencies doesn't seem to do the trick unfortunately.

Any suggestions?

[Zuz666]

Any suggestions?

@basnijholt adding dependencies works for me.

{
  "domain": "adaptive_lighting",
  "name": "Adaptive Lighting",
  "codeowners": ["@basnijholt", "@RubenKelevra", "@th3w1zard1", "@protyposis"],
  "config_flow": true,
  "dependencies": [
    "light"
  ],
  "documentation": "https://github.com/basnijholt/adaptive-lighting#readme",
  "iot_class": "calculated",
  "issue_tracker": "https://github.com/basnijholt/adaptive-lighting/issues",
  "requirements": ["ulid-transform"],
  "version": "1.21.3"
}

[basnijholt]

Oh that's great! Could you make a PR? 😃

[Marck]

Created a PR (#1003) in case you want to merge this right now. Don't want to steal @Zuz666's thunder, so if he/she wants to do the honors, be my guest and I'll close it

[basnijholt]

Thanks @Marck! Hopefully this issue is fixed now.