"Stays open for X minutes" condition fires incorrectly


#1

1) Give a description of the problem
I’m trying to use the “stays” condition to see if a switch/contact sensor stays in the same state for X minutes. But even after the switch/contact goes back to the non-event state, the statements inside the condition.

2) What is the expected behaviour?
For example, I have a condition that a contact sensor stays open for 15 minutes. If that occurs, send me an SMS.

I opened the door at 5:21:56, this triggered a scheduled task for 5:36:56. I closed it at 5:22:00. I expected the “stays” condition to evaluate to false in this situation.

3) What is happening/not happening?
But the event at 5:36:56 still fired! In addition to that, even though the condition was not satisfied, it still sent the SMS!

4) Post a Green Snapshot of the piston!

5) Attach logs after turning logging level to Full
> 11/12/2019, 5:36:55 PM +59ms
> +1ms ╔Received event [Home].time = 1573598216427 with a delay of -1368ms
> +111ms ║RunTime Analysis CS > 20ms > PS > 50ms > PE > 41ms > CE
> +114ms ║Runtime (37967 bytes) successfully initialized in 50ms (v0.3.110.20191009) (113ms)
> +115ms ║╔Execution stage started
> +120ms ║║Cancelling condition #2’s schedules…
> +121ms ║║Condition #2 evaluated true (1ms)
> +122ms ║║Cancelling condition #1’s schedules…
> +123ms ║║Condition group #1 evaluated true (state changed) (3ms)
> +125ms ║║Cancelling statement #3’s schedules…
> +130ms ║║Calculating (string) Garage Door + (string) stayed open! >> (string) Garage Door stayed open!
> +169ms ║║Executed virtual command sendSMSNotification (35ms)
> +171ms ║╚Execution stage complete. (56ms)
> +172ms ╚Event processed successfully (172ms)
>
> 11/12/2019, 5:22:00 PM +219ms
> +1ms ╔Received event [Garage Door].contact = closed with a delay of 123ms
> +206ms ║RunTime Analysis CS > 20ms > PS > 46ms > PE > 140ms > CE
> +208ms ║Runtime (37967 bytes) successfully initialized in 46ms (v0.3.110.20191009) (206ms)
> +209ms ║╔Execution stage started
> +229ms ║║Comparison (enum) closed stays (string) open = false (2ms)
> +231ms ║║Comparison (enum) closed stays (string) open = false (1ms)
> +233ms ║║Comparison (enum) open stays (string) open = true (1ms)
> +235ms ║║Comparison (enum) closed stays (string) open = false (1ms)
> +238ms ║║Cancelling any timed trigger schedules for device :ceccd13059dfba8762c8e0392de30fbc: for condition 2
> +239ms ║║Cancelling statement #2’s schedules…
> +239ms ║║Cancelling any timed trigger schedules for device :d4714e580b9f31d2af8aad8acc1373a3: for condition 2
> +240ms ║║Cancelling statement #2’s schedules…
> +241ms ║║Cancelling any timed trigger schedules for device :bbb7a11842b6bfb119c90dbb63bc2013: for condition 2
> +242ms ║║Cancelling statement #2’s schedules…
> +243ms ║║Condition #2 evaluated false (30ms)
> +244ms ║║Condition group #1 evaluated false (state did not change) (31ms)
> +247ms ║╚Execution stage complete. (37ms)
> +248ms ║Setting up scheduled job for Tue, Nov 12 2019 @ 5:36:56 PM EST (in 895.961s)
> +261ms ╚Event processed successfully (260ms)
>
> 11/12/2019, 5:21:56 PM +278ms
> +1ms ╔Received event [Garage Door].contact = open with a delay of 101ms
> +111ms ║RunTime Analysis CS > 20ms > PS > 49ms > PE > 42ms > CE
> +113ms ║Runtime (37961 bytes) successfully initialized in 49ms (v0.3.110.20191009) (111ms)
> +114ms ║╔Execution stage started
> +136ms ║║Comparison (enum) closed stays (string) open = false (1ms)
> +138ms ║║Comparison (enum) closed stays (string) open = false (1ms)
> +140ms ║║Comparison (enum) open stays (string) open = true (1ms)
> +143ms ║║Comparison (enum) open stays (string) open = true (2ms)
> +145ms ║║Cancelling any timed trigger schedules for device :ceccd13059dfba8762c8e0392de30fbc: for condition 2
> +146ms ║║Cancelling statement #2’s schedules…
> +147ms ║║Cancelling any timed trigger schedules for device :d4714e580b9f31d2af8aad8acc1373a3: for condition 2
> +148ms ║║Cancelling statement #2’s schedules…
> +149ms ║║Adding a timed trigger schedule for device :c58071b876c8d1c7be089868f62cead0: for condition 2
> +151ms ║║Adding a timed trigger schedule for device :bbb7a11842b6bfb119c90dbb63bc2013: for condition 2
> +153ms ║║Cancelling condition #2’s schedules…
> +154ms ║║Condition #2 evaluated false (35ms)
> +155ms ║║Cancelling condition #1’s schedules…
> +156ms ║║Condition group #1 evaluated false (state changed) (38ms)
> +159ms ║╚Execution stage complete. (45ms)
> +161ms ║Setting up scheduled job for Tue, Nov 12 2019 @ 5:36:56 PM EST (in 899.989s), with 1 more job pending
> +170ms ╚Event processed successfully (169ms)


#2

I suspect at 5:36:55 PM, one of the 4 sensors had been open for awhile…

> +121ms ║║Condition #2 evaluated true

This is likely because line 10 says “if ANY of …”
(IE: It doesn’t have to be the same device open after the 15 minutes have passed)


#3

Awesome realization - let me try with just one device.

If that’s true, the functionality of “stays” seems misleading though.


#4

Sounds true, in that all that matters is that one of the contacts stays open for 15 minutes after the piston is executed for any reason. I don’t find that misleading myself.

According to the logs:

At 5:21:56pm the piston was triggered due to one of the contacts opening. The contacts with IDs :c58071b876c8d1c7be089868f62cead0: and :bbb7a11842b6bfb119c90dbb63bc2013: were open with the other two being closed. The piston added 15 minute timed triggers for each of these two open devices, one being scheduled and one pending (SmartThings only allows one active schedule).

At 5:22:00pm the piston was triggered by a contact being closed. Contact :bbb7a11842b6bfb119c90dbb63bc2013: was now closed but :c58071b876c8d1c7be089868f62cead0: remained open. The other two remained closed. One timer was cancelled and one timer was rescheduled, still for 15 minutes from the original time.

At 5:36:55pm the 15 minute timer fired meaning the ‘stay’ was over and evaluated true so the SMS was sent.

In summary, the piston triggered with two contacts open and two closed, and one of the two open ones stayed open for fifteen minutes.

Were you perhaps hoping that the ‘stay’ only applied to the contact that had triggered the piston?


#5

Excellent log analysis, @orangebucket!! :+1: