RM 4-0 debugging a rule

So i wrote a super simple rule

turn on lights when motion starts, if lights are already on cancel any off delays.
when motion stops, turn off lights after a 10 minute delay

here is the rule:

The light comes on and i can see that in the log. And i can see when the delayed off triggers.
yet. my light doesn't turn off though. This is from the log file:

2020-12-04 04:08:47.937 pm infoGarage can lights switch is on
app:5272020-12-04 04:08:47.191 pm infoDelay Over: Off: Garage can lights --> delayed: 0:10:00 (cancelable)

Any idea what is going on and what i should look at?
I checked the event log on the switch and this is what came up

Interesting that it doesn't show the time when the light turned on in the device event log, but it shows that the device was on at 4.08:47 when i was expecting the off command to be sent as the delay timer expired.

any idea what to look for (or what i may have done wrong)?

Try this instead:

Trigger:  Garage motion active
Actions:
   On Garage can lights
   Wait for Condition Garage motion inactive
   Wait for Elapsed time 10:00
   Off Garage can lights

The cool thing about this way, is that Wait is auto-cancelled by the rule being triggered. So this thing is going to wait for motion inactive, then wait 10 minutes, then turn off the lights. If motion goes active again, the whole thing starts over again without turning them off.

7 Likes

Thats clever! Thanks I'll try it out tonight.

Out of curiosity,so when the executing thread sits in wait for elapsed time, and another motion event arrives what happens? Does it get queued or is it discarded? In an event driven system I would imagine that you have an exactly-once semantic and the event is queued?

Ie it's assume my sensor generates 5 motion active events in a 10 minute window does this extend my lights on to 50 minutes? Does each event gets processed one after another after the ten minutes elapsed?

I assume a new event does not lead to a new instance of the rule being fired up, there must be a queue of some kind?

The thread is not executing and sitting in a wait. What has happened is that Rule scheduled an event for 10 minutes in the future, and exits -- it is no longer running. When that scheduled event happens, it launches the rule to pick up at the next action after the Wait.

If the rule is triggered, any scheduled event for a Wait is unscheduled, so it never happens, so the rule will not be launched to pick up after the Wait. Effectively, the Wait has been cancelled. If the Wait is for some other type of event or condition, the Rule will have subscribed to that event, and then exited. If the rule is triggered, that subscription is removed, so it never launches the rule from that waited for event. Effectively, the rule being triggered wipes out any pending Wait -- of which there can only be one pending at any one time.

Given this, if during a Wait the rule is triggered, it's as if the rule is starting over from scratch, albeit with the lights already being on. It will send the on command again, but who cares, that won't do anything (and one could condition that with a test of the light being off if one really cared about it). So the rule's actions run again from the top first waiting for motion to go inactive, and then scheduling the ending of elapsed time in 10 minutes.

The net effect is that the lights will stay on until 10 minutes after motion has become inactive, however long that takes, but not for more than those 10 minutes after.

And, btw, 10 minutes is a very long time to leave lights on after motion quits. You can usually use 1 or 2 minutes for most cases.

Got it, so I should think about the model as truly event driven and what can be thought of as a blocking event inside an execution block gets unscheduled upon arrival of a new trigger to ensure that only one event is processed at a time? That's kind of neat. Makes the logic clean and avoids reasoning about race conditions. I was over thinking it, thinking I had to check for state when new events arrive to avoid setting multiple concurrent execution blocking timers.

Thinking of them as scheduled events into the future that automatically cancels when a new trigger arrives makes it easy to reason about them.

I assume this is only true for things that block execution as well as for asynchronous events like delays?

Eg For non blocking things like delays that get scheduled into the future do they too get unscheduled if a new delay gets set for the same object? do each delay execute multiple times if a trigger gets tripped multiple times and it has that delay inside ita execution block and none of the delays have been triggered before a new one gets scheduled? (And if that is the case, if a cancel delay gets called which of the delays gets cancelled)?

I assume it's only one delay per object, it seems to be most compatible with how you described the design of the wait logic.

Yeah, ten minutes is kind of long. I've had it that way for a while so that lights start on when I move thinga in and out of the garage. But yeah, it's kind of long.

Even so, my understanding is that your original rule should work. There doesn't seem to be anything inherently wrong with it. The wait method would just be another way to do it.
Maybe test directly in the device page sending the off command manually and see if it turns it off?

Yes, the hub is an event driven system, pure and simple. It is multi-threaded so simultaneous execution of parallel instances of an app can and does happen, and this can cause race conditions and other problems.

This automatic cancellation feature only applies to Waits, not Delays. You can definitely get into trouble with simultaneous instances where a rule involves conditionals and embedded delays. So I really like Wait as a cleaner approach to problems such as the one you posed.

Multiple delays do get scheduled. Cancel delays cancels all pending delays that are cancellable. Best to design things so that this doesn't happen.

1 Like

Awesome! Thanks for helping me form a me a mental model. The cancellation of wait is neat.

The light automation seems to work well, I don't know why my log showed differently.

So a door lock automation is simple, just another version of the light automation?
Trigger: Door contact sensor any
If (door closed == TRUE) then
wait 10 min
lock door
End-if

Any benefits to consolidation simple automations into rule machine? Is it more lightweight than running standalone apps for simple things like the example I just made?

Lightest wait are Groovy apps that are case specific, then Simple Automation Rule, then Motion Lighting, and heaviest is Rule Machine.

1 Like