Routine used as piston trigger "stuck on", along with broken timer?

alex8687 · 2018-10-20 20:48:07 UTC

1) Give a description of the problem

EDIT: My hourly timer trigger isn’t working either. Am I missing something simple?

After triggering the piston by executing ‘Weather Light’ routine (line 49), the piston condition stays “triggered” (for lack of a better term) with the green track bar next to it, preventing action starting on line 58 from running.

2) What is the expected behavior?
After triggering piston via executing the Weather Light routine, that condition should go back to a “ready” state (similar to the state after running ‘test’) and execute action starting on line 58 successfully with further triggers of the routine.

3) What is happening/not happening?
After triggering the piston via ‘Weather Light’ routine execution for the first time (after initializing with a ‘test’), the routine condition stays active (lines 48-51 - green bar stays next to it when shown with trace mode on), and will not trigger action starting on line 58 if the routine is executed again. If i click ‘test’ the routine condition will revert back to the normal waiting state and work on the next routine execution, before experiencing the same problem again.

4) Post a Green Snapshot of the piston

Left picture is piston state after “initializing with test” and how I would expect the routine to be waiting normally. Right picture is resulting perpetual piston state after executing routine on line 49 once.

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

The bottom two log events are from the routine triggering the piston successfully, the top log event is output from when I try to execute the piston a second time (and the main action of the piston starting on line 57 does not execute).

10/20/2018, 3:36:34 PM +480ms
+0ms ╔Received event [Home].routineExecuted = 634225fe-6eac-4953-859a-b865150f5ac7 with a delay of 54ms
+234ms ║RunTime Analysis CS &gt; 13ms &gt; PS &gt; 184ms &gt; PE &gt; 37ms &gt; CE
+237ms ║Runtime (53143 bytes) successfully initialized in 184ms (v0.3.108.20180906) (235ms)
+238ms ║╔Execution stage started
+248ms ║║Comparison (time) 56194725 happens_daily_at (time) 23400000 = false (0ms)
+250ms ║║Condition #4 evaluated false (5ms)
+251ms ║║Cancelling statement #4's schedules...
+256ms ║║Requesting time schedule wake up at Sun, Oct 21 2018 @ 6:30:00 AM CDT
+259ms ║║Condition group #1 evaluated false (state did not change) (15ms)
+264ms ║║Comparison (time) 56194741 happens_daily_at (time) 78300000 = false (1ms)
+266ms ║║Condition #6 evaluated false (5ms)
+267ms ║║Cancelling statement #6's schedules...
+272ms ║║Requesting time schedule wake up at Sat, Oct 20 2018 @ 9:45:00 PM CDT
+275ms ║║Condition group #2 evaluated false (state did not change) (15ms)
+281ms ║║Comparison (string) :dc3b53b93ccb2b2af0734a55c4b5c398: executes (string) :dc3b53b93ccb2b2af0734a55c4b5c398: = true (2ms)
+283ms ║║Condition #12 evaluated true (7ms)
+289ms ║║Comparison (string) :691a30baff34257871633a9c92d96b69: is_not (string) :72f51ed3e81a5746a6681fa6795b63dd: = true (2ms)
+291ms ║║Condition #13 evaluated true (7ms)
+293ms ║║Condition group #3 evaluated true (state did not change) (16ms)
+296ms ║║Cancelling statement #14's schedules...
+489ms ║║Executed virtual command setVariable (3ms)
+495ms ║║Executed virtual command setVariable (3ms)
+501ms ║║Executed virtual command setVariable (1ms)
+509ms ║║Comparison (boolean) true changes_to (boolean) true = false (0ms)
+511ms ║║Cancelling condition #56's schedules...
+512ms ║║Condition #56 evaluated false (7ms)
+513ms ║║Cancelling condition #27's schedules...
+514ms ║║Condition group #27 evaluated false (state changed) (10ms)
+525ms ║║Condition group #47 evaluated true (state did not change) (1ms)
+531ms ║╚Execution stage complete. (293ms)
+533ms ║Setting up scheduled job for Sat, Oct 20 2018 @ 4:00:00 PM CDT (in 1404.988s), with 2 more jobs pending
+551ms ╚Event processed successfully (552ms)
10/20/2018, 3:36:20 PM +175ms
+1ms ╔Received event [Home].time = 1540067781209 with a delay of -1035ms
+242ms ║RunTime Analysis CS &gt; 66ms &gt; PS &gt; 129ms &gt; PE &gt; 47ms &gt; CE
+246ms ║Runtime (53112 bytes) successfully initialized in 129ms (v0.3.108.20180906) (243ms)
+247ms ║╔Execution stage started
+329ms ║║Restoring attribute 'hue' to value '33.0' using command setHue(33.0)
+342ms ║║Executed physical command [Computer Light].setHue([33.0]) (12ms)
+360ms ║║Restoring attribute 'level' to value '100' using command setLevel(100)
+371ms ║║Executed physical command [Computer Light].setLevel([100]) (9ms)
+388ms ║║Restoring attribute 'saturation' to value '100' using command setSaturation(100)
+397ms ║║Executed physical command [Computer Light].setSaturation([100]) (7ms)
+398ms ║║Executed virtual command [Computer Light].loadStateLocally (87ms)
+403ms ║║Cancelling statement #53's schedules...
+409ms ║║Executed virtual command setVariable (1ms)
+608ms ║╚Execution stage complete. (362ms)
+612ms ║Setting up scheduled job for Sat, Oct 20 2018 @ 4:00:00 PM CDT (in 1419.214s), with 2 more jobs pending
+623ms ╚Event processed successfully (622ms)
10/20/2018, 3:36:15 PM +516ms
+1ms ╔Received event [Home].routineExecuted = 634225fe-6eac-4953-859a-b865150f5ac7 with a delay of 53ms
+131ms ║RunTime Analysis CS &gt; 15ms &gt; PS &gt; 76ms &gt; PE &gt; 39ms &gt; CE
+134ms ║Runtime (53116 bytes) successfully initialized in 76ms (v0.3.108.20180906) (132ms)
+135ms ║╔Execution stage started
+146ms ║║Comparison (time) 56175659 happens_daily_at (time) 23400000 = false (0ms)
+148ms ║║Condition #4 evaluated false (6ms)
+149ms ║║Cancelling statement #4's schedules...
+154ms ║║Requesting time schedule wake up at Sun, Oct 21 2018 @ 6:30:00 AM CDT
+157ms ║║Condition group #1 evaluated false (state did not change) (15ms)
+162ms ║║Comparison (time) 56175675 happens_daily_at (time) 78300000 = false (1ms)
+164ms ║║Condition #6 evaluated false (5ms)
+165ms ║║Cancelling statement #6's schedules...
+170ms ║║Requesting time schedule wake up at Sat, Oct 20 2018 @ 9:45:00 PM CDT
+173ms ║║Condition group #2 evaluated false (state did not change) (15ms)
+180ms ║║Comparison (string) :dc3b53b93ccb2b2af0734a55c4b5c398: executes (string) :dc3b53b93ccb2b2af0734a55c4b5c398: = true (2ms)
+182ms ║║Cancelling condition #12's schedules...
+183ms ║║Condition #12 evaluated true (8ms)
+190ms ║║Comparison (string) :691a30baff34257871633a9c92d96b69: is_not (string) :72f51ed3e81a5746a6681fa6795b63dd: = true (2ms)
+192ms ║║Condition #13 evaluated true (7ms)
+193ms ║║Cancelling condition #3's schedules...
+194ms ║║Condition group #3 evaluated true (state changed) (20ms)
+197ms ║║Cancelling statement #14's schedules...
+353ms ║║Executed virtual command setVariable (4ms)
+362ms ║║Executed virtual command setVariable (3ms)
+368ms ║║Executed virtual command setVariable (2ms)
+376ms ║║Comparison (boolean) true changes_to (boolean) true = true (1ms)
+379ms ║║Cancelling condition #56's schedules...
+380ms ║║Condition #56 evaluated true (8ms)
+381ms ║║Cancelling condition #27's schedules...
+383ms ║║Condition group #27 evaluated true (state changed) (10ms)
+395ms ║║Comparison (boolean) false is (boolean) true = false (3ms)
+397ms ║║Condition #30 evaluated false (11ms)
+398ms ║║Condition group #29 evaluated false (state did not change) (13ms)
+409ms ║║Comparison (boolean) true is (boolean) true = true (2ms)
+411ms ║║Condition #36 evaluated true (11ms)
+412ms ║║Condition group #33 evaluated true (state did not change) (13ms)
+416ms ║║Cancelling statement #37's schedules...
+423ms ║║Executed virtual command setVariable (4ms)
+428ms ║║Cancelling statement #45's schedules...
+446ms ║║Executed virtual command [Computer Light].saveStateLocally (10ms)
+451ms ║║Executed virtual command [Computer Light].wait (0ms)
+452ms ║║Waiting for 200ms
+668ms ║║Executed physical command [Computer Light].setColor([[hex: #FFA500, hue:11, saturation:100, level:50]]) (10ms)
+669ms ║║Executed [Computer Light].setColor (13ms)
+685ms ║║Executed physical command [Computer Light].setLevel([60]) (11ms)
+686ms ║║Executed [Computer Light].setLevel (13ms)
+691ms ║║Executed virtual command [Computer Light].wait (1ms)
+693ms ║║Requesting a wake up for Sat, Oct 20 2018 @ 3:36:21 PM CDT (in 5.0s)
+702ms ║╚Execution stage complete. (567ms)
+705ms ║Setting up scheduled job for Sat, Oct 20 2018 @ 3:36:21 PM CDT (in 4.989s), with 3 more jobs pending
+718ms ╚Event processed successfully (718ms)`Preformatted text`

WCmore · 2018-10-20 21:51:45 UTC

I would try changing line 59 to say:
IF {run} is true

For this to work, you’ll also need to move your final block (lines 92-98) to the very top.

alex8687 · 2018-10-21 00:46:25 UTC

This worked, the routine button now fires the main section of code reliably every time, thank you! The hourly timer section I moved to the top, however, is now experiencing the same issue the routine used to (runs once after test, then not again until test is performed again). Is there something else in my code that is causing this at a fundamental level? Thanks again for your help. From the log:

|+292ms|║╔Execution stage started|
|+311ms|║║Cancelling statement #23's schedules...|
|+592ms|║║Executed virtual command setVariable (4ms)|
|+603ms|║║Executed virtual command setVariable (4ms)|
|+613ms|║║Executed virtual command setVariable (4ms)|
|+623ms|║╚Execution stage complete. (330ms)|

It seems like when it executes the hourly block it is first cancelling the main action in the code (the 23rd statement down the list is line 58 where the “if run = true…” section begins…if I’m understanding that correctly), and then goes on to set the hourly variables. Why would it do that?

WCmore · 2018-10-21 02:45:26 UTC

Can you post a fresh green snapshot please so I can see what you have?

WCmore · 2018-10-21 03:15:09 UTC

It might be as simple as adding a new time block:

every hour at :01 past the hour
Set variable {run} = false

(Otherwise, the variable will not reset between 12am and 6am)

Ryan780 · 2018-10-21 05:00:20 UTC

You have a time variable of between 6am and 12am. That won’t work. You have to use 6am and 11:59 pm. If you only use time it assumes that all your times are in the same calendar day. 12 am is actually 0 the next day. You must be in the US too. It makes more sense when you use military time.

WCmore · 2018-10-21 06:27:52 UTC

Good eye Ryan. Spanning midnight can be tricky.
The easiest solution is changing 12am to 11:59pm, as suggested.

Although I have been known to occasionally invert the code like this:

IF Time is NOT between 12am and 6am

That works too.

Ryan780 · 2018-10-21 07:24:26 UTC

Yes, that is an alternative way of fixing the problem. There are about 12 other ways I can think of. The point is, that is one of the BIGGEST problems with the piston. Fix that first…then see what else needs to be fixed. When dealing with something that never fires, try eliminating those things which CANNOT be true. It usually helps. (since you’re such a fan of the bold text.)

WCmore · 2018-10-21 07:38:39 UTC

I am not sure how you got offended by a compliment, but that does not reflect poorly on me…

alex8687 · 2018-10-21 13:43:32 UTC

Sorry for the late reply, saw this first thing when I woke up this morning. First, changing the time variable did have success - good catch, Ryan! You’re correct I am in the US, and I also agree with you about military time. Funny thing is I enter all my times into WebCoRE using military time and it resolves to 12-hour within the script - not sure if its a setting somewhere or just a US thing, but I wish it would stay in military time. In the end, I actually removed that bit as I would like that routine button to fire the piston without restriction (which it is now doing successfully after WCmore’s initial help).

The issue still remaining is the hourly timer will not fire the piston (lines 31-36). For testing purposes I’ve currently set it to fire every other minute but will set back to hourly when working correctly. It appears to cancel the main action starting at line 65 (statement 23 in the logs) and THEN update the variables on lines 33-35 when executing; I was expecting it to do those two things in opposite order (and complete statement 23 instead of cancelling!), unless I’m misunderstanding how things work and/or are displayed in the log? Below is the current version of the piston and I’ve included the log output from the last attempt to fire the hourly (currently bi-minute) portion of code below, as well.

10/21/2018, 8:27:27 AM +131ms
+1ms ╔Received event [Home].time = 1540128447929 with a delay of -798ms
+152ms ║RunTime Analysis CS &gt; 23ms &gt; PS &gt; 83ms &gt; PE &gt; 46ms &gt; CE
+156ms ║Runtime (52957 bytes) successfully initialized in 83ms (v0.3.108.20180906) (153ms)
+157ms ║╔Execution stage started
+171ms ║║Cancelling statement #23's schedules...
+324ms ║║Executed virtual command setVariable (4ms)
+331ms ║║Executed virtual command setVariable (3ms)
+337ms ║║Executed virtual command setVariable (1ms)
+348ms ║╚Execution stage complete. (192ms)
+351ms ║Setting up scheduled job for Sun, Oct 21 2018 @ 8:29:27 AM CDT (in 120.448s), with 2 more jobs pending
+359ms ╚Event processed successfully (359ms)

WCmore, for your second suggestion:

I think i see the logic here, {run} needs to return to false after each run; if the main block at the bottom isn’t firing then that isn’t happening - what I’ve currently done to solve that is set the {run} variable to have an initial value of false. This has worked successfully with the routine firing as well as the 6:30 / 9:45 firing which leads me to think its successfully accomplishing what your suggested block of code is intending to help with, but please let me know if I’m wrong!

WCmore · 2018-10-21 17:53:05 UTC

I just did some testing, and I can confirm this behavior.

It seems like the command:
execute every other minute
will only execute that one block. It will not run the piston top to bottom.

Alternatively, the command:
execute IF time happens daily at 6:30PM
will run the entire piston top to bottom.

For example, this code only executes the top block of code:

temp

As seen in the log:

temp

And changing the first block to a specific time executes the entire piston:

temp

As seen in the log:

temp

This leads me to suggest putting the hourly timer in a separate piston, or putting all the relevant code within the same block.

alex8687 · 2018-10-21 21:30:54 UTC

WCmore, this has solved the problem, thank you! I’ve converted the hourly timer to a series of If time happens daily at xx:xx triggers and its working as it should. Techically I suppose you have solved two problems, but I’ve marked the answer to my biggest problem as solution; since I’m new here let me know if I should change this. Thanks!

WCmore · 2018-10-21 22:07:49 UTC

We covered a lot of ground… Glad we got it working for you.

The solution you choose is most helpful for other people who later discover this thread. It helps them jump right to the solution, if they wish.