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

ShadowRep · 2024-03-12T18:58:08Z

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

The text was updated successfully, but these errors were encountered:

Chaoscontrol · 2024-03-15T19:25:43Z

Same here. Shows up on every reboot consistently.

goodlucknow · 2024-03-19T11:53:22Z

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 · 2024-03-21T18:54:06Z

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 · 2024-03-24T15:26:39Z

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

Zuz666 · 2024-04-17T10:54:54Z

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 · 2024-04-17T11:01:27Z

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

@diegocjorge, maybe, the code is shown above.

Chaoscontrol · 2024-04-17T12:24:05Z

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

RoboMagus · 2024-04-28T09:44:14Z

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 · 2024-05-03T08:33:51Z

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

th3w1zard1 · 2024-05-03T13:14:59Z

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 · 2024-05-15T04:37:04Z

You likely want light as an after_dep

bdraco · 2024-05-15T04:37:18Z

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

basnijholt · 2024-05-15T16:04:17Z

Thanks a lot @bdraco. I fixed this in #999 and released 1.21.3.

TermeHansen · 2024-05-16T06:43:48Z

@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 · 2024-05-16T09:08:18Z

@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 · 2024-05-16T09:53:35Z

@Zuz666 no warnings :)

basnijholt · 2024-05-17T07:00:37Z

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

Any suggestions?

Zuz666 · 2024-05-19T12:50:36Z

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 · 2024-05-19T16:35:38Z

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

Marck · 2024-05-20T14:13:08Z

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 · 2024-05-20T15:22:02Z

Thanks @Marck! Hopefully this issue is fixed now.

ShadowRep added kind/bug kind/feature need/triage labels Mar 12, 2024

basnijholt added a commit that referenced this issue May 15, 2024

Use after_dependencies to fix #950

da2f33e

basnijholt closed this as completed in 01f639f May 15, 2024

basnijholt reopened this May 17, 2024

Marck mentioned this issue May 20, 2024

Added light dependencies #1003

Merged

basnijholt closed this as completed in #1003 May 20, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

ShadowRep commented Mar 12, 2024

Chaoscontrol commented Mar 15, 2024

goodlucknow commented Mar 19, 2024 •

edited

Loading

diegocjorge commented Mar 21, 2024

th3w1zard1 commented Mar 24, 2024

Zuz666 commented Apr 17, 2024 •

edited

Loading

Zuz666 commented Apr 17, 2024 •

edited

Loading

Chaoscontrol commented Apr 17, 2024

RoboMagus commented Apr 28, 2024

Marck commented May 3, 2024

th3w1zard1 commented May 3, 2024

bdraco commented May 15, 2024

bdraco commented May 15, 2024

basnijholt commented May 15, 2024 •

edited

Loading

TermeHansen commented May 16, 2024

Zuz666 commented May 16, 2024 •

edited

Loading

TermeHansen commented May 16, 2024

basnijholt commented May 17, 2024

Zuz666 commented May 19, 2024

basnijholt commented May 19, 2024

Marck commented May 20, 2024 •

edited

Loading

basnijholt commented May 20, 2024

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

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

Comments

ShadowRep commented Mar 12, 2024

Chaoscontrol commented Mar 15, 2024

goodlucknow commented Mar 19, 2024 • edited Loading

diegocjorge commented Mar 21, 2024

th3w1zard1 commented Mar 24, 2024

Zuz666 commented Apr 17, 2024 • edited Loading

Zuz666 commented Apr 17, 2024 • edited Loading

Chaoscontrol commented Apr 17, 2024

RoboMagus commented Apr 28, 2024

Marck commented May 3, 2024

th3w1zard1 commented May 3, 2024

bdraco commented May 15, 2024

bdraco commented May 15, 2024

basnijholt commented May 15, 2024 • edited Loading

TermeHansen commented May 16, 2024

Zuz666 commented May 16, 2024 • edited Loading

TermeHansen commented May 16, 2024

basnijholt commented May 17, 2024

Zuz666 commented May 19, 2024

basnijholt commented May 19, 2024

Marck commented May 20, 2024 • edited Loading

basnijholt commented May 20, 2024

goodlucknow commented Mar 19, 2024 •

edited

Loading

Zuz666 commented Apr 17, 2024 •

edited

Loading

Zuz666 commented Apr 17, 2024 •

edited

Loading

basnijholt commented May 15, 2024 •

edited

Loading

Zuz666 commented May 16, 2024 •

edited

Loading

Marck commented May 20, 2024 •

edited

Loading