ITADN

Self-triggered 'off' → 'on' detection fires warning with massive state dump in logs (switch.py:2717)

#1433Openhomeassilol 创建于 2026-03-01
kind/bugkind/featureneed/triage
H
homeassilolcommented
## Checklist - [x] I have updated to the [latest Adaptive Lighting version](https://github.com/basnijholt/adaptive-lighting/releases) available in [HACS](https://hacs.xyz/). - [x] I have reviewed the [Troubleshooting Section](https://github.com/basnijholt/adaptive-lighting#sos-troubleshooting) in the [README](https://github.com/basnijholt/adaptive-lighting). - [ ] (If using Zigbee2MQTT) I have read the [Zigbee2MQTT troubleshooting guide](https://github.com/basnijholt/adaptive-lighting#zigbee2mqtt). - [x] I have checked the [V2 Roadmap](https://github.com/basnijholt/adaptive-lighting/discussions/291) and [open issues](https://github.com/basnijholt/adaptive-lighting/issues) to ensure my issue isn't a duplicate. ## Describe the bug Adaptive Lighting is firing a self-detection warning at `switch.py:2717` when it detects an `off` → `on` state transition for `light.couch_wand_licht` — but the warning message itself acknowledges this was **triggered by the adaptive_lighting integration itself, which should not happen**. The warning message includes a complete dump of **both the old and new state objects**, each containing the full `effect_list` attribute with **130+ lighting effects**. This results in a single log entry that is thousands of characters long, heavily polluting the log and making it extremely difficult to parse for actual errors. The warning occurred **2 times** within seconds at `19:54:54`, suggesting this isn't a one-off race condition but a reproducible pattern. ## Log evidence ``` Logger: custom_components.adaptive_lighting.switch Source: custom_components/adaptive_lighting/switch.py:2717 Integration: Adaptive Lighting (custom integration) First occurred: 19:54:54 (2 occurrences) Last logged: 19:54:54 Detected an 'off' → 'on' event for 'light.couch_wand_licht' with context.id='01KJNC1S5W:al:NVQW:skpp:03' and event='<Event state_changed[L]: entity_id=light.couch_wand_licht, old_state=<state light.couch_wand_licht=off; min_color_temp_kelvin=2000, max_color_temp_kelvin=9009, min_mireds=111, max_mireds=500, effect_list=["- Verlauf anim lila", "Abend Effekt Gradient", "Action", "Adventure Game", "Afternoon", "Afternoon B", "Amusement", "August Sunset 🌅", "Aurora", "Awaken", ... (130+ effects listed) ... "Work", "ZDP Duo", "ZDP Trio"], supported_color_modes=["color_temp", "rgb"], effect=None, color_mode=None, brightness=None, ...>, new_state=<state light.couch_wand_licht=on; ... (same 130+ effects repeated) ...>>' ``` *(Truncated — the full log entry contains the entire effect list TWICE, once for old_state and once for new_state)* ## Two issues in one ### 1. Self-triggered detection (the functional bug) The `context.id` format `01KJNC1S5W:al:NVQW:skpp:03` contains the `al` marker, indicating this state change was triggered by Adaptive Lighting itself. The code at `switch.py:2717` correctly identifies this scenario and even states it "should not happen" — yet it continues to occur. This suggests a race condition where the integration's own `light.turn_on` call triggers a state change that arrives back before the context is properly tracked. ### 2. Verbose state object logging (the log pollution issue) Regardless of the self-trigger bug, the warning at `switch.py:2717` dumps the **complete state object** including all attributes. For lights with large `effect_list` attributes (like Govee lights with 130+ effects), this creates enormous log entries. The warning should log only the relevant fields (entity_id, old state value, new state value, context.id) rather than the entire state representation. ## Environment - **Home Assistant Core**: 2026.2.3 - **Home Assistant OS**: 17.1 - **Hardware**: Home Assistant Green (~4 GB RAM) - **Adaptive Lighting**: latest via HACS - **Affected light**: `light.couch_wand_licht` (Govee light via Govee2MQTT, supports 130+ effects) - **Configuration**: `detect_non_ha_changes` likely enabled ## Expected behavior 1. **Self-triggered events should be silently ignored** — if the context ID contains the `al` marker, the integration should recognize its own work and not fire a warning 2. **Warning log messages should be concise** — log only `entity_id`, `old_state.state`, `new_state.state`, and `context.id` rather than the full state representation with all attributes 3. Consider adding a `_LOGGER.debug()` path for the full state dump for debugging purposes, while keeping the `_LOGGER.warning()` brief ## Suggested fix In `switch.py` around line 2717: ```python # Instead of: _LOGGER.warning("Detected an 'off' → 'on' event for '%s' ... %s", entity_id, event) # Consider: if _is_own_context(context): _LOGGER.debug("Ignoring self-triggered 'off' → 'on' for '%s' (context: %s)", entity_id, context.id) return # Skip processing entirely _LOGGER.warning( "Detected an 'off' → 'on' event for '%s' (context: %s, old: %s, new: %s)", entity_id, context.id, old_state.state, new_state.state ) # Full state available at debug level only: _LOGGER.debug("Full event for '%s': %s", entity_id, event) ``` ## Additional context This was discovered during a system-wide cProfile CPU profiling session. On a Home Assistant Green running ~30 integrations with ~258 Bluetooth devices, every unnecessary log write and state object serialization contributes to overall system load. The Govee lights are particularly affected because their massive `effect_list` attribute makes the state representation disproportionately large. Adaptive Lighting is an indispensable part of my setup — this is purely a quality-of-life improvement for the logging behavior. Thank you for maintaining such a fantastic integration!
0 条评论