Trying to get a gentle wake up lighting piston to work properly

frazzlegod · 2019-03-25 15:20:13 UTC

1) Give a description of the problem
I used to have a gentle wake up lighting piston working for a single bulb, set to trigger daily (only on weekdays) at 7:45AM, to go from 0% brightness (off) to 100% brightness over the period of 15 minutes (completing at 8:00AM).

I was under the assumption that the piston was working correctly, and well, until I decided to add piston states at various stages of the piston’s execution, just for visual feedback on the dashboard, like I have done for all my other pistons.

Since doing so, and with logging and trace enabled, I have become aware of significant delays to execution of scheduled tasks (from repeated wait commands). Sometimes, the execution is spot on the scheduled task time, other times it can be delayed up to 30 seconds (so far I have seen), which is completely unacceptable to me for the purpose of this piston.

Taking the maths into account for this:
15 minutes execution duration = 900 seconds (15 minutes X 60 seconds)
900 seconds total duration / 100 (to derive wait period for 1% brightness increments) = 9 seconds between each 1% bulb brightness increment

So, with that in mind, inside a while loop, I have a 9 second wait period, which is obviously repeated several times (once per 1% brightness increment) until the while condition becomes false (ultimately when the bulb has been brightened to the maximum 100%).

It is that multiple-repeated 9 second wait period that is giving me trouble. Sometimes the execution happens bang on the 9 seconds, other times (and mostly) there are ridiculous delays to this wait period being executed. Obviously with the maths involved in what I want to achieve with the light bulb gradually brightening over 15 minutes, it has to be fairly accurate, and with these delays I am seeing in the logs (and watching the bulb’s activity in the ST app), it just does not work properly, and is not acceptable to me.

I have tried various combinations of Task Scheduling Policy and Never Cancel Tasks, but to no avail. And I do not wish to use the built-in “fade” command for this, as I know that once a fade has started, you cannot interrupt it until it has completed, which is not workable for me as I would like the ability to manually turn the bulb off during that 15 minute execution window, if I so wish (without the piston forcing it to switch on again).

Please have a look at my attached piston and advise what I am doing incorrectly because I am really pulling my hair out on this one now.

Although I mentioned a trigger time of 7:45AM above, that is not included in this iteration of my piston as I am currently just testing it with the basic functionality of looping and gradually increasing the bulb brightness in 1% increments for the moment (my current testing involves manually triggering the piston by switching the bulb [on then] off via the ST app). Once I have that basic functionality working, I will wrap the whole thing inside the desired timer.

2) What is the expected behavior?
Covered in the above essay

3) What is happening/not happening?
Covered in the above essay too

4) Post a Green Snapshot of the piston

5) Attach any logs (From ST IDE and by turning logging level to Full)
3/25/2019, 2:36:05 PM +70ms
+0ms ╔Received event [Home].time = 1553524552189 with a delay of 12880ms
+508ms ║RunTime Analysis CS > 230ms > PS > 255ms > PE > 23ms > CE
+511ms ║Runtime (39840 bytes) successfully initialized in 255ms (v0.3.10a.20190223) (509ms)
+512ms ║╔Execution stage started
+547ms ║║Comparison (integer) 4 is_less_than (integer) 100 = true (2ms)
+549ms ║║Condition #11 evaluated true (8ms)
+551ms ║║Condition group #10 evaluated true (state did not change) (10ms)
+566ms ║║Comparison (enum) on is (string) on = true (4ms)
+569ms ║║Condition #13 evaluated true (14ms)
+571ms ║║Condition group #12 evaluated true (state did not change) (17ms)
+584ms ║║Calculating (integer) 4 + (integer) 1 >> (integer) 5
+593ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setVariable (4ms)
+615ms ║║Executed physical command [Hue (Master Bedroom: Scott’s Bedside)].setLevel([5]) (17ms)
+617ms ║║Executed [Hue (Master Bedroom: Scott’s Bedside)].setLevel (19ms)
+626ms ║║Calculating (string) 5 + (string) % >> (string) 5%
+640ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setState (9ms)
+646ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].wait (1ms)
+648ms ║║Requesting a wake up for Mon, Mar 25 2019 @ 2:36:14 PM GMT (in 9.0s)
+656ms ║╚Execution stage complete. (144ms)
+659ms ║Setting up scheduled job for Mon, Mar 25 2019 @ 2:36:14 PM GMT (in 8.991s)
+671ms ╚Event processed successfully (671ms)
3/25/2019, 2:35:42 PM +512ms
+1ms ╔Received event [Home].time = 1553524532054 with a delay of 10458ms
+560ms ║RunTime Analysis CS > 152ms > PS > 384ms > PE > 23ms > CE
+564ms ║Runtime (39840 bytes) successfully initialized in 384ms (v0.3.10a.20190223) (561ms)
+565ms ║╔Execution stage started
+599ms ║║Comparison (integer) 3 is_less_than (integer) 100 = true (2ms)
+601ms ║║Condition #11 evaluated true (7ms)
+603ms ║║Condition group #10 evaluated true (state did not change) (8ms)
+616ms ║║Comparison (enum) on is (string) on = true (2ms)
+618ms ║║Condition #13 evaluated true (12ms)
+619ms ║║Condition group #12 evaluated true (state did not change) (13ms)
+629ms ║║Calculating (integer) 3 + (integer) 1 >> (integer) 4
+636ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setVariable (3ms)
+656ms ║║Executed physical command [Hue (Master Bedroom: Scott’s Bedside)].setLevel([4]) (15ms)
+658ms ║║Executed [Hue (Master Bedroom: Scott’s Bedside)].setLevel (18ms)
+666ms ║║Calculating (string) 4 + (string) % >> (string) 4%
+670ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setState (0ms)
+675ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].wait (0ms)
+677ms ║║Requesting a wake up for Mon, Mar 25 2019 @ 2:35:52 PM GMT (in 9.0s)
+684ms ║╚Execution stage complete. (119ms)
+686ms ║Setting up scheduled job for Mon, Mar 25 2019 @ 2:35:52 PM GMT (in 8.992s)
+697ms ╚Event processed successfully (696ms)
3/25/2019, 2:35:22 PM +486ms
+0ms ╔Received event [Home].time = 1553524513590 with a delay of 8895ms
+428ms ║RunTime Analysis CS > 105ms > PS > 305ms > PE > 18ms > CE
+431ms ║Runtime (39839 bytes) successfully initialized in 305ms (v0.3.10a.20190223) (429ms)
+433ms ║╔Execution stage started
+478ms ║║Comparison (integer) 2 is_less_than (integer) 100 = true (3ms)
+481ms ║║Condition #11 evaluated true (11ms)
+484ms ║║Condition group #10 evaluated true (state did not change) (14ms)
+498ms ║║Comparison (enum) on is (string) on = true (2ms)
+501ms ║║Condition #13 evaluated true (12ms)
+502ms ║║Condition group #12 evaluated true (state did not change) (14ms)
+514ms ║║Calculating (integer) 2 + (integer) 1 >> (integer) 3
+521ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setVariable (4ms)
+543ms ║║Executed physical command [Hue (Master Bedroom: Scott’s Bedside)].setLevel([3]) (17ms)
+545ms ║║Executed [Hue (Master Bedroom: Scott’s Bedside)].setLevel (19ms)
+553ms ║║Calculating (string) 3 + (string) % >> (string) 3%
+559ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setState (1ms)
+565ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].wait (1ms)
+567ms ║║Requesting a wake up for Mon, Mar 25 2019 @ 2:35:32 PM GMT (in 9.0s)
+575ms ║╚Execution stage complete. (143ms)
+578ms ║Setting up scheduled job for Mon, Mar 25 2019 @ 2:35:32 PM GMT (in 8.991s)
+588ms ╚Event processed successfully (589ms)
3/25/2019, 2:35:03 PM +982ms
+1ms ╔Received event [Home].time = 1553524497533 with a delay of 6449ms
+498ms ║RunTime Analysis CS > 239ms > PS > 245ms > PE > 14ms > CE
+501ms ║Runtime (39683 bytes) successfully initialized in 245ms (v0.3.10a.20190223) (500ms)
+502ms ║╔Execution stage started
+523ms ║║Comparison (integer) 1 is_less_than (integer) 100 = true (3ms)
+525ms ║║Cancelling condition #11’s schedules…
+526ms ║║Condition #11 evaluated true (8ms)
+528ms ║║Cancelling condition #10’s schedules…
+529ms ║║Condition group #10 evaluated true (state changed) (11ms)
+542ms ║║Comparison (enum) on is (string) on = true (2ms)
+544ms ║║Cancelling condition #13’s schedules…
+545ms ║║Condition #13 evaluated true (13ms)
+547ms ║║Cancelling condition #12’s schedules…
+548ms ║║Condition group #12 evaluated true (state changed) (17ms)
+558ms ║║Calculating (integer) 1 + (integer) 1 >> (integer) 2
+564ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setVariable (3ms)
+587ms ║║Executed physical command [Hue (Master Bedroom: Scott’s Bedside)].setLevel([2]) (18ms)
+588ms ║║Executed [Hue (Master Bedroom: Scott’s Bedside)].setLevel (20ms)
+596ms ║║Calculating (string) 2 + (string) % >> (string) 2%
+601ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setState (1ms)
+606ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].wait (1ms)
+607ms ║║Requesting a wake up for Mon, Mar 25 2019 @ 2:35:13 PM GMT (in 9.0s)
+616ms ║╚Execution stage complete. (113ms)
+618ms ║Setting up scheduled job for Mon, Mar 25 2019 @ 2:35:13 PM GMT (in 8.991s)
+628ms ╚Event processed successfully (628ms)
3/25/2019, 2:34:48 PM +700ms
+2ms ╔Received event [Hue (Master Bedroom: Scott’s Bedside)].switch = on with a delay of 834ms
+94ms ║RunTime Analysis CS > 21ms > PS > 54ms > PE > 18ms > CE
+97ms ║Runtime (39701 bytes) successfully initialized in 54ms (v0.3.10a.20190223) (95ms)
+99ms ║╔Execution stage started
+115ms ║║Comparison (enum) on is (string) off = false (3ms)
+118ms ║║Cancelling condition #4’s schedules…
+120ms ║║Condition #4 evaluated false (12ms)
+122ms ║║Cancelling condition #3’s schedules…
+124ms ║║Condition group #3 evaluated false (state changed) (16ms)
+128ms ║╚Execution stage complete. (29ms)
+130ms ║Setting up scheduled job for Mon, Mar 25 2019 @ 2:34:57 PM GMT (in 8.704s)
+145ms ╚Event processed successfully (144ms)
3/25/2019, 2:34:48 PM +393ms
+1ms ╔Received event [Hue (Master Bedroom: Scott’s Bedside)].switch = off with a delay of 824ms
+68ms ║RunTime Analysis CS > 13ms > PS > 42ms > PE > 13ms > CE
+71ms ║Runtime (39484 bytes) successfully initialized in 42ms (v0.3.10a.20190223) (68ms)
+72ms ║╔Execution stage started
+83ms ║║Comparison (enum) off is (string) off = true (1ms)
+85ms ║║Cancelling condition #4’s schedules…
+86ms ║║Condition #4 evaluated true (8ms)
+87ms ║║Cancelling condition #3’s schedules…
+88ms ║║Condition group #3 evaluated true (state changed) (11ms)
+91ms ║║Cancelling statement #5’s schedules…
+98ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setVariable (3ms)
+115ms ║║Executed physical command [Hue (Master Bedroom: Scott’s Bedside)].setLevel([1]) (13ms)
+116ms ║║Executed [Hue (Master Bedroom: Scott’s Bedside)].setLevel (15ms)
+129ms ║║Executed physical command [Hue (Master Bedroom: Scott’s Bedside)].setColorTemperature([2732]) (8ms)
+130ms ║║Executed [Hue (Master Bedroom: Scott’s Bedside)].setColorTemperature (9ms)
+134ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].setState (1ms)
+138ms ║║Executed virtual command [Hue (Master Bedroom: Scott’s Bedside)].wait (1ms)
+139ms ║║Requesting a wake up for Mon, Mar 25 2019 @ 2:34:57 PM GMT (in 9.0s)
+144ms ║╚Execution stage complete. (73ms)
+146ms ║Setting up scheduled job for Mon, Mar 25 2019 @ 2:34:57 PM GMT (in 8.994s)
+158ms ╚Event processed successfully (158ms)

WCmore · 2019-03-25 15:51:20 UTC

I don’t have the freetime at the moment to dig deep, but I think you will have better results changing 2% every 18 seconds… or even better results changing 3% every 27 seconds.
(the human eye should not be able to tell the difference)

The logic is SmartThings does not handle “jackhammer” commands so well…

frazzlegod · 2019-03-25 16:06:09 UTC

Hi WCmore,

Thank you for your reply.

In my testing I did try with 18 seconds wait periods, but not per 2% brightness increment, instead keeping it as a 1% brightness increment, i.e. every 18 seconds, increment bulb brightness by 1% (therefore increasing the overall 0% -> 100% duration to 30 minutes). However, I continued to experience the aforementioned execution delays

I have not yet tried with any wait period of 27 seconds. I will give that a go and see what happens.

Aside from that, does my piston look “okay” on the whole?

Thank you once again for your time,
frazzlegod

WCmore · 2019-03-25 16:10:21 UTC

I am about to walk out the door, but this logic does not make sense to me:

IF RGB Bulb 14 is off
Then
    IF RGB Bulb 14 is on
    Then
        Loop
    END IF
END IF

frazzlegod · 2019-03-25 16:20:41 UTC

The idea behind that logic was as follows…

If the bulb is off (to start with, which it should be), then switch it on and begin the gradual brightening sequence, then if the bulb is on (during the while loop, to control the 1% increments, which it should be now as the piston switched it on in the initial step), continue the 1% brightening increments. However, if, during the while loop, the bulb happens to be off (i.e. I have manually switched it off because I want to terminate the brightening sequence), then halt the brightening sequence.

Is that flawed logic?

…frazzlegod

WCmore · 2019-03-25 16:27:02 UTC

Oh, then I would try split the two IF’s into separate blocks… Although it may be tricky to get one trigger to invert without the other trigger firing. (using a second trigger from a different device sounds like the smoothest solution)

IF Time is X
Then
    Set level to 1%
END IF

IF RGB Bulb 14 is on
Then
    Loop   (Wait 27 sec & Set level +3)
ELSE
    Cancel all tasks etc
END IF

I am assuming that this bulb is only used at full brightness or for wakeup purposes…
(for example, it will never stay at 50%)

frazzlegod · 2019-03-25 19:50:14 UTC

I am trying to follow your suggestion, with a brand new piston.

I have the first IF (time trigger and setting to 1%), but I am not clear on the 2nd IF. I get that the 2nd IF is a condition to test that the bulb is now ON, but I am not sure which type of “loop” to insert inside the THEN…

Perhaps you could provide an expanded example of what you mean? I feel that I am going code/logic blind with this particular piston, and some fresh eyes is what I need I believe.

Also, to answer your question, no, the bulb is not just used at full brightness or just for wakeup purposes; it is a Hue bulb that is part of a few different Hue scenes, all of which could set the bulb to differing percentages as well, in addition to this specific wakeup use case.

Thank you once again.

…frazzlegod

WCmore · 2019-03-25 22:25:23 UTC

Oh. Then please ignore all of my posts above.
(I was basing it on your first post)

Unfortunately, I am booked solid the next few days.
Hopefully someone else can step forward to help you.

That being said, there is a good thread here somewhere with almost exactly what you are looking for already created.

EDIT :
I cannot find the post I was looking for, but this might work.

frazzlegod · 2019-03-26 16:56:57 UTC

So I have been trashing pistons and creating new pistons, here there and everywhere just to try to get something for this working, but to no avail still.

I did take a look at the link you posted, took some insight from that piston example and integrated some of that logic into my own piston. But, again, I just cannot get it to work consistently and reliably.

I’m beginning to convince myself that the “wait” command is just there to give me grief and not actually allow me to achieve what I want to with this. If only the “fade” command could be interrupted once it’s started (then I would obviously try that approach instead of looped waits).

I did have some hope when I noticed that every 27 seconds, increasing the bulb brightness by 3% each time, did indeed do just that, according to the WC log output, within the ~-1000ms - ~1000ms range, which is acceptable. However, as the piston execution gradually continued towards its target of 100% bulb brightness, it displayed signs of slowing down dramatically, missing scheduled tasks, massive delays etc., most notably after ~30% bulb brightness had been achieved. What gives…?

I have several other pistons already, which do what I want them to do, so I did believe that I had a good understanding of how most of the different concepts work when writing a piston but, with this particular one, I am seriously beginning to doubt my comprehension of it all and feeling a little defeated at the moment

I have even noticed that when I attempt to trigger the piston execution with…

IF Time happens daily at X

…despite the logs showing that the scheduled job had been created for the target time (as expected), it more often that not completely misses that time and fires anything up to 1 minute later, which of course is not reliable enough for this use case. I wonder if missing the initial target trigger time has a detrimental effect over subsequent scheduled jobs and their associated delays?

I will keep working away at this, trying different things to try to get closer to what I wish to achieve, but I am kind of at the point that I’m borderline begging for more help from anyone. Your quick responses and suggestions / advice have been most welcomed and very much appreciated, however if anyone else could chip in, or indeed if you have had any further thoughts on this, that would be great too.

Many thanks
…frazzlegod

WCmore · 2019-03-26 17:35:24 UTC

I will confess… In the past, I have spent way too many hours trying to stop a fade once it starts, and have come to the conclusion that with the frustration and lack of reliability, it’s not worth it.

Personally, I’ll never begin a fade unless I intend to run it thru to completion.

But, that being said, since this is a wakeup piston (meaning your eyes will be closed), why not expand the test a bit more to 5% every 45 seconds. It may not be any better, but with less network chatter, it might run thru to completion.

frazzlegod · 2019-03-26 18:06:06 UTC

Sure, I will give the 5% / 45 seconds a shot, and see what happens.

You make a good point about the network chatter aspect; perhaps I’m just sending the setLevel() command too frequently for the Hue bulb to cope with (although I did think that every 27 seconds [+3%] was conservative enough for the process not to get into a mess).

I’ll give your new suggestion a go and report back the outcome.

Thanks once again
…frazzlegod

WCmore · 2019-03-26 18:06:11 UTC

If your wakeup times are consistent throughout the week, then this should be very reliable:

Yes, the code looks clunky on our end, but the execution should be smooth as butter.