danobot
commented
3 years ago So you have transitions configured on your light?
Closed mplogas closed 3 years ago
danobot
commented
3 years ago So you have transitions configured on your light?
danobot
commented
3 years ago This is caused by transitions in brightness. Can you try adding brightness to the state_attributes_ignore list?
mplogas
commented
3 years ago @danobot
So you have transitions configured on your light?
Not that I'm aware of. Currently all lights controlled by EC are without any further customization.
This is caused by transitions in brightness. Can you try adding brightness to the state_attributes_ignore list?
OK, added. I'll get back once I see results. One question, though: Now that I ignore brightness changes, how would I move to a 'wanted BLOCKED state', e.g. by dimming light up or down manually from lovelace?
vlefevre86
commented
3 years ago I have the same issue, and brightness has been on the state_attributes_ignore for a long time (using circadian)...
danobot
commented
3 years ago Can we focus on one EC configuration please? Do you have an example of bad_oben where it doesnt work? Please simplify the issue description, else there are too many variables. What is the minimum configuration that reproduces the issue? Start by removing night mode and service_data.
EC only ignores state changes caused by its own operations (making the service calls for example). Any state changes caused by other contexts (such as the random hash one 41215b3808d811ebab745962c5c87d60) is correctly treated as some manual control and put EC into blocked.
Do you have an entity named 41215b3808d811ebab745962c5c87d60? It could be an entity created by another ingegration.
vlefevre86
commented
3 years ago Ho sure, I was just trying to help you figure out the issue, as it seems to behave the same, and only started to behave like that after updating EC without changing anything else. Don't mind me.
danobot
commented
3 years ago I was talking to @mplogas, there are two EC configs and logs in the issue description and its hard to compare that way.
danobot
commented
3 years ago I checked my own logs and for me manual control created those random ids, the same is true for automations turning on entities.
hass | 2020-10-08T14:11:58.423794346Z 2020-10-08 22:11:58 DEBUG (MainThread) [custom_components.entity_controller.mtn_lounge] state_entity_state_change :: [ Entity: light.tv_led, Context: Context(user_id='602fcc0cbfad440fae92787b1fbb106e', parent_id=None, id='3a3df3cc097011eb95411590d88d6479') ]
hass | 2020-10-08T14:11:58.423830265Z Old state: <state light.tv_led=on; brightness=79, friendly_name=TV Backlight, supported_features=1 @ 2020-10-08T22:09:11.659551+08:00>
hass | 2020-10-08T14:11:58.423933319Z New State: <state light.tv_led=on; brightness=166, friendly_name=TV Backlight, supported_features=1 @ 2020-10-08T22:09:11.659551+08:00>Does your logbook give any indicator what might be going on?
I created v9.0.1 with more detailed context logging you can see in the above logs.
mplogas
commented
3 years ago @danobot
Can we focus on one EC configuration please?
Oh, I'm sorry, I didn't meant to confuse the situation. See, both bad_oben and bad_unten have more or less the same EC rules, same type of hardware (Indoor Phillips Motion Sensor, Osram Ceiling Leight) on the same firmware. It thought of including this to demonstrate the "randomness" of it. BTW: bad_oben is working almost all the time, while bad_unten almost never works. So I'll focus on bad_unten for now.
What is the minimum configuration that reproduces the issue? Start by removing night mode and service_data.
OK, will do, but I need to wait for the weekend until my family isn't interfering and I have plenty of night hours to test.
Do you have an entity named 41215b3808d811ebab745962c5c87d60
Nope, not at all. But I digged in my recorder db, only to find this:
Time and date matches to yesterdays event. However I have no idea what the context_id is about, but I'm happy to dig deeper if you want.
I created v9.0.1 with more detailed context logging you can see in the above logs.
I'll give it a shot tonight and see what the log are saying.
danobot
commented
3 years ago What are your findings on this?
mplogas
commented
3 years ago @danobot sorry for abandoning the issue. EC is still acting weird but I'm currently in the process of rebuilding my HA instance on a dedicated NUC and move from deconz to zigbee2mqtt. I can't give any define answer for now. Once everything has settled I will start to investigate into the issue.
Thanks
MunkeyBalls
commented
3 years ago Noticing the same kind of behavior on my setup. I don't think it's the attributes, because I would've expected the "A significant attribute changed and will be handled" message to be in the logs. It seems like something funny is going on with the context ids, which makes sense because I see this happening more frequent with multiple lights in a group/controller. Also, I use flux and when disabling flux it seems to be harder to reproduce.
2021-01-07 22:37:33 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] state_entity_state_change :: Ignoring this state change because it came from ec_5a09f6_c96532bf1a90bc4e4254bddcea
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] state_entity_state_change :: [ Entity: light.kitchen2, Context: Context(user_id=None, parent_id=None, id='d4c90ff3409089ba356719d33ba23e0a') ]
Old state: <state light.kitchen2=off; min_mireds=153, max_mireds=500, effect_list=['night_mode'], friendly_name=kitchen2, supported_features=47 @ 2021-01-07T22:37:30.479614+01:00>
New State: <state light.kitchen2=on; min_mireds=153, max_mireds=500, effect_list=['night_mode'], brightness=255, color_temp=370, effect=white_mode, friendly_name=kitchen2, supported_features=47 @ 2021-01-07T22:37:34.091151+01:00>
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] state_entity_state_change :: We are in active timer and the state of observed state entities changed.
2021-01-07 22:37:34 INFO (MainThread) [custom_components.entity_controller.mtn_kitchen] <state light.kitchen_milight_mr16_1=on; min_mireds=153, max_mireds=500, effect_list=['night_mode'], brightness=255, color_temp=370, effect=white_mode, friendly_name=kitchen_milight_mr16_1, supported_features=47 @ 2021-01-07T22:37:33.186942+01:00>
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] State entities are ON. [light.kitchen_milight_mr16_1]
2021-01-07 22:37:34 INFO (MainThread) [custom_components.entity_controller.mtn_kitchen] <state light.kitchen_milight_mr16_1=on; min_mireds=153, max_mireds=500, effect_list=['night_mode'], brightness=255, color_temp=370, effect=white_mode, friendly_name=kitchen_milight_mr16_1, supported_features=47 @ 2021-01-07T22:37:33.186942+01:00>
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] State entities are ON. [light.kitchen_milight_mr16_1]
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] Exiting active
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] on_exit_active :: Turning off entities, cancelling timer
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] _cancel_timer :: Cancelling timer
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] on_exit_active | Performing Transition Behaviour
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] on_exit_active | Action - ignore
2021-01-07 22:37:34 DEBUG (MainThread) [custom_components.entity_controller.mtn_kitchen] Entering blockedConfig for this specific light:
mtn_kitchen:
sensor:
- binary_sensor.pir_kitchen_lights
entities:
- light.kitchen_milight_mr16_1
- light.kitchen2
- light.kitchen3
override:
- input_boolean.entity_controller_master
- input_boolean.entity_controller_kitchen_override
- binary_sensor.kitchen_brightness_block
state_entities:
- light.kitchen_milight_mr16_1
- light.kitchen2
- light.kitchen3
#service_data:
# brightness: 255
# transition: 5
delay: 60
backoff: true
backoff_factor: 1.5
backoff_max: 300
state_attributes_ignore:
- effect_list
- effect
- brightness
- color_temp
- rgb_color
- xy_color
- hs_color
- min_mireds
- max_mireds
#night_mode:
# delay: 60
# service_data:
# brightness: 70
# start_time: '23:00:00'
# end_time: '06:00:00'For now I've disabled to blocking completely by adding the following code in init.py in just before the try/catch block in the state_entity_state_change method. Note, this is not a fix, but a workaround since I need the lights to turn off more than the blocked feature.
self.log.debug("state_entity_state_change :: Ignoring ALL state changes")
returnwhen disabling flux it seems to be harder to reproduce
Are you able to reproduce it at all when flux is disabled?
MunkeyBalls
commented
3 years ago I've been testing for 2 days with flux disabled and I think the problem is as good as gone.
I say "as good as" because I am still running into blocked state every now and then. I think those instances where it's still going into blocked is due to a different problem where sometimes my lights don't get turned off when going from active_timer to idle state. Then the next time the entity controller is triggered it will enter blocked because the light is already.
Ignore this last section, instead of wasting your time I'll take some more time to see what's going on. I do see the lights sometimes not turning off though, and sometimes there's a flicker where lights get turned of and then instantly turned on again.
<<< Do not delete the following template headers. All information must be filled in because we need it to analyse the problem. Your issue will be auto closed without this information. Before opening a new issue, please read the documentation and search for keywords relating to your problem. Since this is an open source project expect to be involved in the issue resolution because we depend on your support. >>>
Description
I'm still having erratic BLOCKED states on several devices, although nothing is triggering the BLOCKED state. I described the issue in #195, and it improved but it's still not working all the time.
Configuration
Same HW configuration as in #195
EC v9.0.0
Steps to reproduce
Steps to reproduce the behavior:
It even seems the actor itself is triggering the BLOCKED state.
Expected behavior
EC unblocks after expiration timestamp when no movement is detected
Actual Behaviour
Logs
This is when it works (bad_oben, works 8 / 10 times as expected)
This is how it looks when it doesn't work (bad_unten, works 2 / 10 times). Please note the 4th
state_entity_state_change, it's not using 'bad_unten' as context but its id. Could that be a lead?Version
v9.0.0 is the latest public release