Text me if light left on for 15 minutes - not working

[rwhillrunner]

1) Give a description of the problem
New to WebCoRE but not new to coding. Thought I’d start with an easy piston but it has me baffled. Trying to set something up that will text my wife and me if she forgets to turn off her closet light. It’s texting us even after the switch is off. I can’t figure this out and it seems so simple.

2) What is the expected behaviour?
If the light stays on for 15 minutes, text us.

3) What is happening/not happening?
It’s texting us 15 minutes after the light turned on, even if it has been turned off.

4) Post a Green Snapshot of the piston

5) Attach logs after turning logging level to Full
4/9/2020, 5:22:22 AM +87ms
+12ms ╔Received event [Home].time = 1586427743945 with a delay of -1858ms
+155ms ║RunTime Analysis CS > 49ms > PS > 86ms > PE > 18ms > CE
+162ms ║Runtime (38209 bytes) successfully initialized in 86ms (v0.3.110.20191009) (137ms)
+163ms ║╔Execution stage started
+169ms ║║Cancelling condition #2’s schedules…
+170ms ║║Condition #2 evaluated true (1ms)
+171ms ║║Cancelling condition #1’s schedules…
+172ms ║║Condition group #1 evaluated true (state changed) (3ms)
+174ms ║║Cancelling statement #4’s schedules…
+523ms ║║Executed virtual command sendSMSNotification (345ms)
+533ms ║║Executed virtual command sendSMSNotification (4ms)
+547ms ║╚Execution stage complete. (383ms)
+549ms ╚Event processed successfully (548ms)
4/9/2020, 5:07:13 AM +697ms
+1ms ╔Received event [Lisa’s Closet Light].switch = on with a delay of 46ms
+10233ms ║RunTime Analysis CS > 18ms > PS > 10190ms > PE > 25ms > CE
+10234ms ║Piston waited at a semaphore for 10015ms
+10236ms ║Runtime (38292 bytes) successfully initialized in 10190ms (v0.3.110.20191009) (10234ms)
+10237ms ║╔Execution stage started
+10245ms ║║Comparison (enum) on stays (string) on = true (1ms)
+10247ms ║║Adding a timed trigger schedule for condition 2
+10249ms ║║Condition #2 evaluated false (8ms)
+10250ms ║║Condition group #1 evaluated false (state did not change) (9ms)
+10252ms ║╚Execution stage complete. (15ms)
+10253ms ║Setting up scheduled job for Thu, Apr 9 2020 @ 5:22:23 AM CDT (in 899.996s)
+10265ms ╚Event processed successfully (10265ms)
4/9/2020, 5:07:16 AM +484ms
+1ms ╔Received event [Lisa’s Closet Light].switch = off with a delay of 53ms
+114ms ║RunTime Analysis CS > 17ms > PS > 77ms > PE > 20ms > CE
+116ms ║Runtime (38213 bytes) successfully initialized in 77ms (v0.3.110.20191009) (115ms)
+117ms ║╔Execution stage started
+125ms ║║Comparison (enum) off stays (string) on = false (2ms)
+127ms ║║Cancelling any timed trigger schedules for condition 2
+127ms ║║Cancelling statement #2’s schedules…
+128ms ║║Condition #2 evaluated false (7ms)
+129ms ║║Condition group #1 evaluated false (state did not change) (8ms)
+131ms ║╚Execution stage complete. (14ms)
+132ms ╚Event processed successfully (132ms)
4/9/2020, 5:07:13 AM +629ms
+1ms ╔Received event [Lisa’s Closet Light].switch = off with a delay of 75ms
+140ms ║RunTime Analysis CS > 23ms > PS > 97ms > PE > 20ms > CE
+142ms ║Runtime (38212 bytes) successfully initialized in 97ms (v0.3.110.20191009) (140ms)
+143ms ║╔Execution stage started
+151ms ║║Comparison (enum) off stays (string) on = false (1ms)
+153ms ║║Cancelling any timed trigger schedules for condition 2
+154ms ║║Cancelling statement #2’s schedules…
+155ms ║║Condition #2 evaluated false (7ms)
+156ms ║║Condition group #1 evaluated false (state did not change) (8ms)
+157ms ║╚Execution stage complete. (14ms)
+158ms ╚Event processed successfully (158ms)
4/9/2020, 5:07:06 AM +185ms
+2ms ╔Received event [Lisa’s Closet Light].switch = on with a delay of 70ms
+138ms ║RunTime Analysis CS > 23ms > PS > 96ms > PE > 19ms > CE
+141ms ║Runtime (38206 bytes) successfully initialized in 96ms (v0.3.110.20191009) (138ms)
+142ms ║╔Execution stage started
+150ms ║║Comparison (enum) on stays (string) on = true (1ms)
+151ms ║║Adding a timed trigger schedule for condition 2
+153ms ║║Cancelling condition #2’s schedules…
+154ms ║║Condition #2 evaluated false (8ms)
+155ms ║║Cancelling condition #1’s schedules…
+156ms ║║Condition group #1 evaluated false (state changed) (11ms)
+158ms ║╚Execution stage complete. (17ms)
+159ms ║Setting up scheduled job for Thu, Apr 9 2020 @ 5:22:06 AM CDT (in 899.993s)
+168ms ╚Event processed successfully (167ms)

Here’s the SmartThings log for the switch this morning, showing it was turned on and almost immediately off twice at 5:07 but was clearly off at 5:22:

[Pantheon]

Has this piston been working? I had some ST interruptions this morning as well.

Tip : The number of SMS is limited daily to 50 (I think). You could combine your SMS command into one by separating your telephone numbers with a semicolon 1234567890;1234567890

[WCmore]

it was turned on and almost immediately off twice at 5:07

Spamming a switch can get it out of sync. I would not turn off the light until after it has been on for at least a couple of seconds. (and the same with the other direction)

[rwhillrunner]

It’s been having this same behavior for at least a couple of days now.

[rwhillrunner]

Interesting. I’ll have to check my ST logs against my SMS message logs. Can’t prove or disprove at this very moment but this sounds like a possibility.

I’ll also have to check what she was doing that she’d turn it off so quickly.

[orangebucket]

What you are seeing is the light being turned off and then being immediately switched on again, and then off again shortly after. The ‘on’ event arrives so quickly that it hits a semaphore and so arrives after the ‘off’. As the ‘off’ event has already been processed there is no event to prevent the ‘stays on’ being true and you get the SMS.

I also note that the second on/off isn’t flagged as ‘physical’ as the first on/off is.

[WCmore]

I’ll also have to check what she was doing that she’d turn it off so quickly

The gap is so tiny (one tenth of a second), I would suspect that it was done by some sort of programming.

[rwhillrunner]

I don’t have any programming on that switch as far as I’m aware but I’ll check.

I do think I came up with the following as a solution for this. Didn’t think this was going to work but I got a couple false alarms this afternoon so it seems to be working. I could probably collapse it to one if statement but wanted to check for false alarms.

Thanks for the tip on what was going on! Definitely led me in the right direction.