Random lights turning on, not sure why, how to debug?

Configuration
1

I have a trigger that turns everything off. In the picture you can see it’s triggered and everything shuts off but then a random light (not always the same one) comes back on. This trigger is handled in nodered but all it’s doing is sending the homeassistant.turn_off command to all the entities so I think this is a HA issue. How can I track this down, how do I figure out how the turn on command is being fired?

Edit: Actually, looking over the log it appears the living room never got the off command but instead got on. That’s even stranger, somehow everything else got off but it got on?

image
image750×520 80.1 KB

2 
logger:
  default: debug

Then start searching through home-assistant.log. More than likely there are details/clues in there that can help you answer your own question.

3

Your Aeotec sensor has likely created an association with the switches causing them to toggle on/off when motion is detected.

Search the zwave section of the forum for solutions.

4

If it was associated wouldn’t it happen every time? This seems to only happen when I trigger something that turns a bunch of things on/off. I notice this in the morning (turning a bunch of lights on) and with my lockup trigger. It’s as if something is getting overwhelmed or something and it’s hard to replicate. If I run lockup right now it works…

5

Ugh, this happened again this morning with the master bedroom light! This has to be a bug in HA somewhere but tracking this down would be pretty impossible considering how infrequence it happens. I’ve had my logs on debug since the last instance months ago so I was able to trace through it but besides the normal zwave status updates I see the only reference to the light turning on is this:

2019-12-08 05:32:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=zwave.bedroom_light, old_state=<state zwave.bedroom_light=ready; node_id=5, node_name=Bedroom Light, manufacturer_name=Cooper, product_name=RF9534DS Wall Dimmer Module, query_stage=Complete, is_awake=True, is_ready=True, is_failed=False, is_info_received=True, max_baud_rate=40000, is_zwave_plus=False, capabilities={'routing', 'listening'}, neighbors={1, 2, 3, 4, 7, 10, 11, 12, 14, 15, 19, 20, 22, 23, 24, 26, 27, 28, 29, 30}, sentCnt=8436, sentFailed=96, retries=25, receivedCnt=8697, receivedDups=240, receivedUnsolicited=39, sentTS=2019-12-08 05:32:06:122 , receivedTS=2019-12-08 05:32:06:213 , lastRequestRTT=83, averageRequestRTT=50, lastResponseRTT=90, averageResponseRTT=57, application_version=1.12, friendly_name=Bedroom Light @ 2019-12-07T06:54:00.379671-05:00>, new_state=<state zwave.bedroom_light=ready; node_id=5, node_name=Bedroom Light, manufacturer_name=Cooper, product_name=RF9534DS Wall Dimmer Module, query_stage=Complete, is_awake=True, is_ready=True, is_failed=False, is_info_received=True, max_baud_rate=40000, is_zwave_plus=False, capabilities={'routing', 'listening'}, neighbors={1, 2, 3, 4, 7, 10, 11, 12, 14, 15, 19, 20, 22, 23, 24, 26, 27, 28, 29, 30}, sentCnt=8437, sentFailed=96, retries=25, receivedCnt=8698, receivedDups=240, receivedUnsolicited=39, sentTS=2019-12-08 05:32:08:220 , receivedTS=2019-12-08 05:32:08:246 , lastRequestRTT=18, averageRequestRTT=34, lastResponseRTT=25, averageResponseRTT=41, application_version=1.12, friendly_name=Bedroom Light @ 2019-12-07T06:54:00.379671-05:00>>

2019-12-08 05:32:08 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.bedroom_light_level, old_state=<state light.bedroom_light_level=off; node_id=5, value_index=0, value_instance=1, value_id=72057594126630913, friendly_name=Bedroom Light, supported_features=33 @ 2019-12-07T17:30:42.528597-05:00>, new_state=<state light.bedroom_light_level=on; brightness=240, node_id=5, value_index=0, value_instance=1, value_id=72057594126630913, friendly_name=Bedroom Light, supported_features=33 @ 2019-12-08T05:32:08.366538-05:00>>

2019-12-08 05:32:08 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.139813407445968] Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'zwave.bedroom_light', 'old_state': <state zwave.bedroom_light=ready; node_id=5, node_name=Bedroom Light, manufacturer_name=Cooper, product_name=RF9534DS Wall Dimmer Module, query_stage=Complete, is_awake=True, is_ready=True, is_failed=False, is_info_received=True, max_baud_rate=40000, is_zwave_plus=False, capabilities={'routing', 'listening'}, neighbors={1, 2, 3, 4, 7, 10, 11, 12, 14, 15, 19, 20, 22, 23, 24, 26, 27, 28, 29, 30}, sentCnt=8436, sentFailed=96, retries=25, receivedCnt=8697, receivedDups=240, receivedUnsolicited=39, sentTS=2019-12-08 05:32:06:122 , receivedTS=2019-12-08 05:32:06:213 , lastRequestRTT=83, averageRequestRTT=50, lastResponseRTT=90, averageResponseRTT=57, application_version=1.12, friendly_name=Bedroom Light @ 2019-12-07T06:54:00.379671-05:00>, 'new_state': <state zwave.bedroom_light=ready; node_id=5, node_name=Bedroom Light, manufacturer_name=Cooper, product_name=RF9534DS Wall Dimmer Module, query_stage=Complete, is_awake=True, is_ready=True, is_failed=False, is_info_received=True, max_baud_rate=40000, is_zwave_plus=False, capabilities={'routing', 'listening'}, neighbors={1, 2, 3, 4, 7, 10, 11, 12, 14, 15, 19, 20, 22, 23, 24, 26, 27, 28, 29, 30}, sentCnt=8437, sentFailed=96, retries=25, receivedCnt=8698, receivedDups=240, receivedUnsolicited=39, sentTS=2019-12-08 05:32:08:220 , receivedTS=2019-12-08 05:32:08:246 , lastRequestRTT=18, averageRequestRTT=34, lastResponseRTT=25, averageResponseRTT=41, application_version=1.12, friendly_name=Bedroom Light @ 2019-12-07T06:54:00.379671-05:00>}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2019, 12, 8, 10, 32, 8, 363032, tzinfo=<UTC>), 'context': {'id': 'e85bae8c3dff4d8ebf6c0e262c38602c', 'parent_id': None, 'user_id': None}}}

It just appears to happen. For context, at 5:30 every day I have a set of lights turn on, the bedroom light is not one of them. Everyday, for months (years) this has worked fine but randomly another light will turn on (or one of the ones that should turn on, don’t) and it can cause problems. It’s not a linked light or part of an automation as it would happen more frequently, this is clearly some kind of race condition/bug in the system when the stars are aligning. This morning, in addition to our bedroom light two other lights came on too that are not part of the animation, one of which is the pantry light that only turns on if the door sensor is triggered which it was not but the light was on.

2019-12-08 05:32:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.pantry, old_state=<state light.pantry=off; friendly_name=Pantry Light, supported_features=41 @ 2019-12-07T16:52:37.703943-05:00>, new_state=<state light.pantry=on; brightness=254, friendly_name=Pantry Light, supported_features=41 @ 2019-12-08T05:32:01.252449-05:00>>

Any thoughts?

6

Check your logbook.
Check your automations.

If there was a bug in HA everyone would be experiencing it.

7

That’s not true, bugs happen all the time that only surface in certain situations.

I’ve looked over the raw debug logs of HA and there is nothing triggering this at all, the state just changes. If it was an automation I would see the service call like I do for the other lights that turn on.

8

I donno man, been using zwave (~65 devices, ~40 of them are lights/switches) for 4 years and don’t have this issue. I have automations do everything for me for lights. Never had a light come on when it’s not supposed to.

You can debug this by adding an automation that notifies you when your context is emtpy, using a state trigger.

condition:
  condition: template
  value_template: >
    {{ trigger.to_state.context.user_id == None and trigger.to_state.context.parent_id == None and trigger.to_state.context.id == None }}

EDIT: When the context is empty, it’s coming from a manual press (i.e outside HA). I’d have to verify again, but that’s what I remember last time I checked the context object.

9

For anyone who stumbles across this: I had the same thing happen to me last night, a zigbee light turned on on its own.
Going through the logs, I discovered the light becomes unavailable from time to time and when it comes online again, it turns on by default. So in my case the problem is bad zigbee coverage.

1 Like
10

A lot of times the way to turn on a smart bulb outside of the automation system is by turning off the power to the bulb and then turning it back on which forces the bulb itself to light up.

If the bulb goes “unavailable” and then the bulb lights up when it comes back sounds like an electrical issue with either the bulb or the power to the bulb. I doubt it’s due to zigbee coverage.

1 Like