Lights only adapting once

[broyuken]

Version information:

1.10.0

Description:

After updating to 1.10 all my lights only adapt once. They don’t get marked as manually controlled, but they just stop updating. I see the switch shows the brightness should be at 89% but the light is still set to 91%. I also noticed this in my kitchen this morning where the lights were still warm white around noon, but weren’t marked as manually controlled.

[broyuken]

Here is the config and the attributes set on the switch, but the light itself is at 91% still.

Attributes
Configuration
lights:
- light.office_ceiling_light
prefer_rgb_color: false
include_config_in_attributes: true
initial_transition: 0
sleep_transition: 90
transition: 10
transition_until_sleep: false
interval: 300
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: '11:59:00'
max_sunrise_time: null
sunrise_offset: 0
sunset_time: '12:01:00'
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
name: Office Ceiling Light
Manual control
Brightness pct
84.37
Color temp kelvin
2,000
Color temp mired
500
Rgb color
255, 136.86832541739756, 13.904070298965905
Xy color
0.598, 0.383
Hs color
30.504, 93.333
Sun position
-0.16

[basnijholt]

Oh no! Could you try downgrading to 1.9.0 and see if it still happens? That will allow us to debug this better.

[broyuken]

some quick testing and 1.9.1 appears to have the issue as well.

edit, I take that back, 1.9.1 seems to be working as expected. Will keep monitoring to see whats going on.

[basnijholt]

Then I am happy we released a lot of versions in the recent days. One version after every change.

Would it be possible to also try 1.8.0? Sorry for these issues! @th3w1zard1 has done A LOT of great work and fixed many issues in the last weeks. It is definitely possible we might have introduced an extra bug.

[th3w1zard1]

@broyuken would it be possible to post debug logs of 1.10.0 running? I can't reproduce with the config you posted

[th3w1zard1]

I found the problem I think

sunrise_time: '11:59:00'
max_sunrise_time: null
sunrise_offset: 0
sunset_time: '12:01:00'
min_sunset_time: null

What on earth is going on with your sunrise sunset times @broyuken ?

[broyuken]

I have it set up that way because if I have sunrise and sunset at their actual times then it gets way too bright at 6am and 6pm for example. I wanted it dimmer at that time and the only way I could do it was to make sunrise and sunset 2 mins apart so that the dimming begins and happens right before/after noon.

[broyuken]

Here's a debug log for AL. The light in question that I'm testing with is light.office_ceiling_light

home-assistant_2023-04-04T21-34-43.370Z.log

[th3w1zard1]

@broyuken is there any way you can shorten these logs and remove the noise? There's so much going on. You also have a lot of errors unrelated to adaptive lighting

2023-04-04 17:20:39.614 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback _SelectorDatagramTransport._read_ready()
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.10/asyncio/selector_events.py", line 1035, in _read_ready
    self._protocol.datagram_received(data, addr)
  File "/config/custom_components/localtuya/discovery.py", line 70, in datagram_received
    self.device_found(decoded)
  File "/config/custom_components/localtuya/discovery.py", line 79, in device_found
    self._callback(device)
  File "/config/custom_components/localtuya/__init__.py", line 105, in _device_discovered
    entry = async_config_entry_by_device_id(hass, device_id)
  File "/config/custom_components/localtuya/common.py", line 127, in async_config_entry_by_device_id
    if device_id in entry.data[CONF_DEVICES]:
KeyError: 'devices

Maybe something is interfering?

[th3w1zard1]

@broyuken Spent a few minutes going through the noise anyway, and a lot of it seems normal?

2023-04-04 16:34:17.496 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Office Ceiling Light: Detected an 'off' → 'on' event for 'light.office_ceiling_light' with context.id='01GX6ZMDNHT6K1N4GVEX61VWSS'
2023-04-04 16:34:17.497 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Office Ceiling Light: '_update_attrs_and_maybe_adapt_lights' called with context.id='adapt_lgt:b'x!)6':light_event:b'0R''
2023-04-04 16:34:17.498 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Office Ceiling Light: '_adapt_lights(['light.office_ceiling_light'], 0.0, force=True, context.id=adapt_lgt:b'x!)6':light_event:b'0R')' called
2023-04-04 16:34:17.499 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Office Ceiling Light: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.office_ceiling_light', 'brightness': 100} with context.id='adapt_lgt:b'x!)6':light_event:b'0R''
2023-04-04 16:34:17.511 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.office_ceiling_light']')' event with context.id='adapt_lgt:b'x!)6':light_event:b'0R''
2023-04-04 16:34:17.578 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.office_ceiling_light' 'state_changed' event: '{'supported_color_modes': [<ColorMode.BRIGHTNESS: 'brightness'>], 'color_mode': <ColorMode.BRIGHTNESS: 'brightness'>, 'brightness': 100, 'icon': 'mdi:dome-light', 'friendly_name': 'Office Ceiling Light', 'supported_features': <LightEntityFeature.TRANSITION: 32>}' with context.id='adapt_lgt:b'x!)6':light_event:b'0R''
2023-04-04 16:34:17.578 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] TurnOnOffListener: New adapt '<state light.office_ceiling_light=on; supported_color_modes=[<ColorMode.BRIGHTNESS: 'brightness'>], color_mode=brightness, brightness=100, icon=mdi:dome-light, friendly_name=Office Ceiling Light, supported_features=LightEntityFeature.TRANSITION @ 2023-04-04T16:34:17.488904-04:00>' found for light.office_ceiling_light
2023-04-04 16:34:17.586 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Start transition timer for light.office_ceiling_light

Light correctly adapted here: the light adapted to the new brightness value as shown by the 'detected state change'

then scroll 200 or so lines down to the next adapt of light.office_ceiling_light:

2023-04-04 16:37:46.910 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Office Ceiling Light: '_adapt_lights(['light.office_ceiling_light'], 10.0, force=False, context.id=adapt_lgt:b'x!)6':interval:b'0s')' called
2023-04-04 16:37:46.911 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Office Ceiling Light: 'detect_non_ha_changes: true', calling update_entity(light.office_ceiling_light) and check if it's last adapt succeeded.
2023-04-04 16:37:46.912 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Office Ceiling Light: Current state of light.office_ceiling_light: <state light.office_ceiling_light=on; supported_color_modes=[<ColorMode.BRIGHTNESS: 'brightness'>], color_mode=brightness, brightness=100, icon=mdi:dome-light, friendly_name=Office Ceiling Light, supported_features=LightEntityFeature.TRANSITION @ 2023-04-04T16:34:17.488904-04:00>
2023-04-04 16:37:46.912 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Office Ceiling Light: Light 'light.office_ceiling_light' correctly matches our last adapt's service data, continuing... context.id=adapt_lgt:b'x!)6':interval:b'0s'.
2023-04-04 16:37:46.912 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Office Ceiling Light: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.office_ceiling_light', 'transition': 10.0, 'brightness': 98} with context.id='adapt_lgt:b'x!)6':interval:b'0s''
2023-04-04 16:37:46.913 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Porch String Lights: '_update_attrs_and_maybe_adapt_lights' called with context.id='adapt_lgt:b'Tde&':interval:b'0R''
2023-04-04 16:37:46.915 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Porch String Lights: '_adapt_lights(['light.porch_string_lights'], 10.0, force=False, context.id=adapt_lgt:b'Tde&':interval:b'0R')' called
2023-04-04 16:37:46.937 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.office_ceiling_light']')' event with context.id='adapt_lgt:b'x!)6':interval:b'0s''

then 20 or so lines lower you'll see it took that state change too.

2023-04-04 16:37:47.086 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.office_ceiling_light' 'state_changed' event: '{'supported_color_modes': [<ColorMode.BRIGHTNESS: 'brightness'>], 'color_mode': <ColorMode.BRIGHTNESS: 'brightness'>, 'brightness': 98, 'icon': 'mdi:dome-light', 'friendly_name': 'Office Ceiling Light', 'supported_features': <LightEntityFeature.TRANSITION: 32>}' with context.id='adapt_lgt:b'x!)6':interval:b'0s''

The only oddities I noticed were the sunrise/sunset times, and the unnaturally large interval setting of 300. It's possible you saw the brightness_pct attribute differing from the light's state because the next interval hasn't run yet. Is there any reason your interval is so large?

[jeremynoesen]

I am also experiencing this issue, I downgraded to 1.9.1 and the issue does not occur on that version.

[th3w1zard1]

@jeremynoesen Thanks for sharing. Do you remember if Adaptive Lighting firing any manual control events on 1.10.0 when this issue happened?

[broyuken]

300 is just 5 minutes, every 5 mins it adjust the lights over a 10 second period. I don’t think that’s that odd. And this also happens with my kitchen ceiling lights which have normal sunrise sunset times.

[jeremynoesen]

@jeremynoesen Thanks for sharing. Do you remember if Adaptive Lighting firing any manual control events on 1.10.0 when this issue happened?

I have not checked. I can go back to 1.10.0 and check later today.

[iambucketdotcom]

I am also having this issue. I have deleted the Adaptive lighting groups and service and re-configured (1.10.0). The lights only update when a switch (such as sleep mode, brightness, color) is toggled.

Since htis is my work from home office with no external windows, as a temporary workaround to avoid having to manually downgrade, I've made it so every time I step away form my machine, I lock it, and it sets the lights to sleep mode, and then when I unlock the machine it re-enables the lights and updates their color. It's not perfect but there will still be a gradual color arch through the day.

[keshirkey]

Same issue. It was working flawlessly for years.

[basnijholt]

Just noting, the bug must have been introduced in some of these changes: https://github.com/basnijholt/adaptive-lighting/compare/1.9.1...1.10.0#diff-2ae6ce86e459ad0e8703be113d8bd00c7fb232c57bc6133c2f3e5a680fd008b2

[th3w1zard1]

I'd love to help fix this issue today but I cannot reproduce this bug. 1.10.0 is working correctly for all 9 lights I have.

If anybody could post debug logs, that'd be great!

[broyuken]

I posted debug logs the other day.

[th3w1zard1]

I figured out the issue.

[th3w1zard1]

A hotfix will be posted soon.

[th3w1zard1]

I can confirm my lights indeed have this issue with 1.10.0. Everyone needs to revert back to 1.9.1 until a hotfix can be pushed.

[th3w1zard1]

This issue has been fixed by version 1.10.1. Thank you to everyone here who submitted a bug report!