Piston fails to compare proper time

Razamo786 · 2019-05-02 02:56:01 UTC

1) Give a description of the problem
Piston executes daily on time but unable to complete the task as current time stamp is not showing right.

2) What is the expected behaviour?
Based on current time of the day, it should turn on/off lights and lock doors.

3) What is happening/not happening?
Piston executes on time but doesn’t finish the job as it fails to validate the time

4) Post a Green Snapshot of the piston

Uploaded

5) Attach logs after turning logging level to Full
|+370ms|║Comparison (time) 81253992 happens_daily_at (time) 1556756400000 = false (1ms)|
| — | — |
|+375ms|║Cancelling statement #2’s schedules…|
|+384ms|║Requesting time schedule wake up at Thu, May 2 2019 @ 8:20:00 PM EDT|
|+400ms|║Comparison (enum) off is (string) off = true (2ms)|
|+415ms|║Comparison (time) 81254065 happens_daily_at (time) 1556756400000 = false (1ms)|
|+421ms|║Cancelling statement #5’s schedules…|
|+430ms|║Requesting time schedule wake up at Thu, May 2 2019 @ 8:20:00 PM EDT|
|+446ms|║Comparison (time) 81254096 happens_daily_at (time) 82800000 = false (1ms)|
|+449ms|║Cancelling statement #11’s schedules…|
|+454ms|║Requesting time schedule wake up at Wed, May 1 2019 @ 11:00:00 PM EDT|
|+469ms|║Comparison (time) 81254120 happens_daily_at (time) 0 = false (1ms)|
|+472ms|║Cancelling statement #15’s schedules…|
|+478ms|║Requesting time schedule wake up at Thu, May 2 2019 @ 12:00:00 AM EDT|
|+507ms|║Comparison (time) 81254144 is_between (time) 600000 … (time) 25200000 = false (15ms)|
|+523ms|║Comparison (time) 81254174 happens_daily_at (time) 1556707620000 = false (1ms)|
|+527ms|║Cancelling statement #24’s schedules…|
|+536ms|║Requesting time schedule wake up at Thu, May 2 2019 @ 6:47:00 AM EDT|
|+560ms|║Comparison (enum) off is (string) on = false (3ms)|
|+581ms|║Setting up scheduled job for Wed, May 1 2019 @ 11:00:00 PM EDT (in 1545.765s), with 4 more jobs pending|
|+597ms|╚Piston successfully started (597ms)|
|5/1/2019, 10:17:03 PM +299ms|
|+1ms|╔Starting piston… (v0.3.10a.20190223)|
|+261ms|║╔Subscribing to devices…|
|+437ms|║║Subscribing to Front Porch Lights…|
|+439ms|║║Subscribing to Master Bedroom Night Lamp…|
|+440ms|║║Subscribing to Kitchen…|
|+442ms|║║Subscribing to Island Lights…|
|+444ms|║║Subscribing to Back Door…|
|+445ms|║║Subscribing to Front Door…|
|+447ms|║║Subscribing to Garage Door…|
|+449ms|║╚Finished subscribing (200ms)|
|+526ms|║Comparison (time) 80223779 happens_daily_at (time) 1556756400000 = false (0ms)|
|+531ms|║Cancelling statement #2’s schedules…|
|+540ms|║Requesting time schedule wake up at Thu, May 2 2019 @ 8:20:00 PM EDT|
|+557ms|║Comparison (enum) off is (string) off = true (3ms)|
|+572ms|║Comparison (time) 80223867 happens_daily_at (time) 1556756400000 = false (1ms)|
|+579ms|║Cancelling statement #5’s schedules…|
|+587ms|║Requesting time schedule wake up at Thu, May 2 2019 @ 8:20:00 PM EDT|
|+603ms|║Comparison (time) 80223898 happens_daily_at (time) 82800000 = false (0ms)|
|+606ms|║Cancelling statement #11’s schedules…|
|+611ms|║Requesting time schedule wake up at Wed, May 1 2019 @ 11:00:00 PM EDT|
|+626ms|║Comparison (time) 80223921 happens_daily_at (time) 0 = false (1ms)|
|+630ms|║Cancelling statement #15’s schedules…|
|+636ms|║Requesting time schedule wake up at Thu, May 2 2019 @ 12:00:00 AM EDT|
|+676ms|║Comparison (time) 80223946 is_between (time) 600000 … (time) 25200000 = false (15ms)|
|+693ms|║Comparison (time) 80223987 happens_daily_at (time) 1556707620000 = false (1ms)|
|+697ms|║Cancelling statement #24’s schedules…|
|+706ms|║Requesting time schedule wake up at Thu, May 2 2019 @ 6:47:00 AM EDT|
|+721ms|║Comparison (enum) off is (string) on = false (3ms)|
|+743ms|║Setting up scheduled job for Wed, May 1 2019 @ 11:00:00 PM EDT (in 2575.96s), with 4 more jobs pending|
|+761ms|╚Piston successfully started (760ms)|
|5/1/2019, 10:08:56 PM +537ms|
|+1ms|╔Starting piston… (v0.3.10a.20190223)|
|+237ms|║╔Subscribing to devices…|
|+355ms|║║Subscribing to Front Porch Lights…|
|+357ms|║║Subscribing to Master Bedroom Night Lamp…|
|+359ms|║║Subscribing to Kitchen…|
|+361ms|║║Subscribing to Island Lights…|
|+362ms|║║Subscribing to Back Door…|
|+364ms|║║Subscribing to Front Door…|
|+366ms|║║Subscribing to Garage Door…|
|+367ms|║╚Finished subscribing (143ms)|
|+437ms|║Comparison (datetime) 1556762936934 happens_daily_at (datetime) 1556756400000 = false (1ms)|
|+440ms|║Cancelling condition #2’s schedules…|
|+442ms|║Cancelling statement #2’s schedules…|
|+457ms|║Comparison (enum) off is (string) off = true (3ms)|
|+460ms|║Cancelling condition #3’s schedules…|
|+472ms|║Comparison (datetime) 1556762937006 happens_daily_at (datetime) 1556756400000 = false (1ms)|
|+476ms|║Cancelling statement #5’s schedules…|
|+492ms|║Comparison (datetime) 1556762937026 happens_daily_at (datetime) 1556766000000 = false (1ms)|
|+495ms|║Cancelling statement #11’s schedules…|
|+498ms|║Requesting time schedule wake up at Wed, May 1 2019 @ 11:00:00 PM EDT|
|+512ms|║Comparison (datetime) 1556762937046 happens_daily_at (datetime) 1556683200000 = false (0ms)|
|+519ms|║Cancelling statement #15’s schedules…|
|+539ms|║Comparison (datetime) 1556762937068 is_between (datetime) 1556683800000 … (datetime) 1556708400000 = false (6ms)|
|+554ms|║Comparison (datetime) 1556762937088 happens_daily_at (datetime) 1556707620000 = false (1ms)|
|+556ms|║Cancelling statement #24’s schedules…|
|+573ms|║Comparison (enum) off is (string) on = false (3ms)|
|+582ms|║Setting up scheduled job for Wed, May 1 2019 @ 11:00:00 PM EDT (in 3062.882s)|
|+598ms|╚Piston successfully started (598ms)|
|5/1/2019, 8:19:59 PM +105ms|
|+1ms|╔Received event [Home].time = 1556756400000 with a delay of -896ms|
|+213ms|║RunTime Analysis CS > 35ms > PS > 138ms > PE > 40ms > CE|
|+215ms|║Runtime (41318 bytes) successfully initialized in 138ms (v0.3.10a.20190223) (213ms)|
|+217ms|║╔Execution stage started|
|+262ms|║║Comparison (time) 73199331 happens_daily_at (time) 1556756400000 = true (0ms)|
|+264ms|║║Time restriction check passed|
|+266ms|║║Cancelling condition #2’s schedules…|
|+267ms|║║Condition #2 evaluated true (42ms)|
|+269ms|║║Cancelling statement #2’s schedules…|
|+275ms|║║Requesting time schedule wake up at Thu, May 2 2019 @ 8:20:00 PM EDT|
|+288ms|║║Comparison (enum) on is (string) off = false (2ms)|
|+290ms|║║Condition #3 evaluated false (12ms)|
|+291ms|║║Condition group #1 evaluated false (state did not change) (66ms)|
|+297ms|║║Comparison (time) 73199398 happens_daily_at (time) 1556756400000 = false (1ms)|
|+299ms|║║Condition #5 evaluated false (6ms)|
|+301ms|║║Cancelling statement #5’s schedules…|
|+308ms|║║Requesting time schedule wake up at Thu, May 2 2019 @ 8:20:00 PM EDT|
|+311ms|║║Condition group #4 evaluated false (state did not change) (19ms)|
|+319ms|║║Comparison (time) 73199421 happens_daily_at (time) 82800000 = false (0ms)|
|+321ms|║║Condition #11 evaluated false (5ms)|
|+322ms|║║Cancelling statement #11’s schedules…|
|+327ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 11:00:00 PM EDT|
|+330ms|║║Condition group #10 evaluated false (state did not change) (15ms)|
|+337ms|║║Comparison (time) 73199439 happens_daily_at (time) 0 = false (1ms)|
|+339ms|║║Condition #15 evaluated false (5ms)|
|+341ms|║║Cancelling statement #15’s schedules…|
|+345ms|║║Requesting time schedule wake up at Thu, May 2 2019 @ 12:00:00 AM EDT|
|+349ms|║║Condition group #14 evaluated false (state did not change) (15ms)|
|+367ms|║║Comparison (time) 73199458 is_between (time) 600000 … (time) 25200000 = false (11ms)|
|+370ms|║║Cancelling condition #19’s schedules…|
|+371ms|║║Condition #19 evaluated false (17ms)|
|+372ms|║║Cancelling condition #18’s schedules…|
|+373ms|║║Condition group #18 evaluated false (state changed) (21ms)|
|+382ms|║║Comparison (time) 73199483 happens_daily_at (time) 1556707620000 = false (0ms)|
|+383ms|║║Condition #24 evaluated false (6ms)|
|+386ms|║║Cancelling statement #24’s schedules…|
|+393ms|║║Requesting time schedule wake up at Thu, May 2 2019 @ 6:47:00 AM EDT|
|+396ms|║║Condition group #23 evaluated false (state did not change) (19ms)|
|+404ms|║╚Execution stage complete. (188ms)|
|+408ms|║Setting up scheduled job for Wed, May 1 2019 @ 11:00:00 PM EDT (in 9600.488s), with 4 more jobs pending|
|+417ms|╚Event processed successfully (417ms)|
|5/1/2019, 7:07:58 AM +74ms|
|+1ms|╔Received event [Home].time = 1556708879362 with a delay of -1288ms|
|+130ms|║RunTime Analysis CS > 23ms > PS > 63ms > PE > 44ms > CE|
|+133ms|║Runtime (41314 bytes) successfully initialized in 63ms (v0.3.10a.20190223) (131ms)|
|+134ms|║╔Execution stage started|
|+179ms|║║Skipped execution of physical command [Back Door].lock([]) because it would make no change to the device. (4ms)|
|+180ms|║║Executed [Back Door].lock (6ms)|
|+247ms|║║Executed physical command [Front Door].lock() (63ms)|
|+248ms|║║Executed [Front Door].lock (66ms)|
|+256ms|║║Skipped execution of physical command [Garage Door].lock([]) because it would make no change to the device. (5ms)|
|+257ms|║║Executed [Garage Door].lock (7ms)|
|+299ms|║║Comparison (time) 25678336 happens_daily_at (time) 1556707620000 = false (2ms)|
|+301ms|║║Condition #24 evaluated false (40ms)|
|+306ms|║║Cancelling statement #24’s schedules…|
|+312ms|║║Requesting time schedule wake up at Thu, May 2 2019 @ 6:47:00 AM EDT|
|+316ms|║║Condition group #23 evaluated false (state did not change) (54ms)|
|+321ms|║╚Execution stage complete. (187ms)|
|+324ms|║Setting up scheduled job for Wed, May 1 2019 @ 8:20:00 PM EDT (in 47521.603s), with 4 more jobs pending|
|+333ms|╚Event processed successfully (333ms)|
|5/1/2019, 6:47:59 AM +82ms|
|+1ms|╔Received event [Home].time = 1556707680000 with a delay of -918ms|
|+120ms|║RunTime Analysis CS > 20ms > PS > 57ms > PE > 42ms > CE|
|+122ms|║Runtime (41316 bytes) successfully initialized in 57ms (v0.3.10a.20190223) (120ms)|
|+123ms|║╔Execution stage started|
|+168ms|║║Comparison (time) 24479214 happens_daily_at (time) 1556756400000 = false (0ms)|
|+169ms|║║Condition #2 evaluated false (37ms)|
|+171ms|║║Cancelling statement #2’s schedules…|
|+178ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 8:20:00 PM EDT|
|+181ms|║║Condition group #1 evaluated false (state did not change) (50ms)|
|+187ms|║║Comparison (time) 24479265 happens_daily_at (time) 1556756400000 = false (1ms)|
|+189ms|║║Condition #5 evaluated false (5ms)|
|+190ms|║║Cancelling statement #5’s schedules…|
|+197ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 8:20:00 PM EDT|
|+200ms|║║Condition group #4 evaluated false (state did not change) (18ms)|
|+207ms|║║Comparison (time) 24479286 happens_daily_at (time) 82800000 = false (1ms)|
|+209ms|║║Condition #11 evaluated false (5ms)|
|+211ms|║║Cancelling statement #11’s schedules…|
|+215ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 11:00:00 PM EDT|
|+219ms|║║Condition group #10 evaluated false (state did not change) (15ms)|
|+226ms|║║Comparison (time) 24479305 happens_daily_at (time) 0 = false (0ms)|
|+228ms|║║Cancelling condition #15’s schedules…|
|+229ms|║║Condition #15 evaluated false (6ms)|
|+231ms|║║Cancelling statement #15’s schedules…|
|+235ms|║║Requesting time schedule wake up at Thu, May 2 2019 @ 12:00:00 AM EDT|
|+238ms|║║Cancelling condition #14’s schedules…|
|+240ms|║║Condition group #14 evaluated false (state changed) (17ms)|
|+260ms|║║Comparison (time) 24479326 is_between (time) 600000 … (time) 25200000 = true (12ms)|
|+261ms|║║Time restriction check passed|
|+263ms|║║Cancelling condition #19’s schedules…|
|+265ms|║║Condition #19 evaluated true (20ms)|
|+266ms|║║Cancelling condition #18’s schedules…|
|+267ms|║║Condition group #18 evaluated true (state changed) (24ms)|
|+270ms|║║Cancelling statement #20’s schedules…|
|+277ms|║║Executed virtual command [Back Door, Front Door, Garage Door].wait (1ms)|
|+279ms|║║Requesting a wake up for Wed, May 1 2019 @ 7:07:59 AM EDT (in 1200.0s)|
|+289ms|║╚Execution stage complete. (166ms)|
|+292ms|║Setting up scheduled job for Wed, May 1 2019 @ 7:07:59 AM EDT (in 1199.989s), with 4 more jobs pending|
|+303ms|╚Event processed successfully (303ms)|
|4/30/2019, 11:59:59 PM +78ms|
|+1ms|╔Received event [Home].time = 1556683200000 with a delay of -923ms|
|+163ms|║RunTime Analysis CS > 23ms > PS > 71ms > PE > 69ms > CE|
|+167ms|║Runtime (41316 bytes) successfully initialized in 71ms (v0.3.10a.20190223) (165ms)|
|+169ms|║╔Execution stage started|
|+379ms|║║Comparison (time) 86399376 happens_daily_at (time) 1556669940000 = false (1ms)|
|+382ms|║║Condition #2 evaluated false (84ms)|
|+388ms|║║Cancelling statement #2’s schedules…|
|+399ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 8:19:00 PM EDT|
|+407ms|║║Condition group #1 evaluated false (state did not change) (107ms)|
|+415ms|║║Comparison (time) 86399487 happens_daily_at (time) 1556669940000 = false (0ms)|
|+418ms|║║Condition #5 evaluated false (9ms)|
|+426ms|║║Cancelling statement #5’s schedules…|
|+438ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 8:19:00 PM EDT|
|+443ms|║║Condition group #4 evaluated false (state did not change) (34ms)|
|+454ms|║║Comparison (time) 86399527 happens_daily_at (time) 82800000 = false (1ms)|
|+457ms|║║Cancelling condition #11’s schedules…|
|+459ms|║║Condition #11 evaluated false (9ms)|
|+462ms|║║Cancelling statement #11’s schedules…|
|+469ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 11:00:00 PM EDT|
|+474ms|║║Cancelling condition #10’s schedules…|
|+476ms|║║Condition group #10 evaluated false (state changed) (27ms)|
|+487ms|║║Comparison (time) 86399560 happens_daily_at (time) 0 = true (1ms)|
|+490ms|║║Time restriction check passed|
|+492ms|║║Cancelling condition #15’s schedules…|
|+494ms|║║Condition #15 evaluated true (11ms)|
|+497ms|║║Cancelling statement #15’s schedules…|
|+506ms|║║Requesting time schedule wake up at Thu, May 2 2019 @ 12:00:00 AM EDT|
|+512ms|║║Cancelling condition #14’s schedules…|
|+513ms|║║Condition group #14 evaluated true (state changed) (32ms)|
|+518ms|║║Cancelling statement #16’s schedules…|
|+527ms|║║Skipped execution of physical command [Master Bedroom Night Lamp].off([]) because it would make no change to the device. (3ms)|
|+530ms|║║Executed [Master Bedroom Night Lamp].off (6ms)|
|+558ms|║║Comparison (time) 86399615 is_between (time) 600000 … (time) 25200000 = false (17ms)|
|+562ms|║║Condition #19 evaluated false (25ms)|
|+564ms|║║Condition group #18 evaluated false (state did not change) (27ms)|
|+576ms|║║Comparison (time) 86399648 happens_daily_at (time) 1556621280000 = false (1ms)|
|+579ms|║║Condition #24 evaluated false (9ms)|
|+581ms|║║Cancelling statement #24’s schedules…|
|+590ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 6:48:00 AM EDT|
|+594ms|║║Condition group #23 evaluated false (state did not change) (26ms)|
|+604ms|║╚Execution stage complete. (436ms)|
|+609ms|║Setting up scheduled job for Wed, May 1 2019 @ 6:48:00 AM EDT (in 24480.314s), with 4 more jobs pending|
|+624ms|╚Event processed successfully (623ms)|
|4/30/2019, 10:59:59 PM +78ms|
|+1ms|╔Received event [Home].time = 1556679600000 with a delay of -922ms|
|+211ms|║RunTime Analysis CS > 22ms > PS > 94ms > PE > 94ms > CE|
|+214ms|║Runtime (41317 bytes) successfully initialized in 94ms (v0.3.10a.20190223) (212ms)|
|+216ms|║╔Execution stage started|
|+287ms|║║Comparison (time) 82799305 happens_daily_at (time) 1556669940000 = false (1ms)|
|+290ms|║║Cancelling condition #2’s schedules…|
|+292ms|║║Condition #2 evaluated false (64ms)|
|+295ms|║║Cancelling statement #2’s schedules…|
|+312ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 8:19:00 PM EDT|
|+320ms|║║Condition group #1 evaluated false (state did not change) (93ms)|
|+333ms|║║Comparison (time) 82799403 happens_daily_at (time) 1556669940000 = false (2ms)|
|+337ms|║║Condition #5 evaluated false (12ms)|
|+344ms|║║Cancelling statement #5’s schedules…|
|+356ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 8:19:00 PM EDT|
|+362ms|║║Condition group #4 evaluated false (state did not change) (40ms)|
|+376ms|║║Comparison (time) 82799448 happens_daily_at (time) 82800000 = true (1ms)|
|+379ms|║║Time restriction check passed|
|+382ms|║║Cancelling condition #11’s schedules…|
|+384ms|║║Condition #11 evaluated true (15ms)|
|+387ms|║║Cancelling statement #11’s schedules…|
|+396ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 11:00:00 PM EDT|
|+403ms|║║Cancelling condition #10’s schedules…|
|+405ms|║║Condition group #10 evaluated true (state changed) (36ms)|
|+411ms|║║Cancelling statement #12’s schedules…|
|+436ms|║║Skipped execution of physical command [Front Porch Lights].off([]) because it would make no change to the device. (4ms)|
|+439ms|║║Executed [Front Porch Lights].off (8ms)|
|+454ms|║║Comparison (time) 82799526 happens_daily_at (time) 0 = false (1ms)|
|+459ms|║║Condition #15 evaluated false (11ms)|
|+482ms|║║Cancelling statement #15’s schedules…|
|+499ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 12:00:00 AM EDT|
|+510ms|║║Condition group #14 evaluated false (state did not change) (63ms)|
|+560ms|║║Comparison (time) 82799595 is_between (time) 600000 … (time) 25200000 = false (21ms)|
|+564ms|║║Condition #19 evaluated false (47ms)|
|+567ms|║║Condition group #18 evaluated false (state did not change) (50ms)|
|+582ms|║║Comparison (time) 82799653 happens_daily_at (time) 1556621280000 = false (1ms)|
|+586ms|║║Condition #24 evaluated false (11ms)|
|+589ms|║║Cancelling statement #24’s schedules…|
|+603ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 6:48:00 AM EDT|
|+609ms|║║Condition group #23 evaluated false (state did not change) (35ms)|
|+624ms|║╚Execution stage complete. (409ms)|
|+630ms|║Setting up scheduled job for Wed, May 1 2019 @ 12:00:00 AM EDT (in 3600.293s), with 4 more jobs pending|
|+641ms|╚Event processed successfully (640ms)|
|4/30/2019, 8:18:59 PM +49ms|
|+1ms|╔Received event [Home].time = 1556669940000 with a delay of -951ms|
|+158ms|║RunTime Analysis CS > 17ms > PS > 102ms > PE > 38ms > CE|
|+161ms|║Runtime (41318 bytes) successfully initialized in 102ms (v0.3.10a.20190223) (159ms)|
|+162ms|║╔Execution stage started|
|+198ms|║║Comparison (time) 73139220 happens_daily_at (time) 1556669940000 = true (1ms)|
|+200ms|║║Time restriction check passed|
|+202ms|║║Cancelling condition #2’s schedules…|
|+204ms|║║Condition #2 evaluated true (32ms)|
|+206ms|║║Cancelling statement #2’s schedules…|
|+214ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 8:19:00 PM EDT|
|+230ms|║║Comparison (enum) on is (string) off = false (3ms)|
|+232ms|║║Cancelling condition #3’s schedules…|
|+234ms|║║Condition #3 evaluated false (16ms)|
|+236ms|║║Condition group #1 evaluated false (state did not change) (65ms)|
|+242ms|║║Comparison (time) 73139287 happens_daily_at (time) 1556669940000 = false (1ms)|
|+244ms|║║Condition #5 evaluated false (6ms)|
|+246ms|║║Cancelling statement #5’s schedules…|
|+253ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 8:19:00 PM EDT|
|+256ms|║║Condition group #4 evaluated false (state did not change) (18ms)|
|+263ms|║║Comparison (time) 73139309 happens_daily_at (time) 82800000 = false (0ms)|
|+265ms|║║Condition #11 evaluated false (5ms)|
|+266ms|║║Cancelling statement #11’s schedules…|
|+271ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 11:00:00 PM EDT|
|+274ms|║║Condition group #10 evaluated false (state did not change) (15ms)|
|+281ms|║║Comparison (time) 73139327 happens_daily_at (time) 0 = false (1ms)|
|+283ms|║║Condition #15 evaluated false (4ms)|
|+284ms|║║Cancelling statement #15’s schedules…|
|+289ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 12:00:00 AM EDT|
|+292ms|║║Condition group #14 evaluated false (state did not change) (15ms)|
|+310ms|║║Comparison (time) 73139345 is_between (time) 600000 … (time) 25200000 = false (11ms)|
|+312ms|║║Cancelling condition #19’s schedules…|
|+313ms|║║Condition #19 evaluated false (17ms)|
|+315ms|║║Cancelling condition #18’s schedules…|
|+316ms|║║Condition group #18 evaluated false (state changed) (21ms)|
|+324ms|║║Comparison (time) 73139369 happens_daily_at (time) 1556621280000 = false (1ms)|
|+326ms|║║Condition #24 evaluated false (6ms)|
|+328ms|║║Cancelling statement #24’s schedules…|
|+335ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 6:48:00 AM EDT|
|+338ms|║║Condition group #23 evaluated false (state did not change) (19ms)|
|+346ms|║╚Execution stage complete. (184ms)|
|+349ms|║Setting up scheduled job for Tue, Apr 30 2019 @ 11:00:00 PM EDT (in 9660.603s), with 4 more jobs pending|
|+359ms|╚Event processed successfully (358ms)|
|4/30/2019, 7:08:58 AM +46ms|
|+1ms|╔Received event [Home].time = 1556622539372 with a delay of -1326ms|
|+97ms|║RunTime Analysis CS > 17ms > PS > 44ms > PE > 35ms > CE|
|+99ms|║Runtime (41313 bytes) successfully initialized in 44ms (v0.3.10a.20190223) (97ms)|
|+101ms|║╔Execution stage started|
|+157ms|║║Skipped execution of physical command [Back Door].lock([]) because it would make no change to the device. (3ms)|
|+158ms|║║Executed [Back Door].lock (7ms)|
|+166ms|║║Skipped execution of physical command [Front Door].lock([]) because it would make no change to the device. (4ms)|
|+167ms|║║Executed [Front Door].lock (7ms)|
|+175ms|║║Skipped execution of physical command [Garage Door].lock([]) because it would make no change to the device. (4ms)|
|+176ms|║║Executed [Garage Door].lock (7ms)|
|+208ms|║║Comparison (time) 25738227 happens_daily_at (time) 1556621280000 = false (1ms)|
|+210ms|║║Condition #24 evaluated false (28ms)|
|+223ms|║║Cancelling statement #24’s schedules…|
|+234ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 6:48:00 AM EDT|
|+238ms|║║Condition group #23 evaluated false (state did not change) (58ms)|
|+253ms|║╚Execution stage complete. (153ms)|
|+258ms|║Setting up scheduled job for Tue, Apr 30 2019 @ 8:19:00 PM EDT (in 47401.697s), with 4 more jobs pending|
|+270ms|╚Event processed successfully (269ms)|
|4/30/2019, 6:48:59 AM +84ms|
|+1ms|╔Received event [Home].time = 1556621340000 with a delay of -917ms|
|+115ms|║RunTime Analysis CS > 28ms > PS > 48ms > PE > 39ms > CE|
|+117ms|║Runtime (41316 bytes) successfully initialized in 48ms (v0.3.10a.20190223) (115ms)|
|+119ms|║╔Execution stage started|
|+161ms|║║Comparison (time) 24539212 happens_daily_at (time) 1556669940000 = false (0ms)|
|+163ms|║║Condition #2 evaluated false (35ms)|
|+167ms|║║Cancelling statement #2’s schedules…|
|+174ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 8:19:00 PM EDT|
|+177ms|║║Condition group #1 evaluated false (state did not change) (50ms)|
|+183ms|║║Comparison (time) 24539263 happens_daily_at (time) 1556669940000 = false (1ms)|
|+186ms|║║Condition #5 evaluated false (6ms)|
|+193ms|║║Cancelling statement #5’s schedules…|
|+200ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 8:19:00 PM EDT|
|+204ms|║║Condition group #4 evaluated false (state did not change) (25ms)|
|+213ms|║║Comparison (time) 24539293 happens_daily_at (time) 82800000 = false (1ms)|
|+215ms|║║Condition #11 evaluated false (6ms)|
|+217ms|║║Cancelling statement #11’s schedules…|
|+221ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 11:00:00 PM EDT|
|+225ms|║║Condition group #10 evaluated false (state did not change) (17ms)|
|+232ms|║║Comparison (time) 24539313 happens_daily_at (time) 0 = false (0ms)|
|+234ms|║║Cancelling condition #15’s schedules…|
|+235ms|║║Condition #15 evaluated false (7ms)|
|+237ms|║║Cancelling statement #15’s schedules…|
|+241ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 12:00:00 AM EDT|
|+245ms|║║Cancelling condition #14’s schedules…|
|+246ms|║║Condition group #14 evaluated false (state changed) (18ms)|
|+265ms|║║Comparison (time) 24539335 is_between (time) 600000 … (time) 25200000 = true (11ms)|
|+267ms|║║Time restriction check passed|
|+269ms|║║Cancelling condition #19’s schedules…|
|+270ms|║║Condition #19 evaluated true (20ms)|
|+272ms|║║Cancelling condition #18’s schedules…|
|+273ms|║║Condition group #18 evaluated true (state changed) (23ms)|
|+278ms|║║Cancelling statement #20’s schedules…|
|+285ms|║║Executed virtual command [Back Door, Front Door, Garage Door].wait (1ms)|
|+287ms|║║Requesting a wake up for Tue, Apr 30 2019 @ 7:08:59 AM EDT (in 1200.0s)|
|+297ms|║╚Execution stage complete. (179ms)|
|+301ms|║Setting up scheduled job for Tue, Apr 30 2019 @ 7:08:59 AM EDT (in 1199.988s), with 4 more jobs pending|
|+310ms|╚Event processed successfully (310ms)|
|4/29/2019, 11:59:59 PM +78ms|
|+1ms|╔Received event [Home].time = 1556596800000 with a delay of -923ms|
|+167ms|║RunTime Analysis CS > 27ms > PS > 75ms > PE > 65ms > CE|
|+170ms|║Runtime (41316 bytes) successfully initialized in 75ms (v0.3.10a.20190223) (168ms)|
|+172ms|║╔Execution stage started|
|+237ms|║║Comparison (time) 86399263 happens_daily_at (time) 1556583480000 = false (2ms)|
|+241ms|║║Condition #2 evaluated false (55ms)|
|+250ms|║║Cancelling statement #2’s schedules…|
|+263ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 8:18:00 PM EDT|
|+269ms|║║Condition group #1 evaluated false (state did not change) (85ms)|
|+279ms|║║Comparison (time) 86399350 happens_daily_at (time) 1556583480000 = false (1ms)|
|+282ms|║║Condition #5 evaluated false (10ms)|
|+292ms|║║Cancelling statement #5’s schedules…|
|+307ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 8:18:00 PM EDT|
|+313ms|║║Condition group #4 evaluated false (state did not change) (41ms)|
|+325ms|║║Comparison (time) 86399397 happens_daily_at (time) 82800000 = false (1ms)|
|+460ms|║║Cancelling condition #11’s schedules…|
|+463ms|║║Condition #11 evaluated false (143ms)|
|+466ms|║║Cancelling statement #11’s schedules…|
|+473ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 11:00:00 PM EDT|
|+478ms|║║Cancelling condition #10’s schedules…|
|+479ms|║║Condition group #10 evaluated false (state changed) (161ms)|
|+490ms|║║Comparison (time) 86399563 happens_daily_at (time) 0 = true (1ms)|
|+494ms|║║Time restriction check passed|
|+497ms|║║Cancelling condition #15’s schedules…|
|+499ms|║║Condition #15 evaluated true (13ms)|
|+502ms|║║Cancelling statement #15’s schedules…|
|+511ms|║║Requesting time schedule wake up at Wed, May 1 2019 @ 12:00:00 AM EDT|
|+517ms|║║Cancelling condition #14’s schedules…|
|+519ms|║║Condition group #14 evaluated true (state changed) (34ms)|
|+524ms|║║Cancelling statement #16’s schedules…|
|+537ms|║║Skipped execution of physical command [Master Bedroom Night Lamp].off([]) because it would make no change to the device. (5ms)|
|+540ms|║║Executed [Master Bedroom Night Lamp].off (9ms)|
|+589ms|║║Comparison (time) 86399628 is_between (time) 600000 … (time) 25200000 = false (33ms)|
|+595ms|║║Condition #19 evaluated false (44ms)|
|+598ms|║║Condition group #18 evaluated false (state did not change) (48ms)|
|+618ms|║║Comparison (time) 86399686 happens_daily_at (time) 1556534940000 = false (1ms)|
|+622ms|║║Condition #24 evaluated false (15ms)|
|+626ms|║║Cancelling statement #24’s schedules…|
|+649ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 6:49:00 AM EDT|
|+653ms|║║Condition group #23 evaluated false (state did not change) (46ms)|
|+666ms|║╚Execution stage complete. (495ms)|
|+672ms|║Setting up scheduled job for Tue, Apr 30 2019 @ 6:49:00 AM EDT (in 24540.251s), with 4 more jobs pending|
|+680ms|╚Event processed successfully (681ms)|
|4/29/2019, 10:59:59 PM +64ms|
|+0ms|╔Received event [Home].time = 1556593200000 with a delay of -937ms|
|+143ms|║RunTime Analysis CS > 22ms > PS > 66ms > PE > 55ms > CE|
|+146ms|║Runtime (41316 bytes) successfully initialized in 66ms (v0.3.10a.20190223) (145ms)|
|+148ms|║╔Execution stage started|
|+226ms|║║Comparison (time) 82799227 happens_daily_at (time) 1556583480000 = false (1ms)|
|+229ms|║║Condition #2 evaluated false (65ms)|
|+231ms|║║Cancelling statement #2’s schedules…|
|+268ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 8:18:00 PM EDT|
|+274ms|║║Condition group #1 evaluated false (state did not change) (111ms)|
|+284ms|║║Comparison (time) 82799341 happens_daily_at (time) 1556583480000 = false (1ms)|
|+287ms|║║Cancelling condition #5’s schedules…|
|+289ms|║║Condition #5 evaluated false (11ms)|
|+312ms|║║Cancelling statement #5’s schedules…|
|+323ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 8:18:00 PM EDT|
|+329ms|║║Cancelling condition #4’s schedules…|
|+331ms|║║Condition group #4 evaluated false (state changed) (54ms)|
|+342ms|║║Comparison (time) 82799401 happens_daily_at (time) 82800000 = true (1ms)|
|+344ms|║║Time restriction check passed|
|+347ms|║║Cancelling condition #11’s schedules…|
|+349ms|║║Condition #11 evaluated true (12ms)|
|+351ms|║║Cancelling statement #11’s schedules…|
|+359ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 11:00:00 PM EDT|
|+365ms|║║Cancelling condition #10’s schedules…|
|+366ms|║║Condition group #10 evaluated true (state changed) (31ms)|
|+372ms|║║Cancelling statement #12’s schedules…|
|+14338ms|║║Executed physical command [Front Porch Lights].off() (13959ms)|
|+14341ms|║║Executed [Front Porch Lights].off (13963ms)|
|+14355ms|║║Comparison (time) 82813413 happens_daily_at (time) 0 = false (1ms)|
|+14358ms|║║Condition #15 evaluated false (9ms)|
|+14361ms|║║Cancelling statement #15’s schedules…|
|+14368ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 12:00:00 AM EDT|
|+14373ms|║║Condition group #14 evaluated false (state did not change) (25ms)|
|+14406ms|║║Comparison (time) 82813445 is_between (time) 600000 … (time) 25200000 = false (21ms)|
|+14410ms|║║Condition #19 evaluated false (29ms)|
|+14412ms|║║Condition group #18 evaluated false (state did not change) (32ms)|
|+14425ms|║║Comparison (time) 82813483 happens_daily_at (time) 1556534940000 = false (1ms)|
|+14429ms|║║Condition #24 evaluated false (10ms)|
|+14432ms|║║Cancelling statement #24’s schedules…|
|+14443ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 6:49:00 AM EDT|
|+14450ms|║║Condition group #23 evaluated false (state did not change) (32ms)|
|+14733ms|║╚Execution stage complete. (14586ms)|
|+14738ms|║Setting up scheduled job for Tue, Apr 30 2019 @ 12:00:00 AM EDT (in 3586.199s), with 4 more jobs pending|
|+14748ms|╚Event processed successfully (14749ms)|
|4/29/2019, 8:17:59 PM +77ms|
|+0ms|╔Received event [Home].time = 1556583480000 with a delay of -924ms|
|+185ms|║RunTime Analysis CS > 20ms > PS > 130ms > PE > 36ms > CE|
|+188ms|║Runtime (41318 bytes) successfully initialized in 130ms (v0.3.10a.20190223) (187ms)|
|+189ms|║╔Execution stage started|
|+231ms|║║Comparison (time) 73079275 happens_daily_at (time) 1556583480000 = true (0ms)|
|+232ms|║║Time restriction check passed|
|+234ms|║║Cancelling condition #2’s schedules…|
|+235ms|║║Condition #2 evaluated true (38ms)|
|+240ms|║║Cancelling statement #2’s schedules…|
|+247ms|║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 8:18:00 PM EDT|
|+260ms|║║Comparison (enum) off is (string) off = true (2ms)|
|+262ms|║║Cancelling condition #3’s schedules…|
|+263ms|║║Condition #3 evaluated true (13ms)

guxdude · 2019-05-02 07:39:13 UTC

I am not sure why you are showing no triggers for this piston.

I suggest simplifying the logic and combining things you want to happen at the same time. For example, your fist if could be:

if time happens daily at sunset
then
  if dimmer 4 is off
  then
    turn on white bulb 6, white bulb 9, and dimmer 7
  else
    turn on white bulb 6 and dimmer 7
  endif
endif

Similarly, you should combine the dimmer 7 off and locks into one if @ 12am (the range doesn’t make sense for the locks anyway)

Finally, I would remove the condition for bulb 9 being on at sunrise. If you turn off a bulb that is already off, no harm done.

WCmore · 2019-05-02 08:19:26 UTC

… and just one tiny thing to add to what @guxdude said.

It is helpful if you clear your logs before testing, or at least, only copy/paste the section that you are having issues with. Nobody wants to trudge thru 13 pages of old logs for no reason.

logeox · 2019-05-02 16:45:35 UTC

Wouldn’t it be easier to just execute a routine for time of day. Im sure you already do certain steps similar to this with your routines. Just easier in the long run in my book. I do something similar to this then we come home and it determines time of day and executes appropriate routine.

Razamo786 · 2019-05-02 17:31:52 UTC

My issue is the time comparison. See below log.

If you convert 82813483 from epoch to human readable date/time, it is Wednesday, August 16, 1972 7:44:43 AM ET.

|+14425ms|║║Comparison (time) 82813483 happens_daily_at (time) 1556534940000 = false (1ms)|

WCmore · 2019-05-02 19:22:42 UTC

With seven triggers in this piston, it’s important to remember that each time any one of them fires, the entire piston will run top to bottom, executing anything that is allowed by conditions.

In the case you mentioned, it executed at 11PM, and turned on “White Bulb 6” as instructed. The ‘false’ that you see here is the time check found on line 65.

Condensed Log:
|4/29/2019, 10:59:59 PM
╔Received event [Home].time = 1556593200000
║║Condition group #10 evaluated true (state changed)
║║Executed physical command [Front Porch Lights].off()
║║Comparison (time) 82813483 happens_daily_at (time) 1556534940000 = false
║║Requesting time schedule wake up at Tue, Apr 30 2019 @ 6:49:00 AM EDT|

(IE: 11PM is not sunrise, so it is false, and a schedule is set for the real sunrise)

Pro Tip:
This is one example of why I try to keep each piston to a single trigger (when possible). Your piston might look “pretty” to the eye, but it makes SmartThings & webCoRE go thru tons of extra logic each time anything unrelated changes.

For example, I have one piston devoted to doing a bunch of things at sunset. Another piston handles sunrise. Yet another handles nighttime, etc

ike2018 · 2019-05-03 00:08:03 UTC

How about the conditions or triggers that are not allowed? Are they still congesting the proccess

WCmore · 2019-05-03 01:18:13 UTC

If you feel adventurous, take a look at their 13 pages of logs.
Look at how much logic transpires at each timed event.
(webCoRE still has to analyze & decide whether to execute each block)