'stays open' evaluating true when it's not true

[jmcclellan]

1) Give a description of the problem
‘stays open’ condition evaluating true, when not true

2) What is the expected behaviour?
door contact ‘stays open’ alert only evaluates true when door actually stays open

3) What is happening/not happening?
webcore received event for door open. then received event for door closed. door is closed and shows closed in Smartthings. but after timer expires, webcore still evaluates ‘stays open for x minutes’ as true and sends an alert as if the door stayed open. but it didn’t.

**4) Post a Green Snapshot of the piston![image|45x37] 3/3/2021, 10:55:32 AM +103ms

5) Attach logs after turning logging level to Full
3/3/2021, 10:55:32 AM +103ms
+0ms ╔Received event [Home].time = 1614786933534 with a delay of -1432ms
+97ms ║RunTime Analysis CS > 37ms > PS > 7ms > PE > 54ms > CE
+100ms ║Runtime (40429 bytes) successfully initialized in 7ms (v0.3.110.20191009) (99ms)
+101ms ║╔Execution stage started
+106ms ║║Cancelling condition #6’s schedules…
+107ms ║║Condition #6 evaluated true (1ms)
+108ms ║║Cancelling condition #1’s schedules…
+109ms ║║Condition group #1 evaluated true (state changed) (4ms)
+111ms ║║Cancelling statement #3’s schedules…
+118ms ║║Executed virtual command setVariable (4ms)
+123ms ║║Calculating (string) Front door + (string) left open! >> (string) Front door left open!
+140ms ║║Executed virtual command sendPushNotification (15ms)
+158ms ║║Condition #8 evaluated false (14ms)
+159ms ║║Condition group #7 evaluated false (state did not change) (15ms)
+164ms ║╚Execution stage complete. (64ms)
+165ms ╚Event processed successfully (165ms)
3/3/2021, 10:53:33 AM +395ms
+2ms ╔Received event [Front door].contact = closed with a delay of 82ms
+10097ms ║RunTime Analysis CS > 19ms > PS > 10018ms > PE > 60ms > CE
+10098ms ║Piston waited at a semaphore for 10014ms
+10101ms ║Runtime (40509 bytes) successfully initialized in 10018ms (v0.3.110.20191009) (10099ms)
+10102ms ║╔Execution stage started
+10120ms ║║Comparison (enum) closed stays (string) open = false (2ms)
+10123ms ║║Comparison (enum) closed stays (string) open = false (2ms)
+10125ms ║║Cancelling any timed trigger schedules for device :e15f714fefa025df117dd7f6a367fc2e: for condition 2
+10126ms ║║Cancelling statement #2’s schedules…
+10127ms ║║Cancelling any timed trigger schedules for device :ab013e547a5357e7ba38e0bd47d21d64: for condition 2
+10128ms ║║Cancelling statement #2’s schedules…
+10129ms ║║Condition #2 evaluated false (22ms)
+10156ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+10159ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+10161ms ║║Comparison (enum) closed stays (string) open = false (2ms)
+10163ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+10165ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+10167ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+10170ms ║║Cancelling any timed trigger schedules for device :9f125e85d7668f07630cda8669e2b54f: for condition 6
+10171ms ║║Cancelling statement #6’s schedules…
+10172ms ║║Cancelling any timed trigger schedules for device :545c96cd4154f43a033054a0560b355c: for condition 6
+10173ms ║║Cancelling statement #6’s schedules…
+10174ms ║║Cancelling any timed trigger schedules for device :89228cac944a8052eca54ec498767ce2: for condition 6
+10174ms ║║Cancelling statement #6’s schedules…
+10175ms ║║Cancelling any timed trigger schedules for device :8fb094e769ca309b8d39cf4bbe526d81: for condition 6
+10176ms ║║Cancelling statement #6’s schedules…
+10177ms ║║Cancelling any timed trigger schedules for device :28dff03eed807785c7129675dfda7dff: for condition 6
+10178ms ║║Cancelling statement #6’s schedules…
+10179ms ║║Cancelling any timed trigger schedules for device :f5e3232120c2ce6a145021e4ca2b4806: for condition 6
+10179ms ║║Cancelling statement #6’s schedules…
+10180ms ║║Condition #6 evaluated false (51ms)
+10181ms ║║Condition group #1 evaluated false (state did not change) (75ms)
+10191ms ║║Condition #8 evaluated false (6ms)
+10192ms ║║Condition group #7 evaluated false (state did not change) (8ms)
+10194ms ║╚Execution stage complete. (93ms)
+10195ms ╚Event processed successfully (10195ms)
3/3/2021, 10:53:33 AM +381ms
+1ms ╔Received event [Front door].contact = open with a delay of 91ms
+77ms ║RunTime Analysis CS > 20ms > PS > 5ms > PE > 51ms > CE
+79ms ║Runtime (40426 bytes) successfully initialized in 5ms (v0.3.110.20191009) (77ms)
+80ms ║╔Execution stage started
+97ms ║║Comparison (enum) closed stays (string) open = false (2ms)
+99ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+102ms ║║Cancelling any timed trigger schedules for device :e15f714fefa025df117dd7f6a367fc2e: for condition 2
+102ms ║║Cancelling statement #2’s schedules…
+103ms ║║Cancelling any timed trigger schedules for device :ab013e547a5357e7ba38e0bd47d21d64: for condition 2
+104ms ║║Cancelling statement #2’s schedules…
+105ms ║║Condition #2 evaluated false (20ms)
+132ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+135ms ║║Comparison (enum) closed stays (string) open = false (2ms)
+137ms ║║Comparison (enum) open stays (string) open = true (1ms)
+139ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+142ms ║║Comparison (enum) closed stays (string) open = false (1ms)
+144ms ║║Comparison (enum) closed stays (string) open = false (2ms)
+147ms ║║Cancelling any timed trigger schedules for device :9f125e85d7668f07630cda8669e2b54f: for condition 6
+148ms ║║Cancelling statement #6’s schedules…
+148ms ║║Cancelling any timed trigger schedules for device :545c96cd4154f43a033054a0560b355c: for condition 6
+149ms ║║Cancelling statement #6’s schedules…
+152ms ║║Adding a timed trigger schedule for device :89228cac944a8052eca54ec498767ce2: for condition 6
+155ms ║║Cancelling any timed trigger schedules for device :8fb094e769ca309b8d39cf4bbe526d81: for condition 6
+155ms ║║Cancelling statement #6’s schedules…
+156ms ║║Cancelling any timed trigger schedules for device :28dff03eed807785c7129675dfda7dff: for condition 6
+157ms ║║Cancelling statement #6’s schedules…
+158ms ║║Cancelling any timed trigger schedules for device :f5e3232120c2ce6a145021e4ca2b4806: for condition 6
+159ms ║║Cancelling statement #6’s schedules…
+160ms ║║Condition #6 evaluated false (53ms)
+161ms ║║Condition group #1 evaluated false (state did not change) (76ms)
+170ms ║║Condition #8 evaluated false (7ms)
+171ms ║║Condition group #7 evaluated false (state did not change) (8ms)
+174ms ║╚Execution stage complete. (93ms)
+175ms ║Setting up scheduled job for Wed, Mar 3 2021 @ 10:55:33 AM EST (in 119.979s)
+184ms ╚Event processed successfully (184ms)

[E_Sch]

If you scroll down half way thru this, there is a discussion on stays open

How to make a piston fire only if switch is not already on

So I have been looking at all this more. I don’t think webCoRE is broken (but there are improvements in labeling I think) ‘did not change’ is a condition. (and it looks backward in time, IT DOES NOT SET A FUTURE TIMER) when the piston runs (because of some other event), it looks backwards in time to see if the variable changed or not within the specified duration (assuming there are enough events (in HE for example, one could set the db that there is very limited history)) there is no co…

[orangebucket]

‘stays open’ condition evaluating true, when not true

Looks like that to me too. The logs show that the timed trigger is scheduled by the open and that it is marked for cancellation by the close, and yet when the timer fires (which is correct - the timer doesn’t get cancelled as such, it just gets told to do nothing) it acts like it wasn’t cancelled at all and returns true.

I don’t know exactly where the cancellation should have happened but I think it might be part of the piston exit process.

Does it fail every time? The closed seems to have come so quickly that a semaphore wait happened, but that should be harmless. Similarly the timer fired one and a half seconds early but that should also be routine.

[jmcclellan]

it happens a lot - often enough that I have since disabled the piston due to annoying the family with erroneous alerts - but not all the time. can’t say for certain but it seems to happen more often when a door was opened/closed relatively quickly. This piston worked exactly as-is for months, then randomly started doing this

[E_Sch]

Not using two ‘stays’ in an if with or, both sides of the if may not execute on every run…(and cause problems with stays)

I would only use one stays per if, and I would keep the if’s at the first level, and I would code to ensure the stays get run over on every event so that the state is kept accurate.