Rule evaluation

This is a variation on some issues that I've already seen posted, but most of the related topics devolved into other discussions and so haven't answered my own question yet.

I have a pretty simple Rule Machine rule: if the office "is occupied" (a virtual switch set by a motion sensor) AND the office temperature is < 72º (checked by the same sensor), then turn on the spaceheater.

I frequently -- at least once a day -- walk into my office after a prolonged absence, and the temperature is typically about 68º if I haven't been in there, so the rule's temperature condition is almost always satisfied. I can see the motion sensor flicker to acknowledge my presence.

I have a log showing

[dev:97] (http://x.x.x.x/logs#dev97) 2018-12-09 12:24:53.310 pm [info] (http://x.x.x.x/device/edit/97)Office Occupied was turned on
[dev:107] (http://x.x.x.x/logs#dev107) 2018-12-09 12:24:53.284 pm [info] (http://x.x.x.x/device/edit/107)Office Sensor: motion is active
[dev:107] (http://1x.x.x.x/logs#dev107) 2018-12-09 12:24:53.197 pm [info] (http://x.x.x.x/device/edit/107)Office Sensor: motion is active

But the spaceheater doesn't turn on, and in the App List, "(Restricted)" still appears next to my "Extra Warmth" app.

If I click to edit the app, the title changes from "(Restricted)" to "[True]". But still no spaceheater.

When I click "Done" at the bottom of the app configuration page, I hear the "tick" of my spaceheater turning on.

So my question is this: Why isn't the rule being executed on the "Office Occupied" state change? Should it not be re-evaluating the rule when the motion sensor senses me and sets "Office Occupied" to true? Why do I have to re-edit the rule in order to force reevaluation?

Screenshots of the rule below, and a log from a few days ago that shows a time when, despite both conditions showing up as "true," the RM rule didn't actually kick in for a minute and 30 seconds!

Happy to provide any additional information as needed!

If you haven't already, I would try deleting it and recreating it. Then see if it works, or still exhibits the same behavior.

In the past 4 days I have had 3 different RM things that didn't work when I thought they should, that worked perfectly the second time I created them - even though I created it EXACTLY the same as the first time (I took screenshots before/after and compared - they were identical). No idea why.

Just food for thought.

A regular rule should be true or false in the list and only show restricted if you have something in restrictions that is affecting it. Expand Restrictions in the rule and make sure nothing is there.

image

image

How are you turning the virtual switch on or off? Are you sure that the device Spaceheater can be turned on and off from HE? If the rule never switches to false, the true action will never happen again because the actions only take place when the rule swaps from true to false. You have rule logging enabled...can you show more of the events from the events page? Are you seeing the rule go false?

If you've removed and re-added devices, that problem won't show up in RM until you actually go into the rule and go DEEP into where you choose the devices. I had the same thing happen and as it turns out, the device was actually gone from the app but it didn't show that until I drilled all the way down into the checklist for the devices. So, if you're removing/re-adding devices take a screenshot of the rules you'll have to go back into whether or not they "look" right.

Ryan --

If you read carefully, you'll see that forcing RM to reevaluate the rules is successfully triggering the spaceheater.

The "Office Occupied" switch is set by a Motion Lighting routine, and that works.

And, in many circumstances, the rule works as expected. But here's a more elaborate example from my logs. You can see that, at 12:22, I triggered "Office Occupied" AND the "Extra Warmth" app even acknowledged that the temperature was within conditions, but still didn't trigger the spaceheater.

It wasn't until 3 minutes later that it decides that "Extra Warmth is now True" and that was after I re-edit the rule and clicked "Done."

app:662018-12-09 12:25:22.735 pm infoExtra warmth is now True
app:662018-12-09 12:25:22.668 pm info --> Office Occupied on [true]
app:662018-12-09 12:25:22.652 pm info --> Temperature of Office Sensor < 72.0 [true]
dev:1072018-12-09 12:25:12.688 pm infoOffice Sensor: motion is inactive
dev:1072018-12-09 12:25:12.647 pm infoOffice Sensor: motion is inactive
app:662018-12-09 12:25:11.453 pm info --> Office Occupied on [true]
app:662018-12-09 12:25:11.441 pm info --> Temperature of Office Sensor < 72.0 [true]
dev:1072018-12-09 12:25:01.040 pm infoOffice Sensor: motion is active
dev:1072018-12-09 12:25:01.040 pm infoOffice Sensor: motion is active
app:92018-12-09 12:25:00.062 pm debugInitializing
dev:972018-12-09 12:24:53.310 pm infoOffice Occupied was turned on
dev:1072018-12-09 12:24:53.168 pm infoOffice Sensor: motion is active
dev:1072018-12-09 12:24:53.143 pm infoOffice Sensor: motion is active
dev:1072018-12-09 12:24:24.781 pm infoOffice Sensor: motion is inactive
dev:1072018-12-09 12:24:24.756 pm infoOffice Sensor: motion is inactive
dev:342018-12-09 12:24:20.783 pm infoLaundry Motion Sensor is inactive
dev:1072018-12-09 12:24:13.013 pm infoOffice Sensor: motion is active
dev:1072018-12-09 12:24:13.001 pm infoOffice Sensor: motion is active
dev:972018-12-09 12:24:05.408 pm infoOffice Occupied was turned on
dev:1072018-12-09 12:24:05.279 pm infoOffice Sensor: motion is active
dev:1072018-12-09 12:24:05.256 pm infoOffice Sensor: motion is active
app:92018-12-09 12:24:00.041 pm debugInitializing
dev:662018-12-09 12:23:43.758 pm infoBedroom Light energyDuration is 57.76 Days
dev:12018-12-09 12:23:24.464 pm infoThird floor sensor: motion is active
dev:12018-12-09 12:23:24.437 pm infoThird floor sensor: motion is active
app:92018-12-09 12:23:00.040 pm debugInitializing
dev:1072018-12-09 12:22:36.968 pm infoOffice Sensor: motion is inactive
dev:1072018-12-09 12:22:36.898 pm infoOffice Sensor: motion is inactive
dev:422018-12-09 12:22:36.873 pm infoOffice Camera voltage is 124.342 V
dev:3532018-12-09 12:22:27.153 pm infoST motion sensor is inactive
dev:972018-12-09 12:22:25.424 pm infoOffice Occupied was turned on
dev:1072018-12-09 12:22:25.175 pm infoOffice Sensor: motion is active
dev:1072018-12-09 12:22:25.145 pm infoOffice Sensor: motion is active
dev:1072018-12-09 12:22:16.658 pm infoOffice Sensor: motion is inactive
dev:1072018-12-09 12:22:16.631 pm infoOffice Sensor: motion is inactive
dev:182018-12-09 12:22:04.026 pm infoOffice 4 was turned on
dev:172018-12-09 12:22:04.001 pm infoOffice 3 was turned on
dev:162018-12-09 12:22:03.973 pm infoOffice 2 was turned on
app:662018-12-09 12:22:03.939 pm info --> Office Occupied on [true]
dev:152018-12-09 12:22:03.930 pm infoOffice 1 was turned on
app:662018-12-09 12:22:03.894 pm info --> Temperature of Office Sensor < 72.0 [true]
dev:242018-12-09 12:22:03.868 pm infoGroup Office was turned on
app:662018-12-09 12:22:03.194 pm infoExtra warmth: Office Occupied switch on
dev:972018-12-09 12:22:03.060 pm infoOffice Occupied was turned on
dev:1072018-12-09 12:22:02.952 pm infoOffice Sensor: motion is active
dev:1072018-12-09 12:22:02.929 pm infoOffice Sensor: motion is active

Yes, because forcing to re-evaluate is the same as forcing the rule to execute again. I don't ever see Office Occupied Turning off. I also don't see the rule ever going False. So, why do you expect the actions for True to happen again without a force re-evaluation or the rule changing from False to True? Is the rule ever truing the spaceheater off? because it looks to me like the rule has always been true.

You are asking the question....rather than argue with people helping you why don't you try and read what they are saying and digest it rather than assume they are wrong? If you don't give complete information, then how is anyone supposed to help you?

I certainly wasn't trying to argue, just making the point that I had already made it clear that the spaceheater could be turned on and off from HE. I apologize for sounding argumentative.

But I think you're on to something with the Office Occupied never going false. At least that may be related, but I'm not sure exactly how, and this makes it more confusing. I don't see any log entries indicating that Office Occupied is ever switched off, but tons indicating that it's turning on.

There are absolutely times when "Extra Warmth" is false, and I always assumed that it was because the room had been unoccupied for awhile, but now I suspect that it's because eventually it warms up to 72º and that's the only thing that triggers it to turn off.

It is also partly confusing that HE logs "Office Occupied was turned on" in the logs, although it was (I now believe) already turned on, and therefore RM was not triggered. I assumed that, because the event was logged, it was a state change and would therefore triggered a rule evaluation. Maybe it would be nice if the log entry said "Office Occupied was turned on (no state change)" or something in such cases.

So now the question is: why isn't Office Occupied ever turning off?

Here's a detail screenshot from my "Office is occupied" Motion Lighting app. The full rule is basically supposed to be:

  1. When motion is sensed:
  2. Turn on the lights
  3. Turn off the lights after a mode-based delay
  4. Turn on the "Office Occupied" switch
  5. Turn off the "Office Occupied" switch after a mode-based delay

Are 4 and 5 properly represented by the screenshot?

OK, so here's a more comprehensive analysis:

First, "Office Occupied" does eventually get set to false, and so does "Extra Warmth." Sometimes.

Here are today's entries in the log for the Office Occupied device:

switch on Office Occupied was turned on DEVICE 2018-12-10 05:49:58.905 PM EST
switch off Office Occupied was turned off DEVICE 2018-12-10 11:26:01.131 AM EST
switch on Office Occupied was turned on DEVICE 2018-12-10 08:58:11.938 AM EST
switch on Office Occupied was turned on DEVICE 2018-12-10 08:58:11.935 AM EST
switch off Office Occupied was turned off DEVICE 2018-12-10 07:20:01.243 AM EST
switch on Office Occupied was turned on DEVICE 2018-12-10 06:24:50.074 AM EST

When I arrived home and entered my office at 5:49pm, the lights turned on, the Office Occupied switch turned on, but the spaceheater didn't turn on. Again. This is exactly the scenario that prompted this topic.

After further debugging, though, it now appears that "Extra Warmth" was not false when I came home, and therefore didn't think it neeeded to turn on the spaceheater. (Because it didn't think it had changed state, right?)

But...you can see from the Office Occupied device log at the top of this post that Office Occupied went ON at 6:24am and OFF at 7:20am, and both events also appear in the RM log for the Extra Warmth app.

But Office Occupied came back at 8:58am, and then OFF again at 11:26am. That "off" event was not logged by the Extra Warmth app, and so HE never re-evaluated the rules, leaving Extra Warmth to believe that it was still truth-satisfied. At least that's my best guess. Am I wrong to assume that the 11:26 "off" event should have been recorded by the Extra Warmth rule?

RM Office Sensor temperature 66.22 2018-12-10 05:50:18.957 PM EST
RM Office Occupied switch on 2018-12-10 05:49:59.010 PM EST
RM Office Sensor temperature 71.80 2018-12-10 09:57:52.869 AM EST
RM Office Sensor temperature 67.28 2018-12-10 09:04:31.888 AM EST
RM Extra warmth is now True 2018-12-10 08:58:13.913 AM EST
RM Extra warmth is now True 2018-12-10 08:58:13.901 AM EST
RM Office Occupied switch on 2018-12-10 08:58:12.032 AM EST
RM Office Occupied switch on 2018-12-10 08:58:12.028 AM EST
RM Office Sensor temperature 68.59 2018-12-10 08:17:56.955 AM EST
RM Office Sensor temperature 71.64 2018-12-10 07:45:24.905 AM EST
RM Office Sensor temperature 72.40 2018-12-10 07:31:51.061 AM EST
RM Extra warmth is now False 2018-12-10 07:20:02.404 AM EST
RM Extra warmth is False, but delayed by 15 minutes 2018-12-10 07:20:02.394 AM EST
RM Office Occupied switch off 2018-12-10 07:20:02.101 AM EST
RM Extra warmth is now True 2018-12-10 06:24:51.132 AM EST