Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Lights randomly come back on after shut off #10

Closed
broyuken opened this issue Oct 14, 2020 · 82 comments
Closed

Lights randomly come back on after shut off #10

broyuken opened this issue Oct 14, 2020 · 82 comments

Comments

@broyuken
Copy link

This has only happened to me twice, and I don't have a way to replicate it, but I will turn off a light using lovelace and after 10-15 seconds or so it turns itself back on. If I find a way to replicate it I can turn on debugging but I have no way to track it down so it wouldn't do much good right now. I am running d67479d now, and if I see it happen with this version I will let you know but like I said this has only happened twice over the week or so I've been running AL.

@basnijholt
Copy link
Owner

Would it be possible to enable debugging logging with:

logger:
  default: warning
  logs:
    custom_components.adaptive_lighting: debug

and post the log after it occurred?

I have a suspicion as to why it is happening but not sure.

@broyuken
Copy link
Author

I just enabled debugging to see if it happens again. It just happened again on the latest version before I turned on debugging. I believe the only lights I have seen this occur on are Sengled Zigbee bulbs. Hopefully I can catch the full debug going forward.

@basnijholt
Copy link
Owner

OK great!

I already anticipated that this might happen, you can see my comment in the code here

# Now we assume that the lights are still on and they were intended
# to be on. In case this still gives problems for some, we might
# choose to **only** adapt on 'light.turn_on' events and ignore
# other 'off' → 'on' state switches resulting from polling. That
# would mean we 'return True' here.
return False

@broyuken
Copy link
Author

This has happened a bunch of times since I last posted but unfortunately I messed up my Zha yesterday and had to turn off the debug to fix it. I’ll try to get it going again now that things seem to be stable

@broyuken
Copy link
Author

I caught one this evening in my sons room. Turned off the light via home assistant and it turned back on a few seconds later.

2020-10-18 20:19:23 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] State of 'light.justins_light' didn't change wrt change event nr. 0 (context.id=adapt_lgt_769d_interval_938)
2020-10-18 20:19:23 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Justins Bedroom: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.justins_light', 'transition': 45.0, 'brightness': 108, 'color_temp': 500} with context.id='adapt_lgt_769d_interval_938'
2020-10-18 20:19:23 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.justins_light']')' event with context.id='adapt_lgt_769d_interval_938'
2020-10-18 20:19:24 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.justins_light' 'state_changed' event: '{'min_mireds': 154, 'max_mireds': 500, 'brightness': 108, 'color_temp': 500, 'hs_color': (0, 0), 'rgb_color': (255, 255, 255), 'xy_color': (0.323, 0.329), 'off_brightness': None, 'friendly_name': 'Justins Light', 'icon': 'mdi:lamp', 'supported_features': 59}' with context.id='adapt_lgt_769d_interval_938'
2020-10-18 20:19:36 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_off('['light.justins_light']', transition=None)' event with context.id='c516bd2511a011eb9e71e3aac25616a3'
2020-10-18 20:20:09 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.justins_light' 'state_changed' event: '{'min_mireds': 154, 'max_mireds': 500, 'brightness': 108, 'color_temp': 500, 'hs_color': (0, 0), 'rgb_color': (255, 255, 255), 'xy_color': (0.323, 0.329), 'off_brightness': None, 'friendly_name': 'Justins Light', 'icon': 'mdi:lamp', 'supported_features': 59}' with context.id='d89b48aa11a011eb98e8b794d03648fc'
2020-10-18 20:20:09 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Justins Bedroom: Detected an 'off' → 'on' event for 'light.justins_light' with context.id='d89b48aa11a011eb98e8b794d03648fc'
2020-10-18 20:20:09 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], 1.0, force=True, context.id=adapt_lgt_769d_light_event_939)' called
2020-10-18 20:20:09 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Justins Bedroom: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.justins_light', 'transition': 1.0, 'brightness': 107, 'color_temp': 500} with context.id='adapt_lgt_769d_light_event_939'
2020-10-18 20:20:09 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.justins_light']')' event with context.id='adapt_lgt_769d_light_event_939'
2020-10-18 20:20:09 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.justins_light' 'state_changed' event: '{'min_mireds': 154, 'max_mireds': 500, 'brightness': 107, 'color_temp': 500, 'hs_color': (0, 0), 'rgb_color': (255, 255, 255), 'xy_color': (0.323, 0.329), 'off_brightness': None, 'friendly_name': 'Justins Light', 'icon': 'mdi:lamp', 'supported_features': 59}' with context.id='adapt_lgt_769d_light_event_939'
2020-10-18 20:20:17 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_off('['light.justins_light']', transition=None)' event with context.id='dd58269f11a011eba1913116e45fac2e'
2020-10-18 20:20:55 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], None, force=False, context.id=adapt_lgt_769d_interval_940)' called
2020-10-18 20:22:25 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], None, force=False, context.id=adapt_lgt_769d_interval_941)' called
2020-10-18 20:23:55 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], None, force=False, context.id=adapt_lgt_769d_interval_942)' called
2020-10-18 20:25:25 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], None, force=False, context.id=adapt_lgt_769d_interval_943)' called
2020-10-18 20:26:55 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], None, force=False, context.id=adapt_lgt_769d_interval_944)' called
2020-10-18 20:28:25 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], None, force=False, context.id=adapt_lgt_769d_interval_945)' called
2020-10-18 20:29:55 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], None, force=False, context.id=adapt_lgt_769d_interval_946)' called
2020-10-18 20:31:25 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Justins Bedroom: '_adapt_lights(['light.justins_light'], None, force=False, context.id=adapt_lgt_769d_interval_947)' called

@broyuken
Copy link
Author

Any ideas?

@basnijholt
Copy link
Owner

basnijholt commented Oct 22, 2020

I see that this happened:

  • at 20:19:36 light.turn_off called
  • at 20:20:09, the light reports it's on after polling, so AL proceeds to adapt it
  • at 20:20:17, something/someone called light.turn_off again, I presume that's you clicking the off button?

This is not really a bug of AL, but rather that the light reports that it's on, while it is actually off. Still there might be something that we can do. Maybe I can ignore any off -> on events that do not result from light.turn_on for a minute or so. What do you think?

@broyuken
Copy link
Author

that could be, my zigbee network has been a little flakey lately. Unfortunately most of my zigbee devices are sengled bulbs which are only endpoint devices, not routers. Working on trying to rectify that.

@broyuken
Copy link
Author

I'm sure I'm not the only one with a less than 100% stable zigbee network, so if there is some way to ignore those events then it would probably be for the best. Especially if it was an optional configuration.

@basnijholt
Copy link
Owner

I switched to ZHA and I am now seeing these problems too. Unfortunately, it doesn't seem like there is a lot to do. I will probably switch back to deCONZ... :'(

My issue is reported here zigpy/zigpy-deconz#140.

@broyuken
Copy link
Author

I will watch that thread but I may need to pick up a new zigbee stick. What are you using with deconz?

@basnijholt
Copy link
Owner

I have all my devices listed here https://github.com/basnijholt/home-assistant-config/#my-devices

@danielbrunt57
Copy link

danielbrunt57 commented Nov 20, 2020

that could be, my zigbee network has been a little flakey lately. Unfortunately most of my zigbee devices are sengled bulbs which are only endpoint devices, not routers. Working on trying to rectify that.

I started with Conbee II & deCONZ in HomeSeer (before I started HA) but had random turn-on's with Eria but initially only in Bedroom Lamp 2. I returned that bulb and then the Eria in Bedroom Lamp 1 randomly turned on a couple of times so I sent it back to Amazon also. I replaced them with Sengled and no more hiccups. Then I switched to HA using ZHA with Conbee II (no hiccups) but recently replaced Conbee II with CC2652 Stick which has an external antenna attached to the dongle and it has better range. The Sengled's are in bedroom but I have Osram Lightify in office and currently do not have any random turn-ons. I might try the Eria again now that my platform and controller have changed.

@profesaurus
Copy link

I'm having this same issue. It started after I installed adaptive lighting. My Sengled bulbs will get turned off by an automation and then just turn back on for no reason. It seems to only happen at night when adaptive lighting is running.

@basnijholt
Copy link
Owner

basnijholt commented Dec 3, 2020

@profesaurus, could you please add your logs (see https://github.com/basnijholt/adaptive-lighting#having-problems)?

@danielbrunt57
Copy link

danielbrunt57 commented Dec 3, 2020

I'm having this same issue. It started after I installed adaptive lighting. My Sengled bulbs will get turned off by an automation and then just turn back on for no reason. It seems to only happen at night when adaptive lighting is running.

Is the 'off automation' an automation in HA?
Can you verify that after the off automation runs that their status in HA shows off?
Also, after they've randomly turned on, does their status in HA show on?

...and include your logs as requested by @basnijholt !

@profesaurus
Copy link

@basnijholt I have adjusted HA to log debug outputs from AL. If/when it happens again I'll post here with the logs.

@danielbrunt57

The automation is an automation in HA. This is the only action in the automation:

image

Here's the logbook entry for when the automation turned the lights off, but then back on:

image

The top log is interesting because the lights are turned on by the action above....which is a light.turn_off service???

Also, that automation is only triggered once at the time the lights initially turn off:

image

The history does show the lights turning off, then back on:

image

I did find a post on the HA forums about an issue with zha light groups and Circadian Lighting and AL.

I am using zha light groups, so as a test, in AL's settings I unchecked the light groups and checked the individual lights within the groups. I don't know if this will fix it or if I'll need to try the recommended automation in the post.

Let me know if you have any other questions, I'm happy to help.

@danielbrunt57
Copy link

Very interesting.
I have 2 Sengled bulbs (ZHA) in master bedroom. They are motion controlled by Entity Controller, not an HA automation. I've no issues with them turning off and staying off. They are now in a group light.bedroom_lights. I say now because they were in group.bedroom_lights hence the reason for the "#" in the code below as that was needed for EC to observe and ignore changes in the light entities' brightness and color attributes by CL and now AL.

  bedroom_lights_control:
    friendly_name: Bedroom Lights Control
    sensor: binary_sensor.lumi_sensor_motion_bedroom
    sensor_type: duration
    state_attributes_ignore:
      - color_temp
      - brightness
    entity: light.bedroom_lights
    override: 
      - input_boolean.sleep_mode
#    state_entities:
#      - light.bedroom_lamp_1_level_light_color_on_off
#      - light.bedroom_lamp_2_level_light_color_on_off
    service_data:
      brightness: 30
    service_data_on: 
      transition: 3
    service_data_off: 
      transition: 5
    start_time: sunset - 00:30:00
    end_time: sunrise + 00:30:00
    end_time_action: "off"

In AL, I defined them individually as that was when I had group.bedroom_lights.
image

BTW, any ideas why I have a field sizing issue in the options window?

@profesaurus
Copy link

profesaurus commented Dec 5, 2020

@basnijholt & @danielbrunt57, I've got some logs for you. I have two AL setups. As I mentioned in my previous message, in my main AL setup I unchecked the ZHA groups from the settings and checked the individual lights. I haven't seen any issues with this one since doing that. <---- EDIT: This is not true, check my next post.

But I have another AL setup where I left the ZHA light groups in the settings and that one just had an issue with lights turning on after being turned off. In the settings the light.kids_bathroom_lights is the group I'm referring to:

image
image

I manually turned this group off in HA and they almost immediately came back on:

image

These lights have no automations attached to them, so there's nothing I did in HA that could be turning these lights on.

Here are the relevant logs:

2020-12-04 21:34:43 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_off('['light.kids_bathroom_lights']', transition=None)' event with context.id='86b79a45c997779df8683d5efa08b3b3'
2020-12-04 21:34:44 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.kids_bathroom_lights' 'state_changed' event: '{'brightness': 5, 'off_brightness': None, 'friendly_name': 'Kids Bathroom Lights', 'supported_features': 41}' with context.id='86b79a45c997779df8683d5efa08b3b3'
2020-12-04 21:34:48 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.kids_bathroom_lights' 'state_changed' event: '{'brightness': 5, 'off_brightness': None, 'friendly_name': 'Kids Bathroom Lights', 'supported_features': 41}' with context.id='86b79a45c997779df8683d5efa08b3b3'
2020-12-04 21:34:48 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Kids Adaptive Lighting: Detected an 'off' → 'on' event for 'light.kids_bathroom_lights' with context.id='86b79a45c997779df8683d5efa08b3b3'
2020-12-04 21:34:48 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Waiting with adjusting 'light.kids_bathroom_lights' for 0.746035
2020-12-04 21:34:49 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.kids_bathroom_lights' 'state_changed' event: '{'brightness': 4, 'off_brightness': None, 'friendly_name': 'Kids Bathroom Lights', 'supported_features': 41}' with context.id='06ecf7490dfee424bb4057cc7d1ae373'

Please let me know if you need any further info. I'm happy to help.

@profesaurus
Copy link

profesaurus commented Dec 5, 2020

I posted too soon. Looking through my logbook I discovered that my main AL setup had another issue today. And again, these issues only occur when AL is activated in the evening, so I'm pretty confident AL is playing some role in this.

I had an automation turn off a ZHA group, light.master_closet_lights, then about 20 seconds later 2 of the 3 lights in the group (light.master_closet_1 & light.master_closet_3) turned on. These lights are in the same light fixture, so it's not like two can be manually switched on without the others. Here are the logbook entries:

image
image
image
image

The AL settings:
image

And the logs:

2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_3' 'state_changed' event: '{'brightness': 254, 'off_brightness': None, 'friendly_name': 'Master Closet Light 3', 'supported_features': 41}' with context.id='49aebeb61a3a36006be15fd9e6d8fdc8'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Detected an 'off' → 'on' event for 'light.master_closet_3' with context.id='49aebeb61a3a36006be15fd9e6d8fdc8'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: '_update_attrs_and_maybe_adapt_lights' called with context.id='adapt_lgt_e2cf_light_event_80'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Adaptive Lighting: '_adapt_lights(['light.master_closet_3'], 1.0, force=True, context.id=adapt_lgt_e2cf_light_event_80)' called
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.master_closet_3', 'transition': 1.0, 'brightness': 168} with context.id='adapt_lgt_e2cf_light_event_80'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_1' 'state_changed' event: '{'brightness': 254, 'off_brightness': None, 'friendly_name': 'Master Closet Light 1', 'supported_features': 41}' with context.id='a80bb0aabe5af9d5224ea1d10c18c8ed'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.master_closet_3']')' event with context.id='adapt_lgt_e2cf_light_event_80'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Detected an 'off' → 'on' event for 'light.master_closet_1' with context.id='a80bb0aabe5af9d5224ea1d10c18c8ed'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: '_update_attrs_and_maybe_adapt_lights' called with context.id='adapt_lgt_e2cf_light_event_81'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Adaptive Lighting: '_adapt_lights(['light.master_closet_1'], 1.0, force=True, context.id=adapt_lgt_e2cf_light_event_81)' called
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.master_closet_1', 'transition': 1.0, 'brightness': 168} with context.id='adapt_lgt_e2cf_light_event_81'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.master_closet_1']')' event with context.id='adapt_lgt_e2cf_light_event_81'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_3' 'state_changed' event: '{'brightness': 168, 'off_brightness': None, 'friendly_name': 'Master Closet Light 3', 'supported_features': 41}' with context.id='adapt_lgt_e2cf_light_event_80'
2020-12-04 17:50:28 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_1' 'state_changed' event: '{'brightness': 168, 'off_brightness': None, 'friendly_name': 'Master Closet Light 1', 'supported_features': 41}' with context.id='adapt_lgt_e2cf_light_event_81'
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_2' 'state_changed' event: '{'brightness': 254, 'off_brightness': None, 'friendly_name': 'Master Closet Light 2', 'supported_features': 41}' with context.id='093dc58985c4bf33963b210c8021e8a3'
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Detected an 'off' → 'on' event for 'light.master_closet_2' with context.id='093dc58985c4bf33963b210c8021e8a3'
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: '_update_attrs_and_maybe_adapt_lights' called with context.id='adapt_lgt_e2cf_light_event_82'
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Adaptive Lighting: '_adapt_lights(['light.master_closet_2'], 1.0, force=True, context.id=adapt_lgt_e2cf_light_event_82)' called
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.master_closet_2', 'transition': 1.0, 'brightness': 168} with context.id='adapt_lgt_e2cf_light_event_82'
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.master_closet_2']')' event with context.id='adapt_lgt_e2cf_light_event_82'
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_1' 'state_changed' event: '{'brightness': 174, 'off_brightness': None, 'friendly_name': 'Master Closet Light 1', 'supported_features': 41}' with context.id='adapt_lgt_e2cf_light_event_81'
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] State change event of 'light.master_closet_1' is already in 'self.last_state_change' (adapt_lgt_e2cf_light_event_81) adding this state also
2020-12-04 17:50:29 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_2' 'state_changed' event: '{'brightness': 168, 'off_brightness': None, 'friendly_name': 'Master Closet Light 2', 'supported_features': 41}' with context.id='adapt_lgt_e2cf_light_event_82'
2020-12-04 17:50:30 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_1' 'state_changed' event: '{'brightness': 168, 'off_brightness': None, 'friendly_name': 'Master Closet Light 1', 'supported_features': 41}' with context.id='adapt_lgt_e2cf_light_event_81'
2020-12-04 17:50:30 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] State change event of 'light.master_closet_1' is already in 'self.last_state_change' (adapt_lgt_e2cf_light_event_81) adding this state also

2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_1' 'state_changed' event: '{'brightness': 167, 'off_brightness': None, 'friendly_name': 'Master Closet Light 1', 'supported_features': 41}' with context.id='7cb77154a2817828037d33c85423661a'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Detected an 'off' → 'on' event for 'light.master_closet_1' with context.id='7cb77154a2817828037d33c85423661a'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: '_update_attrs_and_maybe_adapt_lights' called with context.id='adapt_lgt_e2cf_light_event_89'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Adaptive Lighting: '_adapt_lights(['light.master_closet_1'], 1.0, force=True, context.id=adapt_lgt_e2cf_light_event_89)' called
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.master_closet_1', 'transition': 1.0, 'brightness': 166} with context.id='adapt_lgt_e2cf_light_event_89'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.master_closet_1']')' event with context.id='adapt_lgt_e2cf_light_event_89'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_1' 'state_changed' event: '{'brightness': 166, 'off_brightness': None, 'friendly_name': 'Master Closet Light 1', 'supported_features': 41}' with context.id='adapt_lgt_e2cf_light_event_89'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_3' 'state_changed' event: '{'brightness': 167, 'off_brightness': None, 'friendly_name': 'Master Closet Light 3', 'supported_features': 41}' with context.id='00ef699d40e73439198ae6e629f7dc8d'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Detected an 'off' → 'on' event for 'light.master_closet_3' with context.id='00ef699d40e73439198ae6e629f7dc8d'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: '_update_attrs_and_maybe_adapt_lights' called with context.id='adapt_lgt_e2cf_light_event_90'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Adaptive Lighting: '_adapt_lights(['light.master_closet_3'], 1.0, force=True, context.id=adapt_lgt_e2cf_light_event_90)' called
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Adaptive Lighting: Scheduling 'light.turn_on' with the following 'service_data': {'entity_id': 'light.master_closet_3', 'transition': 1.0, 'brightness': 166} with context.id='adapt_lgt_e2cf_light_event_90'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected an 'light.turn_on('['light.master_closet_3']')' event with context.id='adapt_lgt_e2cf_light_event_90'
2020-12-04 17:54:18 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Detected a 'light.master_closet_3' 'state_changed' event: '{'brightness': 166, 'off_brightness': None, 'friendly_name': 'Master Closet Light 3', 'supported_features': 41}' with context.id='adapt_lgt_e2cf_light_event_90'

@Chreece
Copy link

Chreece commented Dec 27, 2020

I can also confirm that with my Osram Zigbee lamp

@willtho89
Copy link

willtho89 commented Jan 7, 2021

I did some testing and it looks like the problem is as suggested by @basnijholt: The states of ZHA devices are a bit unreliable. If a device is seen as on in HA, adaptive light tries to adjust its brightness/temperature according to your settings. Unfortunately lights turn on, on brightness change. This seems to be an expected behavior in HA itself.

@basnijholt i think it would be reasonable to add a flag ignore off -> on state change for 1 intervall (or x sec). This might mitigate the error here

@miezie
Copy link

miezie commented Jan 10, 2021

I can confirm the same behavior with Philips and Ikea lights on a Conbee2 stick with Deconz. More then with the original circadian lighting component. Think it relates to the combination of Deconz groups, single light bulbs and HA light groups. Will make that more sophisticated on my side but would like to share my initial thought...

@drinfernoo
Copy link

Has anyone been able to figure out what is happening here? I have two Sengled bulbs which seem to be doing something similar to this... where they sometimes come on randomly, but only at night. It started with one of my bulbs, and has been happening off and on (sometimes doesn't happen at all, sometimes happens many times in a night) for a few months. It just started last night with the second bulb.

Both bulbs are bound directly to one Lutron Aurora each, and none of my Zigbee devices are part of any group (HA or Zigbee). I use ZHA with an HZUSBZ-1 stick.

@miezie
Copy link

miezie commented Jan 18, 2021

I can confirm the same behavior with Philips and Ikea lights on a Conbee2 stick with Deconz. More then with the original circadian lighting component. Think it relates to the combination of Deconz groups, single light bulbs and HA light groups. Will make that more sophisticated on my side but would like to share my initial thought...

I did my checkings and refactored it entirely... Using groups or not using them doesn't differ. I do have one positive thing here... it happens quite a lot and most of the time when shutting down several entities. I will raise loglevels to give some valuable input later on.

@broyuken
Copy link
Author

I seem to have been able to fix it. I think the problem comes in if a light is transitioning while it is shut off, the transition continues which turns the light back on. I fixed this by setting the transition to 1 second. Haven’t had the issue since.

@lennartgrunau
Copy link

I seem to have been able to fix it. I think the problem comes in if a light is transitioning while it is shut off, the transition continues which turns the light back on. I fixed this by setting the transition to 1 second. Haven’t had the issue since.

Trying this right now.

Additionally, I created an automation that fires a light.turn_off ~10 seconds after the first turn off.
Elegant? Nah, but it definitly turns the lights off, when I leave home.

@th3w1zard1
Copy link
Collaborator

th3w1zard1 commented Mar 9, 2023

Following up with some newfound additional research on this issue.

I realize now that most users who have this problem probably have adaptive-lighting as their only automation involving lights. At the very least, adaptive-lighting modify's lights more than any other automation inside of HASSIO. (see #427)
Because of this, I believe it's entirely possible adaptive-lighting isn't causing issue #10 at all, and this issue is always caused outside of adaptive-lighting or even user error.

Please allow me just a moment to explain this happening in a scenario where adaptive-lighting isn't involved:

Setup: user has Zigbee lightbulbs in their bedroom connected to a LAN server running HASSIO and a zigbee mesh running the addon 'zigbee2mqtt'. No automations are running.
Lights are connected in the following manner:
switch >> light >> zigbee2mqtt >> home assistant. The switch is decidedly not connected to HASSIO or zigbee2mqtt

>user has his lights on in his bedroom for most of the day.
>light disconnects momentarily due to a connection hiccup
>user turns bedroom lights off to go to sleep

Here's two problematic possibilities:

>zigbee2mqtt pings the bulb in the middle of the night since it hasn't heard from it in hours.
>bulb replies
>zigbee2mqtt sends that info to hassio
**>hassio tells bulbs to resume last known state ON.**
OR
>bulb reports its status to hassio in the middle of the night.
**_>zigbee2mqtt replies with its knowledge of the bulb's last known state ON_**

These are common scenarios Zigbee light users have to deal with on initial setup. Usually, all the user needs to do is set 'power_on_state' to 'off' in the bulb itself, or fix their MQTT retention settings.
Another common user error that I can't fit into this post, is incorrectly setting up switches to retain messages. Doing this will cause the bulb to execute the switch's command when it inevitably reports to zigbee2mqtt, even if that command was issued hours ago. See this video for more information on MQTT retention settings

If you're still reading: I thank you for sticking around this far. Let me now explain how this relates to adaptive-lighting and this issue thread #10.
Now let's assume the user fixed that during initial installation, then installed adaptive-lighting.

With adaptive-lighting, the dev in his infinite wisdom implemented a very nice and surprisingly simple 'detect_non_ha_changes' feature. It definitely runs correctly in all the tests on my end. We're all very grateful.
Yet randomly, I'll still have bulbs turn themselves on in the middle of the night despite 'detect_non_ha_changes: true' set.

And finally my main point. I can think of two possible causes to issue #10:

1. Update_entity causes zigbee2mqtt to ping the bulb. With 'power_on_state: last_known' setup in its device settings AND improper retain options from the switch available on the MQTT broker, zigbee2mqtt would tell the bulb to turn on like it believes it's supposed to be.

2. update_entity doesn't actually grab a state report from the bulb, just the data from zigbee2mqtt available in the broker, causing adaptive-lighting to use unreliable information to do its check for a significant change.

The snippet below from switch.py is only called when detect_non_ha_changes is set to true.

    async def significant_change(
...
    ) -> bool:
        """Has the light made a significant change since last update.

        This method will detect changes that were made to the light without
        calling 'light.turn_on', so outside of Home Assistant. If a change is
        detected, we mark the light as 'manually controlled' until the light
        or switch is turned 'off' and 'on' again.
        """
        if light not in self.last_state_change:
            return False
        old_states: list[State] = self.last_state_change[light]
        **_await self.hass.helpers.entity_component.async_update_entity(light)_**
        new_state = self.hass.states.get(light)
        ... some compare checks are below ...

Scenario 1 would already have its light on right after the update_entity call.

In scenario 2, old_state could have brightness at 255 and new_state according to zigbee2mqtt could be 255. The bulb hasn't even been pinged despite the update_entity call!
What's worse is this might not be apparent in the first day or even week of using adaptive-lighting, just on the scenarios where zigbee2mqtt occasionally has slightly outdated information available.

The fix in scenario 2 would be to set bulb reporting to 'on', turn off retain in its device settings, and ensure zigbee2mqtt is actually pinging the bulb directly for its current state everytime.

Yes I'm talking about zigbee2mqtt which I'm using and many of you might not be, but I think this can happen with any system sending messages through MQTT. Tasmota comes to mind as using MQTT as well. Again, please see the video
If I'm right about this, the issue isn't caused by adaptive-lighting or even MQTT; it's improperly configured user settings.

Thank you for sticking around to the end!

TL;DR see #447

@th3w1zard1
Copy link
Collaborator

th3w1zard1 commented Mar 24, 2023

see #486

@th3w1zard1 th3w1zard1 added this to Review in progress in Issues/Features TODO List Apr 2, 2023
@th3w1zard1
Copy link
Collaborator

th3w1zard1 commented Apr 4, 2023

@broyuken This should be fixed in 1.10.1

Issues/Features TODO List automation moved this from Review in progress to Done Apr 4, 2023
@broyuken
Copy link
Author

This isn’t fully solved, one of my lights randomly turned on at 6am this morning. The logs just show that it was turned on, not called by anything.

@th3w1zard1
Copy link
Collaborator

If you can post logs showing adaptive lighting fired the light.turn_on command I'll happily reopen this issue and get a priority status on this issue for the next release.

@broyuken
Copy link
Author

That’s the problem, light.turn_on isn’t called. It just says the light was turned on.

@th3w1zard1
Copy link
Collaborator

th3w1zard1 commented Apr 12, 2023

@broyuken

There's only two situations where adaptive lighting does anything to a light entity specifically:

  1. when it calls light.turn_on which will be logged every time.
  2. on every interval, if detect_non_ha_changes: true, adaptive lighting will call async_update_entity to force a state update for your bulb.

If you're not getting the log message then only three possibilities remain, ordered most to least likely:

  1. your zigbee network has too much latency/traffic and needs either more routers or an adjustment to the config, perhaps QoS of 1 instead of 0.
  2. async_update_entity is scaring your bulb into confusion somehow. Ensuring a proper configuration and ensuring the above problem is solved will fix this.
  3. home assistant is doing things it shouldn't be or home assistant has some other broken behavior. You can replicate yourself by copying every light.turn_on adaptive lighting does from the logs into a script with the same delays in between to test yourself. Or try AL with another version of HASS.

if light.turn_on was not called by the integration, there's nothing we can do on our end, as we're not doing anything on our end if you catch my drift...

See #506 to ensure you have the proper config options set for your lights for use with this integration. My guess is there's an improper z2m config option or your LQI is too high.

@th3w1zard1 th3w1zard1 reopened this Apr 12, 2023
v2 automation moved this from Inbox to Reopened Apr 12, 2023
Issues/Features TODO List automation moved this from Done to In progress Apr 12, 2023
@basnijholt
Copy link
Owner

basnijholt commented Jul 27, 2023

Great news, there might be a solution! 🎉 🚀

I also had a major insight yesterday going through the code line-by-line.

I believe the issue of lights turning on is always because for some reason: the light will incorrectly report its state as on! (as mentioned by @th3w1zard1 above).

Because AL then notices a state change, and this state is likely not precisely what it should be according to AL, it will adapt it to the correct state, inadvertently turning the lights on.

In this PR #663, I have made some changes. With that code when detect_non_ha_changes: false and there is a 'off' → 'on' state change which is not the result of a light.turn_on, it will mark the light as manually controlled and not adapt it at all.

I have one light at home which frequently turns on again after I turned it off, I will see whether this still happens with the changes. If not, I will merge and release a new version.

@basnijholt
Copy link
Owner

Hi folks!

I have merged #663 and released v1.18.0. Set detect_non_ha_changes: false for the switches that contain the lights that accidentally turn on.

I will close this issue and would really appreciate folks reporting back on whether the issue is fixed. ⚙️

Thanks everyone for your support and patience in getting this issue fixed! 🙌❤️

Issues/Features TODO List automation moved this from In progress to Done Jul 29, 2023
@basnijholt
Copy link
Owner

BTW if you have debugging logging enabled you'll see messages like these:

2023-07-28 12:40:00.233 DEBUG (MainThread) [custom_components.adaptive_lighting.switch] Bedroom: Ignoring 'off' → 'on' event for 'light.baby_room' with context.id='01H6F07PV5V2HD7W30083Y8RZS' because 'light.turn_on' was not called by HA and 'detect_non_ha_changes' is False

This would previously have turned on the light 💡

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
v2
Reopened
Development

No branches or pull requests