Piston doesn't always fire first time

#1

1) Give a description of the problem
Piston to turn lights on with motion doesn’t always fire the first time even though piston woke up due to motion event. A few minutes later when motion is triggered again, lights come on. Sometimes it works on the first motion event, other times it does not.

2) What is the expected behavior?
Lights on during certain time (early morning when it’s still dark in the house) and motion (I come downstairs).

3) What is happening/not happening?
Sometimes works first time, sometimes second, always works eventually.

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

image
image.png1178×849 32.2 KB

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

Logs are newest to oldest, go to bottom and read up!

It works this time with motion a few minutes later:
11/2/2018, 6:01:22 AM +787ms
+2ms ╔Received event [Living Room Motion].motion = active with a delay of 122ms
+243ms ║RunTime Analysis CS > 18ms > PS > 171ms > PE > 54ms > CE
+246ms ║Runtime (40901 bytes) successfully initialized in 171ms (v0.3.108.20180906) (242ms)
+247ms ║╔Execution stage started
+290ms ║║Comparison (datetime) 1541160083041 is_between (datetime) 1541138400000 … (datetime) 1541165400000 = true (4ms)
+293ms ║║Condition #7 evaluated true (39ms)
+298ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+300ms ║║Cancelling condition #6’s schedules…
+301ms ║║Condition #6 evaluated true (7ms)
+313ms ║║Comparison (enum) off is (string) off = true (1ms)
+315ms ║║Cancelling condition #18’s schedules…
+316ms ║║Condition #18 evaluated true (14ms)
+317ms ║║Cancelling condition #1’s schedules…
+318ms ║║Condition group #1 evaluated true (state changed) (65ms)
+322ms ║║Cancelling statement #2’s schedules…
+335ms ║║Executed physical command [Kitchen Pendants Dimmer].on() (10ms)
+336ms ║║Executed [Kitchen Pendants Dimmer].on (12ms)
+355ms ║║Executed physical command [Kitchen Pendants Dimmer].setLevel([100]) (9ms)
+356ms ║║Executed virtual command [Kitchen Pendants Dimmer].adjustLevel (16ms)
+359ms ║║Cancelling statement #22’s schedules…
+661ms ║║Executed physical command [VLC Thing].speak([Alexa, weather]) (294ms)
+662ms ║║Executed [VLC Thing].speak (296ms)
+669ms ║╚Execution stage complete. (422ms)
+671ms ║Setting up scheduled job for Fri, Nov 2 2018 @ 7:59:00 AM MDT (in 7056.543s)
+685ms ╚Event processed successfully (685ms)

Motion goes inactive again, normal:
11/2/2018, 6:01:13 AM +756ms
+1ms ╔Received event [Living Room Motion].motion = inactive with a delay of 113ms
+113ms ║RunTime Analysis CS > 17ms > PS > 36ms > PE > 61ms > CE
+116ms ║Runtime (40899 bytes) successfully initialized in 36ms (v0.3.108.20180906) (113ms)
+117ms ║╔Execution stage started
+156ms ║║Comparison (datetime) 1541160073880 is_between (datetime) 1541138400000 … (datetime) 1541165400000 = true (4ms)
+158ms ║║Condition #7 evaluated true (35ms)
+163ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+165ms ║║Condition #6 evaluated false (6ms)
+167ms ║║Condition group #1 evaluated false (state did not change) (43ms)
+172ms ║╚Execution stage complete. (55ms)
+174ms ║Setting up scheduled job for Fri, Nov 2 2018 @ 7:59:00 AM MDT (in 7066.071s)
+187ms ╚Event processed successfully (186ms)

Piston fires due to motion, but light doesn’t turn on first time:
11/2/2018, 5:56:42 AM +735ms
+2ms ╔Received event [Living Room Motion].motion = active with a delay of 218ms
+140ms ║RunTime Analysis CS > 25ms > PS > 57ms > PE > 57ms > CE
+142ms ║Runtime (40897 bytes) successfully initialized in 57ms (v0.3.108.20180906) (139ms)
+144ms ║╔Execution stage started
+190ms ║║Comparison (datetime) 1541159802886 is_between (datetime) 1541138400000 … (datetime) 1541165400000 = true (5ms)
+192ms ║║Cancelling condition #7’s schedules…
+193ms ║║Condition #7 evaluated true (43ms)
+199ms ║║Comparison (enum) active changes_to (string) active = false (1ms)
+201ms ║║Cancelling condition #6’s schedules…
+202ms ║║Condition #6 evaluated false (8ms)
+203ms ║║Condition group #1 evaluated false (state did not change) (54ms)
+209ms ║╚Execution stage complete. (66ms)
+211ms ║Setting up scheduled job for Fri, Nov 2 2018 @ 7:59:00 AM MDT (in 7337.055s)
+227ms ╚Event processed successfully (227ms)

Last event night before:
11/1/2018, 9:25:58 PM +153ms
+1ms ╔Received event [Living Room Motion].motion = inactive with a delay of 63ms
+104ms ║RunTime Analysis CS > 16ms > PS > 34ms > PE > 53ms > CE
+106ms ║Runtime (40898 bytes) successfully initialized in 34ms (v0.3.108.20180906) (104ms)
+108ms ║╔Execution stage started
+148ms ║║Comparison (datetime) 1541129158268 is_between (datetime) 1541052000000 … (datetime) 1541078940000 = false (5ms)
+150ms ║║Condition #7 evaluated false (36ms)
+152ms ║║Condition group #1 evaluated false (state did not change) (38ms)
+157ms ║╚Execution stage complete. (50ms)
+159ms ║Setting up scheduled job for Fri, Nov 2 2018 @ 7:59:00 AM MDT (in 37981.689s)
+171ms ╚Event processed successfully (171ms)

REMOVE BELOW AFTER READING
If a solution is found for your question then please mark the post as the solution.

#2

First thing I’d do is rearrange your trigger and conditions and observe if it makes any difference.

motion
time condition
switch condition
#3

I’ll try that and see what happens in the morning. May take a few days of success to see if it works since it sometimes works the first time. Any idea why same piston works the second time, or sometimes the first time? Seems like it shouldn’t matter though I like your thought process. I had it the way I had it because motion happens all the time and I wanted the piston to quit as soon as possible.

#4

I’m not really sure, there have many piston posted like yours that work erratically and the most common thing I see is the sequence of triggers and conditions. I just always keep in mind that pistons process from top to bottom and I build from that…most of the time :slight_smile:

#5

Well it worked today on the first trigger. Let me try it a few more times to see if this has solved it. Thanks eibyer.