Motion Lighting appears to Override iteself

kristjan · January 14, 2019, 4:19pm

Morning!

Motion Lighting wasn't always turning off the lights in my kitchen, and when I look, it says it's been overridden, but no one has manually adjusted or touched anything. It looks from the logs like it happens when I leave the room and the sensor becomes inactive, then come back in. ML notices the lights are already on and sets the "Don't turn off if already on" override, even though ML itself was what initially turned them on. There's also an exciting null in the logs

I would have expected the going/coming to just persist activity and keep the lights on until I leave for good, then automatically turn them back off. Have I misunderstood something about the configuration?

Heading to work for the day, but let me know what else I can gather for you and I'll pick it up tonight. Meantime, I have an RM catchall shutting the lights off after 15 minutes of inactivity.

Here's my config:

And the logs:

Lastly the app state (lights are currently stuck on):

Appreciate the help!

bravenel · January 14, 2019, 4:45pm

What release are you running?

kristjan · January 14, 2019, 5:38pm

I ran the system update last night, so it should be on latest. I can confirm once I'm back on my network.

The sticking was happening before the update (I was hoping for a lucky bugfix in this one), so I think it's an issue in at least the past 2 versions.

bravenel · January 14, 2019, 5:52pm

This one is very strange. I'm not able to reproduce it. So if you find this again, I'd like to drill into what is going on with it. I did discover that the message about override being turned on is sometimes given when override is not turned on, but in your case, it was. The null in the logs is also a mystery at the moment. Investigating that...

kristjan · January 14, 2019, 6:31pm

Is there anything I should try to kick? I deleted and recreated the rule last night.

The dimmer is an HS-WD200+, and the motion sensor is Hue. I haven't noticed anything weird with them, but just in case.

I also have some Hue bulbs following this dimmer via Cobra's One to Many app. I don't see a reason this automation would care, but I'll try disabling it in case there's some weird interaction.

bravenel · January 14, 2019, 6:35pm

Please just keep an eye on it, and if this happens again let me know. The Cobra app would not have any effect on it. If this does happen again, we'd want to turn on some special logging in your hub to track it down.

kristjan · January 14, 2019, 6:38pm

Oh it'll happen again - I can reliably reproduce it by walking in and out of the kitchen at the right times . Lemme know what I should turn on.

And thank you for the speedy response, BTW, in really impressed with y'all's attentiveness!

kristjan · January 15, 2019, 5:36am

Just updated from 2.0.4.114 to .116, no change.

app:1082019-01-14 09:25:16.916 pm infoNot turning off: disabled by override
app:1082019-01-14 09:25:05.728 pm infoNot turning off: disabled by override
app:1082019-01-14 09:25:05.671 pm infoMotion inactive Kitchen Motion Sensor
app:1082019-01-14 09:24:36.080 pm errorjava.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.String (alreadyOn)
app:1082019-01-14 09:24:36.035 pm infoOverride initiated by Kitchen Dimmer
app:1082019-01-14 09:24:34.266 pm infoSetting dimmers [Kitchen Dimmer] to 100
app:1082019-01-14 09:24:34.191 pm infoMotion active Kitchen Motion Sensor
app:1082019-01-14 09:22:16.880 pm infoDelaying off for 3 minutes
app:1082019-01-14 09:22:16.730 pm infoMotion inactive Kitchen Motion Sensor
app:1082019-01-14 09:21:45.692 pm infoSetting dimmers [Kitchen Dimmer] to 100
app:1082019-01-14 09:21:45.514 pm infoMotion active Kitchen Motion Sensor

kristjan · January 15, 2019, 4:39pm

Two new hypotheses on the train:

Motion Lighting is configured for 100% brightness, but the dimmer only hits 99%. Perhaps that looks to ML like an override on the second pass.
The logs only report the dimmer hitting 39% due to their slow ramp rate. If ML last sees that, perhaps the real 99% level looks like an override.

I'll observe the logs and application state this evening. For now these are just thought experiments.

bravenel · January 15, 2019, 4:58pm

ML knows what the target brightness level is. It's looking for a level report that is different from the target. So, the 39% during ramp looks like that, and it goes into override.

I'm not sure what to do about it. Override is just a tricky beast. It used to be that it only worked for "physical" events, initiated by the switch. But, many switches don't report these events faithfully, so that failed a lot. Now, it's looking for a non-target dimmer level. The implication is that devices that report ramp rate intermediate level events are not compatible with override.

It has to have some way to know that a level report represents a request to override the set level. This works well with Alexa or Google Home. Many devices only report level when the level change is complete. Those will work. I will just have to document that it will not work with devices that report levels during ramp.

kristjan · January 15, 2019, 5:09pm

Well rats, that's indeed a bummer!

I've found the WD's native ramp rate annoyingly slow anyway - would you expect that if it ramped faster it would get to the target brightness before reporting? I didn't see a solution for that in Homeseer WD200 LED Color and Ramp rate, but would love to tweak it whether or not the dimmer can work with ML.

raidflex · January 15, 2019, 6:33pm

Does this method still work in motion lighting if the switch used supports physical events?

bravenel · January 15, 2019, 6:41pm

It no longer uses physical events to enter override. It uses a change relative to the target level. This works except for devices that report intermediate levels during ramp.

bravenel · January 15, 2019, 6:43pm

Question for you to explore: does this device report "physical" events? Look at the Device Events from the device page, and you can see there it will say Digital or Physical. Perhaps a solution would be yet another option for override, one that distinguishes which of two methods to use -- physical or level change.

raidflex · January 15, 2019, 6:47pm

My Leviton switches do differentiate between physical and digital events, that is why I was curious if ML would still use the physical event as a an override.

I think you are right in having two different methods.

raidflex · January 15, 2019, 7:13pm

So currently which method does the app subscribe to? Or are both just implemented automatically which is what is causing issues.

bravenel · January 15, 2019, 7:31pm

this

kristjan · January 16, 2019, 6:24am

Yep! These dinmers do report digital with motion and when they broadcast their level during the ramp, and physical when I press it.

That option in the config sounds promising. I'm also thinking I could set up RM to disable ML upon that button press and enable it again when the lights are switched off.

kristjan · February 9, 2019, 2:40am

Update here for anyone the thread might help in the future:

I found Super basic Z-Wave parameter tool (Thank you, @mike.maxwell!) and set the switch ramp rates to 1 second. They appear to report their level 1 second into the change, so this results in them reporting 99% as they should, instead of 39% during a 3 second ramp. Now ML sees the level where it's expected and functions perfectly.

It looks like in later WD200+ firmware, the switch will report both its current level and its target level. The upgrade story is miserable, between the newer ZWave version running them out of space for code and the user needing a paid license and hardware for the upgrade software; so I doubt I'll ever get there, but it could be a helpful feature in the future.

Saw the "physical" option appeared in the latest HE release too, so I'll play around with that. Thank you, @bravenel!