[Resolved] Bug? Light off after x minutes not working with RM or Simple Lighting

I've tried this with Rule Machine as well as Simple Lighting and it's not working.
Is there some limit to the amount of delay between a trigger and an action (is 6 minutes too long or something?)

Desired automation:
When motion occurs, turn the light on.
When motion stops, turn the light off after 6 minutes.

What is happening:
When motion occurs, the light turns on.
Motion stops and reports accordingly to Hubitat.
6-8 minutes later the light is still on with no additional motion occurring on the sensor.

Further Explanation:
I tried setting this up in Simple Lighting initially. When it didn't turn the light off after 6 minutes (does Simple Lighting not report any logs? I couldn't find any), I deleted the automation and then tried doing it in Rule Machine. It too did the same thing, but had logs showing when it turned the light on. The device logs showed when the motion sensor reported inactive. I left the Logs window open and 6-8 minutes after the motion reported inactive the light remained On and Rule Machine logged nothing after turning it on.

Simple Lighting (no restrictions):
image

Rule Machine (no restrictions):

You're looking for the Event of Motion Stop/inactive/end.. is it occurring? Do logs show it?

dev:271 2018-07-19 19:29:08.548:debug motion inactive
dev:271 2018-07-19 19:28:53.211:debug motion active

Have you tried using the Motion Lighting App? I have grouped my bathroom motion sensors together, but it should be similar to what you are trying to achieve and you don't have to fool with conditions.

Yes.. Logs show motion inactive on the desired motion sensor. 6 minutes after that time stamp the light remains on.
I've waited an additional 2 minutes and watched the logs with nothing further happening.

Just out of curiosity, if you set up the rule to work off the motion event and then just set a delay after X and then cancel if motion detected again, does it go off after X?

Let's break it down into the simple steps and see where the problem might be. Of course, the simplest testing option is to create a virtual motion sensor and confirm both states work as intended. Even though the logs show the motion sensor going active / inactive, its always good to eliminate the physical device when testing logic.

Motion lighting app would be another good test to see if similar logic fails in all 3 apps.

Also, it appears to me there is a flaw in your RM triggered rule. The way it is written, the conditions are evaluated- light turns on and the rule is completed.

I just set up an identical Simple Lighting rule and it turned the light off after 6 minutes. What kind of device is Back Bathroom Light? Are you sure that motion didn't start again during the 6 minute interval, which would reset the timer?

Also, for further insight into this, you need to capture the before 6 minutes and after 6 minutes snapshot of the app details page. At the bottom it shows scheduled jobs.

With respect to your triggered rule, that's not going to work right in any event as the rule will not be re-evaluated for the Pending Off.

How about a regular rule:
Condition: motion inactive
Rule: motion inactive
Action for true: turn off after 6 minutes pending

Again, are you sure that motion didn't go active again in the interim? And again, would want to look at the app details page for the scheduled jobs.

I did try motion lighting as well after the first two tests and it too turned the light on, but didn't turn it off 6 minutes (or later) after the motion sensor's device log showed motion was inactive. I'm going to start over for this light in Simple Lighting and look at the App info page for the automation as suggested below by Bruce and see what it shows.

Thanks. I threw that together as a quick test. Simple Lighting and Motion Lighting both also neither turned the light off after motion stopped.

Yes. The motion sensor is properly reporting Active/Inactive in the device logs page. If I watch the sensor states on the device page it rapidly changes to Active when I walk in the room and changes to Inactive probably 20 seconds after I exit. I'll check the app details scheduled jobs info (Thanks, I didn't think of that). It's a ST Zigbee motion sensor (Hubitat shows it's "motionv4").

1 Like

I recreated the Simple Lighting rule.
When motion activated, the desired light came on.
When motion went inactive, the App Info page for the automation showed a schedule "doAntiAction" at 10:30:57. That time has passed and that time is still scheduled with Status "PENDING".

Here are the logs:
Motion Sensor:

2018-07-20 10:24:57.036:debugparse: listResult [[name:motion, value:inactive, descriptionText:Back Bathroom Motion Zigbee is inactive]]
2018-07-20 10:24:57.035:debugparseIasMessage: resultListMap [[name:motion, value:inactive, descriptionText:Back Bathroom Motion Zigbee is inactive]]
2018-07-20 10:24:57.033:infoBack Bathroom Motion Zigbee is inactive
2018-07-20 10:24:57.032:debugparse: zone status 0x0020 -- extended status 0x00
2018-07-20 10:24:43.850:debugparse: listResult [[name:motion, value:active, descriptionText:Back Bathroom Motion Zigbee is active]]
2018-07-20 10:24:43.848:debugparseIasMessage: resultListMap [[name:motion, value:active, descriptionText:Back Bathroom Motion Zigbee is active]]
2018-07-20 10:24:43.846:infoBack Bathroom Motion Zigbee is active
2018-07-20 10:24:43.835:debugparse: zone status 0x0021 -- extended status 0x00

Light Switch

dev:8152018-07-20 10:24:43.910:infoBack Bathroom Light was turned on [digital]

Smart Lighting Schedule Job:

|Handler|Next Run Time|Prev Run Time|Status|Schedule|
|doAntiAction|Fri Jul 20 10:30:57 CDT 2018||PENDING|Once|

As I finish typing this at 10:37, the app info page is now missing the Next Run Time on the scheduled job. No further motion or light actions occurred. The light did not turn off.

|Handler|Next Run Time|Prev Run Time|Status|Schedule|
|doAntiAction|||PENDING|Once|

Try this in Simple Lighting:


If you start with turning the light ON with motion then select "Turn off when motion stops" and enter your delay it should work. I tested here with no issues.

1 Like

That is exactly the same rule/method I am using that's not working (at least not on my hub) (the log results are at post #11):

Ok, I'm sorry. I went back to your original post and saw the rule began with "Turn light off"

Ahh. That was accidental and I tried to swap out that graphic last night. I thought it was corrected. That can mislead the whole thread! Sorry..


I've just edited that first graphic (Smart Lighting) screenshot to correctly reflect the issue.

There is a minor difference in your Smart Lighting rule and mine. I'm renaming the rule. I've gone back and turned that off just to see if it made a difference.

It did not make a difference. When motion went inactive, the app info page showed the scheduled job again. I monitored that and it remained scheduled even after it's pending execution time (verified the hub surpassed that time by watching timestamps on other logs). It stayed there until 2 minutes after that time and then the Next Run Time changed to blank again as I mentioned in post 11.

I am at a loss here. I rebuilt the Simple Lighting rule, and renamed it, and it functioned as intended and the pending job cleared at the execution time. Is there any possibility there is another rule somewhere that may be conflicting? Maybe something will show up on the switch details page?

I rebuilt using a virtual motion sensor as well as @patrick mentioned. Same result.

I have other simple lighting rules that are working but they have existed for a while. I have no clue why this isn't working any way I build it.

I built a new Simple Lighting rule for a different room. Different light switch and motion sensor and using a 2 minute off timer. Same result.

When the motion changes to inactive the App Info page for the Simple Lighting rule shows the Scheduled Job for handler "doAntiAction".. That time passes and the schedule remains in pending for 2 minutes (not related to the 2 minute off timer as this 2 minutes is seen when the off timer is set to 6 minutes as well). After 2 minutes "Next Run Time" changes to blank and the "doAntiAction" scheduled job/handler remains listed in PENDING state.

The Simple Lighting Automation:

Logs taken at 16:10pm (2 min after the scheduled 16:08:03 off time should have occurred)
Motion sensor log:

Light switch log:
image

App Info for the Simple Lighting Automation (before 16:08:00):

App Info for the Simple Lighting Automation (after 16:10:00)

Hubitat crew found the issue.

I had something doing hubAction() calls that was causing a socket timeout issue and ended up killing the scheduler. They are going to patch to prevent that in the future.

I could immediately think of 2 Apps/Drivers that might be doing that. VLCThing and Cast-Web-API (Google Home announcements). VLCThing I knew had issues as I used it for testing and often forgot to start VLC on the host system after reboots, etc. I also realized my Google Home's were no longer announcing messages sent from Hubitat so I suspected it as well.

I removed VLCThing, Cast-Web-Api and the devices that it creates and rebooted my hub. The new Smart Lighting automation's that were not working earlier are now working as expected.

Thanks to everyone that helped get to the core of the issue!

6 Likes

@patrick, hot fix for this issue? I think I have similar issue.

Hot fix 1.1.1.119 is now available

  • Added timeout for HTTP calls to prevent app from hanging.