Lighting piston help


#1

1) Give a description of the problem
Having an issue with one of my first pistons, sure it’s something simple.

2) What is the expected behavior?
Outside lights turn on at sunset (fade from 100 to 80%), at 930 pm fade from 80-30% and at sunrise -30 minutes they should fade from 30-100% and then turn off.

3) What is happening/not happening?
The entire piston works, except at 1010 pm the lights fade from 30-72%.

4) Post a Green Snapshot of the pistonimage

5) Attach any logs (From ST IDE and by turning logging level to Full)
1/16/2018, 10:14:04 PM +15ms
+0ms ╔Starting piston… (v0.2.101.20171227)
+107ms ║╔Subscribing to devices…
+146ms ║║Subscribing to Soffit Lights…
+146ms ║╚Finished subscribing (48ms)
+206ms ║Setting up scheduled job for Wed, Jan 17 2018 @ 7:02:00 AM CST (in 31675.78s), with 2 more jobs pending
+219ms ╚Piston successfully started (219ms)
1/16/2018, 10:10:39 PM +228ms
+0ms ╔Starting piston… (v0.2.101.20171227)
+191ms ║╔Subscribing to devices…
+246ms ║║Subscribing to Soffit Lights…
+247ms ║╚Finished subscribing (63ms)
+369ms ║Setting up scheduled job for Wed, Jan 17 2018 @ 7:02:00 AM CST (in 31880.403s), with 2 more jobs pending
+383ms ╚Piston successfully started (382ms)
1/16/2018, 9:30:02 PM +88ms
+1ms ╔Received event [Spencer].time = 1516159802326 with a delay of -238ms
+100ms ║RunTime Analysis CS > 18ms > PS > 53ms > PE > 29ms > CE
+102ms ║Runtime (38143 bytes) successfully initialized in 53ms (v0.2.101.20171227) (100ms)
+104ms ║╔Execution stage started
+127ms ║╚Execution stage complete. (24ms)
+130ms ║Setting up scheduled job for Wed, Jan 17 2018 @ 7:02:00 AM CST (in 34317.783s), with 2 more jobs pending
+135ms ╚Event processed successfully (135ms)
1/16/2018, 9:29:59 PM +79ms
+1ms ╔Received event [Spencer].time = 1516159800000 with a delay of -921ms
+68ms ║RunTime Analysis CS > 12ms > PS > 30ms > PE > 26ms > CE
+71ms ║Runtime (38142 bytes) successfully initialized in 30ms (v0.2.101.20171227) (68ms)
+72ms ║╔Execution stage started
+90ms ║║Cancelling statement #6’s schedules…
+105ms ║║Skipped execution of physical command [Soffit Lights].setLevel([80]) because it would make no change to the device. (5ms)
+111ms ║║Executed physical command [Soffit Lights].setLevel([72], [delay: 500]) (5ms)
+117ms ║║Executed physical command [Soffit Lights].setLevel([63], [delay: 1000]) (5ms)
+122ms ║║Executed physical command [Soffit Lights].setLevel([55], [delay: 1500]) (5ms)
+128ms ║║Executed physical command [Soffit Lights].setLevel([47], [delay: 2000]) (4ms)
+135ms ║║Executed physical command [Soffit Lights].setLevel([38], [delay: 2500]) (4ms)
+139ms ║║Executed physical command [Soffit Lights].setLevel([30], [delay: 3000]) (4ms)
+144ms ║║Executed physical command [Soffit Lights].setLevel([30], [delay: 3099]) (4ms)
+145ms ║║Executed virtual command [Soffit Lights].fadeLevel (46ms)
+146ms ║║Requesting a wake up for Tue, Jan 16 2018 @ 9:30:02 PM CST (in 3.1s)
+153ms ║╚Execution stage complete. (82ms)
+155ms ║Setting up scheduled job for Tue, Jan 16 2018 @ 9:30:02 PM CST (in 3.092s), with 3 more jobs pending
+162ms ╚Event processed successfully (162ms)
1/16/2018, 9:27:04 PM +477ms
+0ms ╔Starting piston… (v0.2.101.20171227)
+110ms ║╔Subscribing to devices…
+153ms ║║Subscribing to Soffit Lights…
+154ms ║╚Finished subscribing (55ms)
+263ms ║Setting up scheduled job for Tue, Jan 16 2018 @ 9:30:00 PM CST (in 175.264s), with 2 more jobs pending
+274ms ╚Piston successfully started (274ms)
1/16/2018, 9:26:57 PM +189ms
+1ms ╔Starting piston… (v0.2.101.20171227)
+147ms ║╔Subscribing to devices…
+220ms ║║Subscribing to Soffit Lights…
+221ms ║╚Finished subscribing (82ms)
+334ms ║Setting up scheduled job for Tue, Jan 16 2018 @ 9:30:00 PM CST (in 182.477s), with 2 more jobs pending
+346ms ╚Piston successfully started (346ms)
1/16/2018, 8:36:58 PM +564ms
+1ms ╔Received event [Spencer].test = 1516156618564 with a delay of 0ms
+98ms ║RunTime Analysis CS > 19ms > PS > 54ms > PE > 25ms > CE
+101ms ║Runtime (38139 bytes) successfully initialized in 54ms (v0.2.101.20171227) (99ms)
+102ms ║╔Execution stage started
+175ms ║╚Execution stage complete. (73ms)
+181ms ║Setting up scheduled job for Tue, Jan 16 2018 @ 9:30:00 PM CST (in 3181.258s), with 2 more jobs pending
+188ms ╚Event processed successfully (188ms)

REMOVE BELOW AFTER READING


#2

Your fade times are too short for webCoRE and your dimmer to handle; webCoRE wakes itself up and sends a new level to your dimmer for each step in the fade. In practice, due to process times and your dimmer’s/bulb’s limit in how many radio commands it can receive and decode in rapid succession… about 3 seconds per step seems to be the tightest you want to run.

In other words, if you were fading from 90% to 100%, you’d want to do it over 30 seconds at a minimum for 1% per step resolution.

At a 3 second fade, you’re better off just setting the level. If you truly want it gradual, set it so your piston and dimmer have time to keep up with the commands.

Edit to add:

For example, in here you can see your piston sent 3 level commands to your dimmer/bulb in 0.011 seconds:

|+111ms|║║Executed physical command [Soffit Lights].setLevel([72], [delay: 500]) (5ms)|
|+117ms|║║Executed physical command [Soffit Lights].setLevel([63], [delay: 1000]) (5ms)|
|+122ms|║║Executed physical command [Soffit Lights].setLevel([55], [delay: 1500]) (5ms)|

Your device hasn’t even received the first one before the second one is sent - that’s why your delay keeps ramping up.


#3

There isn’t anything happening at 10:10pm. It looks like you went in and then saved something. I would pull up the soffit lights in the smartthings app and check the recently tab to see what else is controlling those lights.


#4

Yep, and the comment he had on the 72% is actually here:
1/16/2018, 9:29:59 PM +79ms
+1ms ╔Received event [Spencer].time = 1516159800000 with a delay of -921ms
+68ms ║RunTime Analysis CS > 12ms > PS > 30ms > PE > 26ms > CE
+71ms ║Runtime (38142 bytes) successfully initialized in 30ms (v0.2.101.20171227) (68ms)
+72ms ║╔Execution stage started
+90ms ║║Cancelling statement #6’s schedules…
+105ms ║║Skipped execution of physical command [Soffit Lights].setLevel([80]) because it would make no change to the device. (5ms)
+111ms ║║Executed physical command [Soffit Lights].setLevel([72], [delay: 500]) (5ms)
+117ms ║║Executed physical command [Soffit Lights].setLevel([63], [delay: 1000]) (5ms)
+122ms ║║Executed physical command [Soffit Lights].setLevel([55], [delay: 1500]) (5ms)

I think the issue here is the lights were probably already at 80% when the fade started, so it skipped 80% and its first command sent to the device was 72%. (I still don’t think the fade command is working the way he wants based on my post above though… those commands are coming in way too fast)


#5

Probably just not in the logs he posted. The reason it skipped the 80 is because it was already set there previously on the first fade.

I do agree that a set level command would probably be better in this situation, I try to stick with solving the issues someone has without gutting their entire setup unless required :stuck_out_tongue_winking_eye:. So if he wants the short fade then I try to keep it there.


#6

Like I said, I’m new at this. To be honest, couldn’t care less if it fades or just sets so I will try replacing the fade level to set level. Does that need to occur over a period of time or just adjust level to 30%?


#7

You can just set level in one command.
I would keep the “wait” though before you turn the light back off as setting the level turns the light on (well, technically that depends on the DTH, but in my cases using a Set Level command actually turns on the light).

IN my experience it just works better if you don’t rapid fire a Set Level followed immediately by a command to turn off the light. A little pause (a second or two) usually is all that is needed.


#8

I made some changes…Used set level and left one fade from 80-30% over 4 minutes (wife likes it). What you are describing makes perfect sense. Thanks for you help!