Comparison (enum) open changes_to (string) open = false (1ms)?

johnwest80 · 2017-12-26 04:35:29 UTC

1) Give a description of the problem
I have a rule with a condition that an open/close sensor change to open. However, the log shows that the comparison is false, even though a logical reading shows it should be true.

2) What is the expected behavior?
The then statement would execute.

3) What is happening/not happening?
The then statement is not executing because the statement: “Comparison (enum) open changes_to (string) open = false (1ms)” should be true.

If you look at the logs, at 10:37:34 the contact turns to open. And yet, Condition #9 evaluates to false. How can this be?

**4) Post a Green Snapshot of the piston

5) Attach any logs (From ST IDE and by turning logging level to Full)

12/25/2017, 10:47:36 PM +152ms
+2ms ╔Received event [Back door open sensor 1].contact = closed with a delay of 106ms
+146ms ║RunTime Analysis CS > 20ms > PS > 46ms > PE > 79ms > CE
+148ms ║Runtime (37635 bytes) successfully initialized in 46ms (v0.2.100.20171211) (145ms)
+149ms ║╔Execution stage started
+191ms ║║Comparison (datetime) 1514260056307 is_between (datetime) 1514241240000 … (datetime) 1514292060000 = true (3ms)
+193ms ║║Time restriction check passed
+194ms ║║Condition #3 evaluated true (39ms)
+204ms ║║Comparison (enum) off is (string) off = true (1ms)
+205ms ║║Condition #8 evaluated true (10ms)
+209ms ║║Comparison (enum) closed changes_to (string) open = false (0ms)
+211ms ║║Condition #9 evaluated false (5ms)
+212ms ║║Condition group #1 evaluated false (state did not change) (58ms)
+214ms ║╚Execution stage complete. (65ms)
+215ms ╚Event processed successfully (215ms)
12/25/2017, 10:47:34 PM +440ms
+2ms ╔Received event [Back door open sensor 1].contact = open with a delay of 100ms**
+177ms ║RunTime Analysis CS > 20ms > PS > 75ms > PE > 82ms > CE**
+179ms ║Runtime (37632 bytes) successfully initialized in 75ms (v0.2.100.20171211) (177ms)**
+180ms ║╔Execution stage started**
+222ms ║║Comparison (datetime) 1514260054626 is_between (datetime) 1514241240000 … (datetime) 1514292060000 = true (4ms)**
+223ms ║║Time restriction check passed**
+225ms ║║Condition #3 evaluated true (38ms)**
+233ms ║║Comparison (enum) off is (string) off = true (2ms)**
+235ms ║║Cancelling condition #8’s schedules…**
+236ms ║║Condition #8 evaluated true (10ms)**
+240ms ║║Comparison (enum) open changes_to (string) open = false (1ms)**
+241ms ║║Cancelling condition #9’s schedules…**
+242ms ║║Condition #9 evaluated false (6ms)**
+243ms ║║Condition group #1 evaluated false (state did not change) (57ms)**
+246ms ║╚Execution stage complete. (66ms)**
+247ms ╚Event processed successfully (247ms)**
12/25/2017, 10:46:21 PM +247ms
+1ms ╔Received event [NFP].time = 1514259982650 with a delay of -1403ms
+174ms ║RunTime Analysis CS > 20ms > PS > 49ms > PE > 105ms > CE
+177ms ║Runtime (37621 bytes) successfully initialized in 49ms (v0.2.100.20171211) (175ms)
+178ms ║╔Execution stage started
+764ms ║║Executed physical command [null].off() (572ms)
+765ms ║║Executed [Pool lights].off (573ms)
+768ms ║╚Execution stage complete. (591ms)
+769ms ╚Event processed successfully (769ms)
12/25/2017, 10:44:36 PM +709ms
+2ms ╔Received event [Back door open sensor 1].contact = closed with a delay of 104ms
+146ms ║RunTime Analysis CS > 19ms > PS > 47ms > PE > 80ms > CE
+149ms ║Runtime (37630 bytes) successfully initialized in 47ms (v0.2.100.20171211) (145ms)
+150ms ║╔Execution stage started
+191ms ║║Comparison (datetime) 1514259876865 is_between (datetime) 1514241240000 … (datetime) 1514292060000 = true (3ms)
+192ms ║║Time restriction check passed
+194ms ║║Condition #3 evaluated true (38ms)
+203ms ║║Comparison (enum) on is (string) off = false (2ms)
+204ms ║║Cancelling condition #8’s schedules…
+205ms ║║Condition #8 evaluated false (10ms)
+206ms ║║Cancelling condition #1’s schedules…
+207ms ║║Condition group #1 evaluated false (state changed) (52ms)
+210ms ║╚Execution stage complete. (61ms)
+212ms ║Setting up scheduled job for Mon, Dec 25 2017 @ 10:46:22 PM EST (in 105.73s)
+225ms ╚Event processed successfully (225ms)
12/25/2017, 10:44:22 PM +299ms
+2ms ╔Received event [Back door open sensor 1].contact = open with a delay of 109ms
+163ms ║RunTime Analysis CS > 33ms > PS > 49ms > PE > 80ms > CE
+165ms ║Runtime (37635 bytes) successfully initialized in 49ms (v0.2.100.20171211) (162ms)
+166ms ║╔Execution stage started
+208ms ║║Comparison (datetime) 1514259862472 is_between (datetime) 1514241240000 … (datetime) 1514292060000 = true (3ms)
+210ms ║║Time restriction check passed
+211ms ║║Condition #3 evaluated true (39ms)
+220ms ║║Comparison (enum) off is (string) off = true (2ms)
+221ms ║║Condition #8 evaluated true (9ms)
+226ms ║║Comparison (enum) open changes_to (string) open = true (0ms)
+227ms ║║Cancelling condition #9’s schedules…
+228ms ║║Condition #9 evaluated true (6ms)
+229ms ║║Cancelling condition #1’s schedules…
+230ms ║║Condition group #1 evaluated true (state changed) (58ms)
+233ms ║║Cancelling statement #4’s schedules…
+345ms ║║Executed physical command [null].on() (109ms)
+346ms ║║Executed [Pool lights].on (111ms)
+350ms ║║Executed virtual command [Pool lights].wait (0ms)
+351ms ║║Requesting a wake up for Mon, Dec 25 2017 @ 10:46:22 PM EST (in 120.0s)
+356ms ║╚Execution stage complete. (190ms)
+357ms ║Setting up scheduled job for Mon, Dec 25 2017 @ 10:46:22 PM EST (in 119.994s)
+364ms ╚Event processed successfully (364ms)
12/25/2017, 10:01:45 PM +181ms
+1ms ╔Received event [Back door open sensor 1].contact = closed with a delay of 123ms
+146ms ║RunTime Analysis CS > 19ms > PS > 48ms > PE > 80ms > CE
+149ms ║Runtime (37635 bytes) successfully initialized in 48ms (v0.2.100.20171211) (146ms)
+150ms ║╔Execution stage started
+191ms ║║Comparison (datetime) 1514257305337 is_between (datetime) 1514241240000 … (datetime) 1514292060000 = true (3ms)
+194ms ║║Time restriction check passed
+196ms ║║Condition #3 evaluated true (40ms)
+205ms ║║Comparison (enum) off is (string) off = true (2ms)
+206ms ║║Condition #8 evaluated true (10ms)
+210ms ║║Comparison (enum) closed changes_to (string) open = false (0ms)
+212ms ║║Condition #9 evaluated false (5ms)
+213ms ║║Condition group #1 evaluated false (state did not change) (58ms)
+215ms ║╚Execution stage complete. (66ms)
+216ms ╚Event processed successfully (217ms)`

johnwest80 · 2017-12-26 04:38:37 UTC

To clarify more, sometimes it works. For example, at 10:44:22pm, Condition #9 returns true, which is correct. Other times, the same condition, run when the door is opened, returns false.

michicago · 2017-12-26 15:48:06 UTC

The condition will only evaluate true when the door is opened (changes to open). So your true evaluation happens when the piston is triggered by the door changing to open. If the piston is executed by another trigger (time, pool lights, door closing) the condition will evaluate false because the door didn’t just change to open.

If you always want it to be true when the door is open, change your “changes to open” to “is open”.

Edit to add: I can’t see the event Timestamp you’re referencing in your pasted log. The one event triggerrd by your door changing to open did evaluate true, though.

johnwest80 · 2017-12-26 17:43:47 UTC

The log does seem hard to read. But to your point, the one I’m referencing shows that the evaluation started because the door contact changed to open. So that shouldn’t be the issue.

johnwest80 · 2018-01-06 00:18:22 UTC

So I figured it out. I needed to put the condition for the sensor changing to open as the first of the three conditions. Not sure why I needed to, but that fixed it. Maybe this will help the next person.