search

basnijholt / adaptive-lighting

Adaptive Lighting custom component for Home Assistant
https://basnijholt.github.io/adaptive-lighting/
Apache License 2.0
1.81k stars 134 forks source link

Delayed adjusting after light turned back on #702

Closed Tommatheussen closed 1 year ago

Tommatheussen commented 1 year ago

Home Assistant Adaptive Lighting Issue Template

Bug Reports

If you need help with using or configuring Adaptive Lighting, please open a Q&A discussion thread here instead.

Before submitting a bug report, please follow these troubleshooting steps:

Please confirm that you have completed the following steps:

Required information for bug reports:

Please include the following information in your issue.

Issues missing this information may not be addressed.

  1. Debug logs captured while the issue occurred. See here for instructions on enabling debug logging:
2023-08-05 14:57:17.171 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.office' 'state_changed' event: '{'supported_color_modes': [<ColorMode.BRIGHTNESS: 'brightness'>], 'color_mode': <ColorMode.BRIGHTNESS: 'brightness'>, 'brightness': 0, 'friendly_name': 'Bureau', 'supported_features': <LightEntityFeature: 0>}' with context.id='01H72WC23KANDQ8RZMQBG8RC6V'
2023-08-05 14:57:17.171 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'off' → 'on' event for 'light.office' with context.id='01H72WC23KANDQ8RZMQBG8RC6V'
2023-08-05 14:57:17.171 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] is_proactively_adapting_context='False', context_id='01H72WC23KANDQ8RZMQBG8RC6V'
2023-08-05 14:57:17.171 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] just_turned_off: delta_time='36.034285' > delay='5'
2023-08-05 14:57:17.172 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] is_proactively_adapting_context='False', context_id='01H72WC23KANDQ8RZMQBG8RC6V'
2023-08-05 14:57:17.172 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: '_update_attrs_and_maybe_adapt_lights' called with context.id='01H72WC23M:al:IJ2X:lght:03' lights: '['light.office']', transition: '0.0', force: 'True'
2023-08-05 14:57:17.172 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: filtered_lights: '['light.office']'
2023-08-05 14:57:17.172 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: Calling _adapt_light from _update_attrs_and_maybe_adapt_lights: 'light.office' with transition 0.0 and context.id=01H72WC23M:al:IJ2X:lght:03
2023-08-05 14:57:17.172 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] is_proactively_adapting_context='False', context_id='01H72WC23KANDQ8RZMQBG8RC6V'
2023-08-05 14:57:17.172 DEBUG (MainThread) [custom_components.adaptive_lighting.adaptation_utils] Preparing adaptation data for light.office with service data {'entity_id': 'light.office', 'brightness': 255}
2023-08-05 14:57:17.173 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: execute_cancellable_adaptation_calls with data: AdaptationData(entity_id='light.office', context=<homeassistant.core.Context object at 0x7f4610f82a20>, sleep_time=0.0, service_call_datas=<async_generator object _create_service_call_data_iterator at 0x7f4619006040>, force=True, max_length=1, which='brightness', initial_sleep=False)
2023-08-05 14:57:17.176 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.office', 'brightness': 255} with context.id='01H72WC23M:al:IJ2X:lght:03'
2023-08-05 14:57:17.178 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.office']')' event with context.id='01H72WC23M:al:IJ2X:lght:03'
2023-08-05 14:57:17.201 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.office' 'state_changed' event: '{'supported_color_modes': [<ColorMode.BRIGHTNESS: 'brightness'>], 'color_mode': <ColorMode.BRIGHTNESS: 'brightness'>, 'brightness': 255, 'friendly_name': 'Bureau', 'supported_features': <LightEntityFeature: 0>}' with context.id='01H72WC23M:al:IJ2X:lght:03'
2023-08-05 14:57:17.201 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] AdaptiveLightingManager: New adapt '<state light.office=on; supported_color_modes=[<ColorMode.BRIGHTNESS: 'brightness'>], color_mode=brightness, brightness=255, friendly_name=Bureau, supported_features=0 @ 2023-08-05T14:57:17.171118+02:00>' found for light.office
2023-08-05 14:57:17.201 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] No transition in last adapt for light light.office, continuing...
2023-08-05 14:57:24.089 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'on' → 'off' event for 'light.office' with context.id='01H72WC8VRKPPHE09Z697WNGV2'
2023-08-05 14:57:28.087 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.office' 'state_changed' event: '{'supported_color_modes': [<ColorMode.BRIGHTNESS: 'brightness'>], 'color_mode': <ColorMode.BRIGHTNESS: 'brightness'>, 'brightness': 0, 'friendly_name': 'Bureau', 'supported_features': <LightEntityFeature: 0>}' with context.id='01H72WCCRPKTF3FDD3HD26X7TN'
2023-08-05 14:57:28.088 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'off' → 'on' event for 'light.office' with context.id='01H72WCCRPKTF3FDD3HD26X7TN'
2023-08-05 14:57:28.088 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] is_proactively_adapting_context='False', context_id='01H72WCCRPKTF3FDD3HD26X7TN'
2023-08-05 14:57:28.088 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] just_turned_off: Waiting with adjusting 'light.office' for 1.000349
2023-08-05 14:57:28.234 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.office' 'state_changed' event: '{'supported_color_modes': [<ColorMode.BRIGHTNESS: 'brightness'>], 'color_mode': <ColorMode.BRIGHTNESS: 'brightness'>, 'brightness': 15, 'friendly_name': 'Bureau', 'supported_features': <LightEntityFeature: 0>}' with context.id='01H72WCCX9ZPF1EBQGMSH7WX28'
2023-08-05 14:57:37.806 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: '_update_attrs_and_maybe_adapt_lights' called with context.id='01H72WCP8D:al:IJ2X:ntrv:04' lights: 'None', transition: '0.0', force: 'False'
2023-08-05 14:57:37.806 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: filtered_lights: '['light.office']'
2023-08-05 14:57:37.806 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: Calling _adapt_light from _update_attrs_and_maybe_adapt_lights: 'light.office' with transition 0.0 and context.id=01H72WCP8D:al:IJ2X:ntrv:04
2023-08-05 14:57:37.806 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] is_proactively_adapting_context='False', context_id='None'
2023-08-05 14:57:37.806 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: 'light.office' is locked
2023-08-05 14:57:39.092 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] just_turned_off: 'light.office' is still on after 11.000349 seconds, assuming it was intended to be on
2023-08-05 14:57:39.093 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] is_proactively_adapting_context='False', context_id='01H72WCCRPKTF3FDD3HD26X7TN'
2023-08-05 14:57:39.093 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: '_update_attrs_and_maybe_adapt_lights' called with context.id='01H72WCQGN:al:IJ2X:lght:05' lights: '['light.office']', transition: '0.0', force: 'True'
2023-08-05 14:57:39.093 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: filtered_lights: '['light.office']'
2023-08-05 14:57:39.093 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: Calling _adapt_light from _update_attrs_and_maybe_adapt_lights: 'light.office' with transition 0.0 and context.id=01H72WCQGN:al:IJ2X:lght:05
2023-08-05 14:57:39.093 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] is_proactively_adapting_context='False', context_id='01H72WCCRPKTF3FDD3HD26X7TN'
2023-08-05 14:57:39.094 DEBUG (MainThread) [custom_components.adaptive_lighting.adaptation_utils] Preparing adaptation data for light.office with service data {'entity_id': 'light.office', 'brightness': 255}
2023-08-05 14:57:39.094 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: execute_cancellable_adaptation_calls with data: AdaptationData(entity_id='light.office', context=<homeassistant.core.Context object at 0x7f461a318c70>, sleep_time=0.0, service_call_datas=<async_generator object _create_service_call_data_iterator at 0x7f460493aa40>, force=True, max_length=1, which='brightness', initial_sleep=False)
2023-08-05 14:57:39.097 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bureau: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.office', 'brightness': 255} with context.id='01H72WCQGN:al:IJ2X:lght:05'
2023-08-05 14:57:39.097 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.office']')' event with context.id='01H72WCQGN:al:IJ2X:lght:05'
2023-08-05 14:57:39.120 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.office' 'state_changed' event: '{'supported_color_modes': [<ColorMode.BRIGHTNESS: 'brightness'>], 'color_mode': <ColorMode.BRIGHTNESS: 'brightness'>, 'brightness': 255, 'friendly_name': 'Bureau', 'supported_features': <LightEntityFeature: 0>}' with context.id='01H72WCQGN:al:IJ2X:lght:05'
2023-08-05 14:57:39.120 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] AdaptiveLightingManager: New adapt '<state light.office=on; supported_color_modes=[<ColorMode.BRIGHTNESS: 'brightness'>], color_mode=brightness, brightness=255, friendly_name=Bureau, supported_features=0 @ 2023-08-05T14:57:28.086986+02:00>' found for light.office
2023-08-05 14:57:39.120 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] No transition in last adapt for light light.office, continuing...
  1. Your Adaptive Lighting configuration:
lights:
  - light.office
prefer_rgb_color: false
include_config_in_attributes: true
initial_transition: 0
sleep_transition: 1
transition: 0
transition_until_sleep: false
interval: 90
min_brightness: 1
max_brightness: 100
min_color_temp: 2000
max_color_temp: 5500
sleep_brightness: 1
sleep_rgb_or_color_temp: color_temp
sleep_color_temp: 1000
sleep_rgb_color:
  - 255
  - 56
  - 0
sunrise_time: null
max_sunrise_time: null
sunrise_offset: 0
sunset_time: null
min_sunset_time: null
sunset_offset: 0
only_once: false
take_over_control: true
detect_non_ha_changes: true
separate_turn_on_commands: false
send_split_delay: 0
adapt_delay: 0
autoreset_control_seconds: 0
skip_redundant_commands: true
name: Bureau
  1. (If using Zigbee2MQTT), provide your configuration files (remove all personal information before posting):
    • devices.yaml
    • groups.yaml
    • configuration.yaml ⚠️; Warning REMOVE ALL of the PERSONAL INFORMATION BELOW before posting ⚠️;
      • mqtt: server:
      • mqtt: user:
      • mqtt: password:
      • advanced: pan_id:
      • advanced: network_key:
      • anything in log_syslog if you use this
    • Brand and model number of problematic light(s) 


4.  Describe the bug and how to reproduce it:

When a light turns off, and back on again in 'semi-rapid' succession, the light does not start adapting after a period (I think the interval period, but not 100% sure).
For example, my light in the bathroom is automated with a motion sensor, it happens from time to time that I have to wave my hand to turn it on again 😅  but that turns on the lights to the lowest brightness (this is configured by myself, as I cannot have a dynamically set brightness in my KNX setup). 
In the logs I have simulated the behaviour for my 'Bureau' lights 

6. Steps to reproduce the behavior:
- Turn light on, let AL adjust the light
- Turn light off and back on again
basnijholt commented 1 year ago

This is actually a protection mechanism to make sure that lights that are just turned off, are not turned on by AL.

What can happen is that one turns the light off with a light.turn_off, then HA updates the state, and the light claims to be on (even though it is turning off or actually off).

To make sure we are not in this situation, we wait a little while to check whether the lights are actually off.

It seems like your lights are turned on outside of HA (so not with a light.turn_on) and therefore only report the on state again.

In this case we cannot distinguish between the protection mechanism and what happens in your case.

You can see that there is no light.turn_on because this message:

Detected an 'off' → 'on' event for 'light.office' with context.id='01H72WC23KANDQ8RZMQBG8RC6V'

is not accompanied by a

# I wrote this one, this does NOT appear in your logs
Detected an 'light.turn_on('['light.office']')' event with context.id='01H72WC23KANDQ8RZMQBG8RC6V'

Can you confirm that it is something outside of HA that turns on the lights?

Tommatheussen commented 1 year ago

Yep that is correct, a physical button (or sensor) turns on and off the lights.

Other than increasing the turn-off timer of the sensor, would you have any other ideas on how to mitigate this issue?

basnijholt commented 1 year ago

Perhaps you can have an automation like:

automation:
  - alias: "Set Manual Control to False after Light Turned On"
    trigger:
      - platform: state
        entity_id: light.YOUR_LIGHT_ENTITY_ID_HERE
        from: 'off'
        to: 'on'
    action:
      - service: adaptive_lighting.set_manual_control
        data:
          entity_id: switch.YOUR_ADAPTIVE_LIGHTING_SWITCH_ENTITY_ID_HERE
          lights:
            - light.YOUR_LIGHT_ENTITY_ID_HERE
          manual_control: false
Tommatheussen commented 1 year ago

Thanks! I'll try that one in the coming days. I'll go ahead and close this issue is it's working by design, I do see the reason why it's there :D