Power Comparison Failed

fixed
#1

1) Give a description of the problem
A comparison of power value is wrong.

2) What is the expected behavior?
85 is not less than 10.

3) What is happening/not happening?
The piston determined that 85 is less than 10, which caused a light to shut-off when it should have been on.

**4) Post a Green Snapshot of the piston![image|45x37]

Failed%20Power%20Comparison
Failed Power Comparison.png1178×547 56.9 KB

5) Attach any logs (From ST IDE and by turning logging level to Full)
2/21/2018, 9:29:29 PM +416ms
+0ms ╔Received event [Home].time = 1519273769855 with a delay of -440ms
+246ms ║RunTime Analysis CS > 27ms > PS > 116ms > PE > 103ms > CE
+248ms ║Runtime (38144 bytes) successfully initialized in 116ms (v0.2.102.20180116) (247ms)
+250ms ║╔Execution stage started
+311ms ║║Comparison (time) 77369679 is_between (time) 75600000 … (time) 1519220640000 = true (9ms)
+312ms ║║Time restriction check passed
+314ms ║║Condition #5 evaluated true (51ms)
+486ms ║║Comparison (decimal) 85.5 was_less_than (integer) 10 = true (161ms)
+487ms ║║Cancelling condition #6’s schedules…
+488ms ║║Condition #6 evaluated true (173ms)
+490ms ║║Cancelling condition #2’s schedules…
+491ms ║║Condition group #2 evaluated true (state changed) (228ms)
+493ms ║║Cancelling statement #3’s schedules…
+573ms ║║Executed physical command [Living Room Bulb].off() (76ms)
+574ms ║║Executed [Living Room Bulb].off (78ms)
+580ms ║║Skipped execution of physical command [Living Room Light].off([]) because it would make no change to the device. (3ms)
+581ms ║║Executed [Living Room Light].off (5ms)
+585ms ║╚Execution stage complete. (336ms)
+587ms ║Setting up scheduled job for Wed, Feb 21 2018 @ 9:31:29 PM MST (in 119.852s)
+599ms ╚Event processed successfully (598ms)

REMOVE BELOW AFTER READING

It seems there were actually 2 failures here:

  1. the comparison failed. Comparison (decimal) 85.5 was_less_than (integer) 10 = true (161ms). This comparison worked previously but now it failed.

  2. the power level was not below 10 for 15 minutes. This was the only time that value was determined to be less, but it was only true for 2 min not 15 min.

Any insight in what happened here?

#2

Might be due to comparing a decimal to an integer.

Try changing value 10 to expression {decimal(10)}

#3

Thanks, I’ll try that.

#4

BTW, I’m doing that same expression in other pistons where it seems to be working well without doing the decimal conversion. Are those comparisons at risk of failing also?

Doesn’t WebCore automatically change to decimal when it does the comparison?

Also, is there a difference in the way Core handles this expression vs WebCore? I just moved that piston to WebCore from Core where I think it was working fine for a long time.

Or, was this a 1-shot anomaly or problem with ST? It seems ST has been having issues lately with not communicating to devices and other problems.

#5

I’m not sure if webCoRE does the conversion automatically… If it doesn’t I imagine this piston would still work sometimes, when the measured value falls on a round number, but not when it has a decimal ending.

Did the decimal() trick work?.. to be honest it was a bit of a long shot so I’m not holding my breath!

#6

I won’t know if decimal works until the piston runs again this evening. I can let you know tomorrow.

#7

That’s a very slow way to test a piston lol… just tweak the time conditions to make it run early :wink:

#8

I think the issue would likely be remedied by asking a different question up front.

Rather than say:

Every 2 minutes
Was the power less than 10 watts for 15 minutes…

Just say…

If power stays below 10 watts for 15 minutes

Lose the Timer all together.

Using stays will create the Timer for you.

If the power dips below 10w then the piston will start a Timer for itself to check again in 15 minutes. If the power goes back above that during the 15 minutes then stays is no longer true, so it will cancel itself. But if it is still true then it will initiate the actions you want in the then part.

I don’t think you can expect for a piston to work properly if it runs every 2 minutes but you want i to keep track of something for 15 minutes. There’s no where in the logs where WC is storing the value of what the power setting was…so I don’t think it will have any knowledge of that.

I think what it really did was answer the question… Was the power less than 10w at any point between now and the last time the piston ran. Sure the power might have went back up, but it was less than 10…so true.

Try stays instead.

#9

Changing to Decimal did not change the failure. Here are the logs. I also included the previous comparison that worked correctly.

2/22/2018, 9:39:12 PM +400ms
+1ms ╔Received event [Home].time = 1519360753416 with a delay of -1016ms
+251ms ║RunTime Analysis CS > 22ms > PS > 118ms > PE > 110ms > CE
+254ms ║Runtime (38853 bytes) successfully initialized in 118ms (v0.2.102.20180116) (251ms)
+255ms ║╔Execution stage started
+324ms ║║Comparison (time) 77952669 is_between (time) 75600000 … (time) 1519306920000 = true (10ms)
+325ms ║║Time restriction check passed
+327ms ║║Condition #5 evaluated true (58ms)
+498ms ║║Comparison (decimal) 85.5 was_less_than (decimal) 10.0 = true (161ms)
+500ms ║║Cancelling condition #6’s schedules…
+501ms ║║Condition #6 evaluated true (172ms)
+510ms ║║Comparison (enum) on is (string) on = true (2ms)
+512ms ║║Cancelling condition #7’s schedules…
+513ms ║║Condition #7 evaluated true (12ms)
+514ms ║║Cancelling condition #2’s schedules…
+515ms ║║Condition group #2 evaluated true (state changed) (246ms)
+518ms ║║Cancelling statement #3’s schedules…
+603ms ║║Executed physical command [Living Room Bulb].off() (82ms)
+603ms ║║Executed [Living Room Bulb].off (83ms)
+609ms ║║Skipped execution of physical command [Living Room Light].off([]) because it would make no change to the device. (3ms)
+610ms ║║Executed [Living Room Light].off (5ms)
+614ms ║╚Execution stage complete. (360ms)
+615ms ║Setting up scheduled job for Thu, Feb 22 2018 @ 9:41:13 PM MST (in 120.401s)
+625ms ╚Event processed successfully (625ms)
2/22/2018, 9:37:12 PM +383ms
+1ms ╔Received event [Home].time = 1519360633416 with a delay of -1033ms
+225ms ║RunTime Analysis CS > 24ms > PS > 85ms > PE > 116ms > CE
+228ms ║Runtime (38851 bytes) successfully initialized in 85ms (v0.2.102.20180116) (226ms)
+229ms ║╔Execution stage started
+298ms ║║Comparison (time) 77832628 is_between (time) 75600000 … (time) 1519306920000 = true (10ms)
+300ms ║║Time restriction check passed
+302ms ║║Condition #5 evaluated true (57ms)
+494ms ║║Comparison (decimal) 84.3 was_less_than (decimal) 10.0 = false (182ms)
+496ms ║║Condition #6 evaluated false (193ms)
+497ms ║║Condition group #2 evaluated false (state did not change) (252ms)
+501ms ║╚Execution stage complete. (272ms)
+503ms ║Setting up scheduled job for Thu, Feb 22 2018 @ 9:39:13 PM MST (in 120.531s)
+512ms ╚Event processed successfully (512ms)

What’s strange is that the failure occurred at roughly the same time as yesterday. I do not know if that is significant but it is an odd coincidence.

Mike - Thanks for the comment, but consider the case where the TV is not on at all. Come 9pm, there is nothing that would trigger shutting off the lights, so I’m not sure that will do all that I want. Still, I have not tried Stays, so I will try it to see what happens. On your other point of 2 min being too fast for the system to handle, I could try changing the polling time from 2 min to 4 min. There is nothing magic about 2. But like I said, I have other pistons with a 2 min polling time that seem to be working just fine. Here’s a thought. Is it possible that will all the pistons running on 2 min intervals that I’m getting the equivalent of stack overflow that causes the system to get confused where normally it would be OK? I’ll look at all those pistons and lengthen the time if they do not need to be so fast.

BTW, this piston, or at least a version of it, ran for 6 months in Core with no problems using the same 2 min technique. It is only when I moved it to WebCore that I had these problems. Is there something inherent in Core that makes it better suited for this type of polling piston, or WebCore worse?

Also BTW, I have another piston in WebCore that runs every 10 min, except occasionally, maybe once every day or 2, it fails. In that case I’m turning on a switch, waiting for 2.5 min, then turning it off. But when it fails, it fails to turn off. I catch that problem by using a 2nd piston to determine if the switch is on for too long. I’m still chasing a solution to that problem.

Robin - You are right, I will change the conditions to have it run sooner. But I wanted to test it in the most similar circumstances possible.

Thanks to both of you for your comments. I’ll make a few changes and see what happens. Will let you know.

#10

I never used Core so I can’t claim to know how it works or the difference between the two systems.

However, you presented us with a problem saying that 85 is not less than 10. I agree, it isn’t…however WC does not agree. So why does it not agree? Which is why I go back to the construct of the piston that you’ve put together.

From my experience, I don’t know how what you’ve wrote there would be implemented by WC. I mean, digging deep into the weeds on this one. I’m not sure how WC would accomplish what you’re after. Maybe Core did something differently but what you’re asking for here is for WC to monitor the power on a plug, but you’re putting that inside of a Timer which is of course going to cause the entire piston to rerun again in 2 minutes…and I don’t know how the new instance that is going to run in 2 minutes will know about what happened in the old instance that ran 2 minutes ago. That’s what I’m getting at… Where is WC storing the information on the level of power being used between reruns of the piston??? I would have no idea. As far as I know it does not work that way and it does not store it anywhere.

Now, conceptually, I could envision a piston that used a Repeat Loop that never reran the entire thing working to do something like this…and if that’s how Core implemented this type of construct then that would explain the difference. But WC is going to make the Timer part the the main trigger for this piston. It’s not going to build a Repeat Loop. It’s just going to run the entire piston again every 2 minutes.

Now…moving forward…we don’t know what problem you’re trying to solve. All we know is that you’ve presented a problem. So there’s not a great way to suggest alternatives that are better suited for WC.

But if you did present the goal…then perhaps we can tell you from our experience with WC how we would do what you’re trying to accomplish.

#11

I too have no idea how WC knows that something was less than a value for more the 15 min, but I am using that same idea in several pistons and they all seem to be working except for this one and then only once in a while. This construct does not seem crazy to me since it is an option that WC is allowing us to use in its drop-down menus. That is the At Least option in the Was comparison. In other pistons I’m also using its cousin the Less Than option in the Was comparison. That too seems to work properly as far as I know.

From my view, WC is a superset of Core. I’m using WC because it is easier to construct complicated pistons than using Core. And it puts them all in one place for me to monitor. But if I cannot get this working consistently in WC I will try going back to Core.

Yesterday I make the timing changes, currently changed from 2 min to 3 min. I’ll see if that makes a difference. I also rearranged the sequence of the conditions to lower the execution time when things are static.

#12

@webCoRE_Minions

85.5 is less than 10 = True

Any thoughts?

#13

I tried it in the console yesterday and it was evaluating as expected.

#14

The condition was “85.5 was less than 10” which tests the historic values of the attribute, not the current value.

It excludes the current value only when evaluated in response to an event for the same attribute, so since the power change triggered the piston run the was operator ignores the current event. If this were triggered by a specific time of day instead and the current value was 85.5 the evaluation would have been false.

#15

Looking at the logs, his piston was triggered by time not power

#16

Good observation, I must be misreading the code wrt when the last event is ignored.

#17

What does that mean exactly? They are not failing, or that they are in fact testing for the 15 minute part?

That’s not exactly proof on anything unfortunately.

You still haven’t said what you’re trying to do. There may be many ways to test for and get the right answer…but unless you let us know what the goal is we have no way of providing that information.

#18

@TonyK1321 The logs in your second reply make it very clear that something is wrong either with the comparison or with the tracking of previous power states for that device. I’m running a similar piston on my end to see if I can get the same behavior but since the was less than logic seems pretty solid I’m leaning toward a fault with recording previous states.

Is it possible that the power dropped below 10 at any time between 9:37:12 PM and 9:39:12 PM, maybe you have logs to check on the device? I want to determine whether I’m looking for incorrect power levels getting recorded or incorrect durations for valid power levels.

EDIT: I just got the same erroneous result on my end. Unfortunately the SmartThings IDE is broken (server errors upon editing code) so I can’t do any debugging right now.

#19

Here are events for that switch between 9:37p and 9:39p last night. It shows that the power was pretty consistent about 85W within that time period. I also looked at the 1/2 hr before 9:37, and it was solid around 85W. Let me know if I can provide any other info that might help you.

2018-02-22 9:38:41.924 PM MST
13 hours ago DEVICE power 85.3 Living Room TV Switch power is 85.3
2018-02-22 9:38:39.929 PM MST
13 hours ago DEVICE power 84.8 Living Room TV Switch power is 84.8
2018-02-22 9:38:38.927 PM MST
13 hours ago DEVICE power 85.4 Living Room TV Switch power is 85.4
2018-02-22 9:38:20.928 PM MST
13 hours ago DEVICE power 84.8 Living Room TV Switch power is 84.8
2018-02-22 9:38:16.963 PM MST
13 hours ago DEVICE power 85.7 Living Room TV Switch power is 85.7
2018-02-22 9:37:51.964 PM MST
13 hours ago DEVICE power 85.2 Living Room TV Switch power is 85.2
2018-02-22 9:37:48.963 PM MST
13 hours ago DEVICE power 85.7 Living Room TV Switch power is 85.7
2018-02-22 9:37:42.924 PM MST
13 hours ago DEVICE power 84.8 Living Room TV Switch power is 84.8
2018-02-22 9:37:38.918 PM MST
13 hours ago DEVICE power 84.2 Living Room TV Switch power is 84.2
2018-02-22 9:37:33.927 PM MST
13 hours ago DEVICE power 84.7 Living Room TV Switch power is 84.7
2018-02-22 9:37:31.919 PM MST
13 hours ago DEVICE power 84.1 Living Room TV Switch power is 84.1
2018-02-22 9:37:19.927 PM MST
13 hours ago DEVICE power 84.8 Living Room TV Switch power is 84.8
2018-02-22 9:37:12.926 PM MST
13 hours ago DEVICE power 85.3 Living Room TV Switch power is 85.3
2018-02-22 9:37:11.926 PM MST
13 hours ago DEVICE power 84.3 Living Room TV Switch power is 84.3
2018-02-22 9:37:08.944 PM MST
13 hours ago DEVICE power 84.8 Living Room TV Switch power is 84.8
2018-02-22 9:37:07.997 PM MST
13 hours ago DEVICE power 84.0 Living Room TV Switch power is 84.0
2018-02-22 9:37:06.973 PM MST
13 hours ago DEVICE power 82.7 Living Room TV Switch power is 82.7
2018-02-22 9:37:05.962 PM MST
13 hours ago DEVICE power 84.1 Living Room TV Switch power is 84.1
2018-02-22 9:34:30.182 PM MST
13 hours ago DEVICE power 85.3 Living Room TV Switch power is 85.3

#20

Thanks, I’m hoping it happens again for me. I was able to get some logging into my smart apps that will identify what’s going on.