1) Give a description of the problem
Piston is set to trigger every 15 minutes but is scheduled somewhere 13 hours away when it triggers.
Update: Reading the logs again (takes some time to absorb all that data), it seems the piston actually fired every 15 minutes today, but it’s only switching on the airco once per day. Once it’s been switched off, it will not come on again until the next day. Maybe the scheduled time in the second screenshot is misleading and I have another issue?
2) What is the expected behavior?
Between 08:00 and 22:00, I expected the piston to fire and reschedule itself every 15 minutes.
3) What is happening/not happening?
Even within the set timeframe, the piston will fire (usually once) and then reschedule itself top many hours into the future. In the screenshot, it rescheduled for 13 hours and 15 minutes.
**4) Post a Green Snapshot of the piston!
5) Attach any logs (From ST IDE and by turning logging level to Full)
(7/12/2018, 5:57:23 PM +59ms
+1ms ╔Received event [BrinkHome].time = 1531411043685 with a delay of -626ms
+95ms ║RunTime Analysis CS > 19ms > PS > 32ms > PE > 44ms > CE
+98ms ║Runtime (37889 bytes) successfully initialized in 32ms (v0.3.105.20180628) (95ms)
+99ms ║╔Execution stage started
+129ms ║║Comparison (decimal) 20.9 is_greater_than (integer) 21 = false (6ms)
+130ms ║║Cancelling condition #6’s schedules…
+131ms ║║Condition #6 evaluated false (14ms)
+132ms ║║Cancelling condition #2’s schedules…
+133ms ║║Condition group #2 evaluated false (state changed) (16ms)
+136ms ║╚Execution stage complete. (38ms)
+138ms ║Setting up scheduled job for Thu, Jul 12 2018 @ 10:12:23 PM PDT (in 47700.489s)
+144ms ╚Event processed successfully (144ms)
7/12/2018, 5:42:22 PM +39ms
+1ms ╔Received event [BrinkHome].time = 1531410143685 with a delay of -1647ms
+93ms ║RunTime Analysis CS > 14ms > PS > 37ms > PE > 43ms > CE
+95ms ║Runtime (37890 bytes) successfully initialized in 37ms (v0.3.105.20180628) (93ms)
+96ms ║╔Execution stage started
+114ms ║║Comparison (decimal) 21.5 is_greater_than (integer) 21 = true (1ms)
+116ms ║║Condition #6 evaluated true (10ms)
+123ms ║║Comparison (enum) closed is_not (string) open = true (2ms)
+124ms ║║Condition #7 evaluated true (8ms)
+128ms ║║Comparison (string) :a329bf118453b170455e81d02f8ded5a: is (string) :a329bf118453b170455e81d02f8ded5a: = true (2ms)
+129ms ║║Condition #8 evaluated true (4ms)
+130ms ║║Condition group #2 evaluated true (state did not change) (24ms)
+132ms ║║Cancelling statement #3’s schedules…
+1515ms ║║Executed physical command [Airco living room].setCoolingSetpoint([20.0]) (1379ms)
+1516ms ║║Executed [Airco living room].setCoolingSetpoint (1381ms)
+1521ms ║║Skipped execution of physical command [Airco living room].cool([]) because it would make no change to the device. (3ms)
+1522ms ║║Executed [Airco living room].cool (4ms)
+1525ms ║╚Execution stage complete. (1428ms)
+1526ms ║Setting up scheduled job for Thu, Jul 12 2018 @ 8:57:23 AM PDT (in 900.121s)
+1535ms ╚Event processed successfully (1535ms)
7/12/2018, 5:27:22 PM +49ms
+0ms ╔Received event [BrinkHome].time = 1531409243685 with a delay of -1637ms
+104ms ║RunTime Analysis CS > 16ms > PS > 42ms > PE > 47ms > CE
+107ms ║Runtime (37891 bytes) successfully initialized in 42ms (v0.3.105.20180628) (105ms)
+108ms ║╔Execution stage started
+133ms ║║Comparison (decimal) 22.7 is_greater_than (integer) 21 = true (6ms)
+135ms ║║Condition #6 evaluated true (16ms)
+148ms ║║Comparison (enum) closed is_not (string) open = true (5ms)
+149ms ║║Condition #7 evaluated true (13ms)
+153ms ║║Comparison (string) :a329bf118453b170455e81d02f8ded5a: is (string) :a329bf118453b170455e81d02f8ded5a: = true (1ms)
+155ms ║║Condition #8 evaluated true (5ms)
+156ms ║║Condition group #2 evaluated true (state did not change) (37ms)
+158ms ║║Cancelling statement #3’s schedules…
+1852ms ║║Executed physical command [Airco living room].setCoolingSetpoint([20.0]) (1690ms)
+1853ms ║║Executed [Airco living room].setCoolingSetpoint (1691ms)
+1860ms ║║Skipped execution of physical command [Airco living room].cool([]) because it would make no change to the device. (5ms)
+1861ms ║║Executed [Airco living room].cool (7ms)
+1864ms ║╚Execution stage complete. (1757ms)
+1866ms ║Setting up scheduled job for Thu, Jul 12 2018 @ 8:42:23 AM PDT (in 899.771s)
+1875ms ╚Event processed successfully (1875ms)
7/12/2018, 5:12:23 PM +36ms
+0ms ╔Received event [BrinkHome].time = 1531408343685 with a delay of -650ms
+90ms ║RunTime Analysis CS > 16ms > PS > 35ms > PE > 39ms > CE
+92ms ║Runtime (37889 bytes) successfully initialized in 35ms (v0.3.105.20180628) (91ms)
+93ms ║╔Execution stage started
+112ms ║║Comparison (decimal) 23.7 is_greater_than (integer) 21 = true (2ms)
+113ms ║║Condition #6 evaluated true (9ms)
+122ms ║║Comparison (enum) closed is_not (string) open = true (1ms)
+123ms ║║Cancelling condition #7’s schedules…
+124ms ║║Condition #7 evaluated true (10ms)
+255ms ║║Comparison (string) :a329bf118453b170455e81d02f8ded5a: is (string) :a329bf118453b170455e81d02f8ded5a: = true (128ms)
+257ms ║║Condition #8 evaluated true (132ms)
+258ms ║║Cancelling condition #2’s schedules…
+258ms ║║Condition group #2 evaluated true (state changed) (154ms)
+261ms ║║Cancelling statement #3’s schedules…
+1840ms ║║Executed physical command [Airco living room].setCoolingSetpoint([20.0]) (1576ms)
+1841ms ║║Executed [Airco living room].setCoolingSetpoint (1577ms)
+1845ms ║║Skipped execution of physical command [Airco living room].cool([]) because it would make no change to the device. (2ms)
+1846ms ║║Executed [Airco living room].cool (4ms)
+1850ms ║╚Execution stage complete. (1756ms)
+1851ms ║Setting up scheduled job for Thu, Jul 12 2018 @ 8:27:23 AM PDT (in 898.799s)
+1860ms ╚Event processed successfully (1860ms)
7/12/2018, 7:57:23 AM +51ms
+1ms ╔Received event [BrinkHome].time = 1531375043685 with a delay of -634ms
+101ms ║RunTime Analysis CS > 18ms > PS > 48ms > PE > 35ms > CE
+104ms ║Runtime (37890 bytes) successfully initialized in 48ms (v0.3.105.20180628) (101ms)
+105ms ║╔Execution stage started
+166ms ║║Comparison (decimal) 21.5 is_greater_than (integer) 21 = true (6ms)
+167ms ║║Condition #6 evaluated true (14ms)
+178ms ║║Comparison (enum) open is_not (string) open = false (4ms)
+179ms ║║Condition #7 evaluated false (11ms)
+180ms ║║Condition group #2 evaluated false (state did not change) (28ms)
+183ms ║╚Execution stage complete. (78ms)
+184ms ║Setting up scheduled job for Thu, Jul 12 2018 @ 8:12:23 AM PDT (in 33300.451s)
+191ms ╚Event processed successfully (191ms)
7/12/2018, 7:42:23 AM +44ms
+1ms ╔Received event [BrinkHome].time = 1531374143685 with a delay of -641ms
+79ms ║RunTime Analysis CS > 16ms > PS > 30ms > PE > 33ms > CE
+81ms ║Runtime (37889 bytes) successfully initialized in 30ms (v0.3.105.20180628) (79ms)
+82ms ║╔Execution stage started
+106ms ║║Comparison (decimal) 21.4 is_greater_than (integer) 21 = true (7ms)
+107ms ║║Condition #6 evaluated true (14ms)
+118ms ║║Comparison (enum) open is_not (string) open = false (5ms)
+120ms ║║Condition #7 evaluated false (11ms)
+121ms ║║Condition group #2 evaluated false (state did not change) (29ms)
+124ms ║╚Execution stage complete. (42ms)
+125ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 10:57:23 PM PDT (in 900.516s)
+132ms ╚Event processed successfully (132ms)
7/12/2018, 7:27:23 AM +54ms
+1ms ╔Received event [BrinkHome].time = 1531373243685 with a delay of -632ms
+130ms ║RunTime Analysis CS > 22ms > PS > 50ms > PE > 58ms > CE
+133ms ║Runtime (37890 bytes) successfully initialized in 50ms (v0.3.105.20180628) (131ms)
+135ms ║╔Execution stage started
+164ms ║║Comparison (decimal) 21.9 is_greater_than (integer) 21 = true (6ms)
+166ms ║║Condition #6 evaluated true (15ms)
+179ms ║║Comparison (enum) open is_not (string) open = false (6ms)
+181ms ║║Cancelling condition #7’s schedules…
+182ms ║║Condition #7 evaluated false (15ms)
+184ms ║║Cancelling condition #2’s schedules…
+185ms ║║Condition group #2 evaluated false (state changed) (33ms)
+189ms ║╚Execution stage complete. (55ms)
+191ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 10:42:23 PM PDT (in 900.441s)
+199ms ╚Event processed successfully (199ms)
7/12/2018, 7:12:23 AM +34ms
+1ms ╔Received event [BrinkHome].time = 1531372343685 with a delay of -651ms
+102ms ║RunTime Analysis CS > 17ms > PS > 40ms > PE > 45ms > CE
+105ms ║Runtime (37890 bytes) successfully initialized in 40ms (v0.3.105.20180628) (103ms)
+107ms ║╔Execution stage started
+133ms ║║Comparison (decimal) 22.4 is_greater_than (integer) 21 = true (7ms)
+135ms ║║Condition #6 evaluated true (17ms)
+148ms ║║Comparison (enum) closed is_not (string) open = true (6ms)
+150ms ║║Cancelling condition #7’s schedules…
+151ms ║║Condition #7 evaluated true (15ms)
+157ms ║║Comparison (string) :a329bf118453b170455e81d02f8ded5a: is (string) :a329bf118453b170455e81d02f8ded5a: = true (2ms)
+158ms ║║Condition #8 evaluated true (6ms)
+159ms ║║Cancelling condition #2’s schedules…
+161ms ║║Condition group #2 evaluated true (state changed) (42ms)
+163ms ║║Cancelling statement #3’s schedules…
+1440ms ║║Executed physical command [Airco living room].setCoolingSetpoint([20.0]) (1273ms)
+1441ms ║║Executed [Airco living room].setCoolingSetpoint (1275ms)
+1445ms ║║Skipped execution of physical command [Airco living room].cool([]) because it would make no change to the device. (2ms)
+1446ms ║║Executed [Airco living room].cool (4ms)
+1449ms ║╚Execution stage complete. (1343ms)
+1451ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 10:27:23 PM PDT (in 899.201s)
+1459ms ╚Event processed successfully (1458ms)
7/11/2018, 10:16:50 PM +234ms
+0ms ╔Received event [BrinkHome].test = 1531340210234 with a delay of 0ms
+86ms ║RunTime Analysis CS > 15ms > PS > 39ms > PE > 32ms > CE
+88ms ║Runtime (37886 bytes) successfully initialized in 39ms (v0.3.105.20180628) (87ms)
+89ms ║╔Execution stage started
+111ms ║╚Execution stage complete. (22ms)
+118ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 10:12:23 PM PDT (in 32133.337s)
+129ms ╚Event processed successfully (129ms)
7/11/2018, 5:57:23 PM +52ms
+1ms ╔Received event [BrinkHome].time = 1531324643685 with a delay of -633ms
+232ms ║RunTime Analysis CS > 13ms > PS > 38ms > PE > 180ms > CE
+235ms ║Runtime (37891 bytes) successfully initialized in 38ms (v0.3.105.20180628) (233ms)
+236ms ║╔Execution stage started
+269ms ║║Comparison (decimal) 23.5 is_greater_than (integer) 21 = true (1ms)
+270ms ║║Condition #6 evaluated true (10ms)
+282ms ║║Comparison (enum) open is_not (string) open = false (5ms)
+283ms ║║Condition #7 evaluated false (12ms)
+285ms ║║Condition group #2 evaluated false (state did not change) (26ms)
+288ms ║╚Execution stage complete. (53ms)
+290ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 10:12:23 PM PDT (in 47700.343s)
+298ms ╚Event processed successfully (298ms)
7/11/2018, 5:42:23 PM +51ms
+0ms ╔Received event [BrinkHome].time = 1531323743685 with a delay of -635ms
+107ms ║RunTime Analysis CS > 30ms > PS > 44ms > PE > 33ms > CE
+109ms ║Runtime (37890 bytes) successfully initialized in 44ms (v0.3.105.20180628) (108ms)
+110ms ║╔Execution stage started
+136ms ║║Comparison (decimal) 23.5 is_greater_than (integer) 21 = true (1ms)
+137ms ║║Condition #6 evaluated true (11ms)
+146ms ║║Comparison (enum) open is_not (string) open = false (1ms)
+147ms ║║Condition #7 evaluated false (9ms)
+148ms ║║Condition group #2 evaluated false (state did not change) (23ms)
+152ms ║╚Execution stage complete. (42ms)
+154ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 8:57:23 AM PDT (in 900.481s)
+165ms ╚Event processed successfully (165ms)
7/11/2018, 5:27:23 PM +39ms
+1ms ╔Received event [BrinkHome].time = 1531322843685 with a delay of -646ms
+66ms ║RunTime Analysis CS > 13ms > PS > 28ms > PE > 24ms > CE
+68ms ║Runtime (37889 bytes) successfully initialized in 28ms (v0.3.105.20180628) (67ms)
+69ms ║╔Execution stage started
+87ms ║║Comparison (decimal) 23.5 is_greater_than (integer) 21 = true (2ms)
+89ms ║║Condition #6 evaluated true (8ms)
+413ms ║║Comparison (enum) open is_not (string) open = false (2ms)
+414ms ║║Condition #7 evaluated false (325ms)
+416ms ║║Condition group #2 evaluated false (state did not change) (336ms)
+418ms ║╚Execution stage complete. (349ms)
+420ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 8:42:23 AM PDT (in 900.227s)
+428ms ╚Event processed successfully (428ms)
7/11/2018, 5:12:22 PM +33ms
+0ms ╔Received event [BrinkHome].time = 1531321943685 with a delay of -1653ms
+82ms ║RunTime Analysis CS > 16ms > PS > 39ms > PE > 27ms > CE
+84ms ║Runtime (37890 bytes) successfully initialized in 39ms (v0.3.105.20180628) (83ms)
+85ms ║╔Execution stage started
+102ms ║║Comparison (decimal) 23.6 is_greater_than (integer) 21 = true (1ms)
+104ms ║║Condition #6 evaluated true (9ms)
+111ms ║║Comparison (enum) open is_not (string) open = false (1ms)
+112ms ║║Condition #7 evaluated false (8ms)
+113ms ║║Condition group #2 evaluated false (state did not change) (18ms)
+116ms ║╚Execution stage complete. (31ms)
+117ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 8:27:23 AM PDT (in 901.535s)
+125ms ╚Event processed successfully (125ms)
7/11/2018, 3:12:23 PM +258ms
+3ms ╔Starting piston… (v0.3.105.20180628)
+334ms ║╔Subscribing to devices…
+394ms ║║Subscribing to Airco living room…
+395ms ║║Subscribing to Sliding doors…
+395ms ║╚Finished subscribing (67ms)
+485ms ║Comparison (decimal) 23.2 is_greater_than (integer) 21 = true (4ms)
+494ms ║Comparison (enum) open is_not (string) open = false (3ms)
+499ms ║Comparison (string) :a329bf118453b170455e81d02f8ded5a: is (string) :a329bf118453b170455e81d02f8ded5a: = true (1ms)
+513ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 8:12:23 AM PDT (in 7199.919s)
+524ms ╚Piston successfully started (523ms)
7/11/2018, 3:12:21 PM +182ms
+79ms ╔Stopping piston…
+151ms ╚Piston successfully stopped (74ms)
7/11/2018, 8:16:19 AM +806ms
+1ms ╔Received event [BrinkHome].execute = 82.95.99.6 with a delay of 38ms
+68ms ║RunTime Analysis CS > 20ms > PS > 25ms > PE > 23ms > CE
+70ms ║Runtime (37887 bytes) successfully initialized in 25ms (v0.3.105.20180628) (69ms)
+71ms ║╔Execution stage started
+77ms ║╚Execution stage complete. (6ms)
+78ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 8:08:26 AM PDT (in 31926.295s)
+88ms ╚Event processed successfully (88ms)
7/11/2018, 7:53:25 AM +865ms
+1ms ╔Starting piston… (v0.3.105.20180628)
+240ms ║╔Subscribing to devices…
+287ms ║║Subscribing to Airco living room…
+288ms ║║Subscribing to Sliding doors…
+288ms ║╚Finished subscribing (56ms)
+348ms ║Comparison (decimal) 21.9 is_greater_than (integer) 21 = true (2ms)
+359ms ║Comparison (enum) open is_not (string) open = false (5ms)
+365ms ║Comparison (string) :a329bf118453b170455e81d02f8ded5a: is (string) :a329bf118453b170455e81d02f8ded5a: = true (1ms)
+378ms ║Setting up scheduled job for Wed, Jul 11 2018 @ 8:08:26 AM PDT (in 33299.94s)
+392ms ╚Piston successfully started (391ms)
7/11/2018, 7:40:51 AM +37ms
+1ms ╔Received event [BrinkHome].time = 1531287652057 with a delay of -1020ms
+76ms ║RunTime Analysis CS > 20ms > PS > 33ms > PE > 22ms > CE
+78ms ║Runtime (37894 bytes) successfully initialized in 33ms (v0.3.105.20180628) (75ms)
+79ms ║╔Execution stage started
+100ms ║║Comparison (decimal) 21.4 is_greater_than (integer) 21 = true (2ms)
+102ms ║║Condition #6 evaluated true (9ms)
+110ms ║║Comparison (enum) open is (string) closed = false (1ms)
+111ms ║║Condition #7 evaluated false (9ms)
+112ms ║║Condition group #2 evaluated false (state did not change) (21ms)
+115ms ║╚Execution stage complete. (36ms)
+117ms ║Setting up scheduled job for Tue, Jul 10 2018 @ 10:55:52 PM PDT (in 900.904s)
+124ms ╚Event processed successfully (124ms)
7/11/2018, 7:25:51 AM +45ms
+1ms ╔Received event [BrinkHome].time = 1531286752057 with a delay of -1013ms
+70ms ║RunTime Analysis CS > 17ms > PS > 36ms > PE > 17ms > CE
+72ms ║Runtime (37894 bytes) successfully initialized in 36ms (v0.3.105.20180628) (70ms)
+73ms ║╔Execution stage started
+94ms ║║Comparison (decimal) 21.5 is_greater_than (integer) 21 = true (2ms)
+96ms ║║Condition #6 evaluated true (12ms)
+106ms ║║Comparison (enum) open is (string) closed = false (2ms)
+108ms ║║Condition #7 evaluated false (11ms)
+109ms ║║Condition group #2 evaluated false (state did not change) (25ms)
+113ms ║╚Execution stage complete. (40ms)
+116ms ║Setting up scheduled job for Tue, Jul 10 2018 @ 10:40:52 PM PDT (in 900.897s)
+124ms ╚Event processed successfully (124ms)
7/11/2018, 7:10:51 AM +40ms
+1ms ╔Received event [BrinkHome].time = 1531285852057 with a delay of -1017ms
+91ms ║RunTime Analysis CS > 18ms > PS > 46ms > PE > 27ms > CE
+94ms ║Runtime (37894 bytes) successfully initialized in 46ms (v0.3.105.20180628) (92ms)
+96ms ║╔Execution stage started
+122ms ║║Comparison (decimal) 21.9 is_greater_than (integer) 21 = true (2ms)
+124ms ║║Condition #6 evaluated true (12ms)
+133ms ║║Comparison (enum) open is (string) closed = false (2ms)
+135ms ║║Condition #7 evaluated false (11ms)
+137ms ║║Condition group #2 evaluated false (state did not change) (25ms)
+141ms ║╚Execution stage complete. (45ms)
+143ms ║Setting up scheduled job for Tue, Jul 10 2018 @ 10:25:52 PM PDT (in 900.875s)
+151ms ╚Event processed successfully (151ms)
7/10/2018, 8:52:01 PM +668ms
+0ms ╔Received event [BrinkHome].test = 1531248721666 with a delay of 1ms
+67ms ║RunTime Analysis CS > 16ms > PS > 34ms > PE > 18ms > CE
+71ms ║Runtime (37890 bytes) successfully initialized in 34ms (v0.3.105.20180628) (69ms)
+72ms ║╔Execution stage started
+81ms ║╚Execution stage complete. (10ms)
+84ms ║Setting up scheduled job for Tue, Jul 10 2018 @ 10:10:52 PM PDT (in 37130.306s)
+94ms ╚Event processed successfully (95ms)
7/10/2018, 7:11:43 PM +954ms
+0ms ╔Received event [BrinkHome].test = 1531242703954 with a delay of 1ms
+310ms ║RunTime Analysis CS > 9ms > PS > 288ms > PE > 13ms > CE
+313ms ║Runtime (37892 bytes) successfully initialized in 288ms (v0.3.105.20180628) (311ms)
+313ms ║╔Execution stage started
+379ms ║╚Execution stage complete. (66ms)
+390ms ║Setting up scheduled job for Tue, Jul 10 2018 @ 10:10:52 PM PDT (in 43147.714s)
+400ms ╚Event processed successfully (400ms)
7/10/2018, 7:11:29 PM +412ms
+0ms ╔Received event [BrinkHome].test = 1531242689410 with a delay of 1ms
+71ms ║Runtime (37809 bytes) successfully initialized in 42ms (v0.3.105.20180628) (70ms)
+72ms ║╔Execution stage started
+77ms ║╚Execution stage complete. (6ms)
+82ms ║Setting up scheduled job for Tue, Jul 10 2018 @ 10:10:52 PM PDT (in 43162.567s)
+167ms ╚Event processed successfully (167ms))