Fade timings are sporadically off

[verybadsoldier]

Usually fade timings are really accurate for me and do match well with the passed fade time in the command. But sometimes when issueing a fade command then the fade takes significantly longer to execute than desired.

I am not sure if this is an issue with the firmware or maybe with the RGBWWLed library. Also I tested only with FHEM so it might also be an issue with the FHEM module. But my best guess is that it is related to the firmare.

The issue is 100% reproducible for me using these commands:

set sz_lightLedWall hue 0
set sz_lightLedWall hue 100 60
set sz_lightLedWall hue 50
set sz_lightLedWall hue 200 60
set sz_lightLedWall hue 100
set sz_lightLedWall hue 200 60

I always issue one command then wait until it completes. Then I send the next command (manually). All fades work fine but the last one takes about 74 seconds to complete instead of the targeted 60 seconds.

I am using latest firmware 0.3.1.

[verybadsoldier]

Well, it does not happend always but quite regularly.

I have written a small script to reproduce the issue:

led_fade.py.zip

It will set different hues with ramps and then check the final hue value after waiting the ramp time. It will run in an endless loop. You will sometimes see stuff like this

Setting hue 50 with ramp 1.0
Sleeping 2.0 seconds...
Color now: {"hsv":{"h":49.97,"s":100.00,"v":100.00,"ct":2700}}
Setting hue 200 with ramp 60.0
Sleeping 61.0 seconds...
Color now: {"hsv":{"h":179.77,"s":100.00,"v":100.00,"ct":2700}}

Which means it sets a hue of 50 (ramp 1.0) and then hue of 200 with a ramp of 60 seconds. So it will fade from 50 to 200 in 60 seconds. But after 61 seconds the hue value still was only 179 (200 not reached yet).

[patrickjahns]

Thanks for reporting this. I've used your script to test the behavior and can confirm your findings.

However - how important are 100% time dependant fades? Which use case requires this?

Currently the controller use the Sming Timer Delegates to call the rgbwwlibrary which then handles fading/animations

See:
https://github.com/patrickjahns/esp_rgbww_firmware/blob/master/app/ledctrl.cpp#L61
and
https://github.com/patrickjahns/RGBWWLed/blob/master/RGBWWLed.cpp#L113

Animations/Fades are internally handled on a 'step basis'

• calculate the amount of steps a fade for time t will take ( t / 'frames/steps second')
• when RGBWWLed::show() is called - the current step will be displayed and the next step will be calculated (for the next show() )

It might be, that the esp is busy handling other tasks and thus the relation between steps/time will be out of sync.

[verybadsoldier]

However - how important are 100% time dependant fades? Which use case requires this?

I noticed this behavior when I tried to synchronize two LED devices in FHEM (I tried a LedController with a WifiLight). To get a long-running disco effect I issued a 15 minute hue-fade to both devices (repeatedly). And it was quite obvious that the visible color often differed alot. The same happened when tried to synchronize 2 LedControllers device in the same way.
After some debugging I noticed this issue with the fade timings.

You are right and I don't expect it to be 100% accurate. But honestly, I am considering a fade taking ~75 seconds instead of the requested 60 seconds to be quite significantly off.

A fix for this would be great. Maybe there is anything I can do or anything I can help out with?

[verybadsoldier]

I added some more debug outputs to better analyze what is going on when it happens.

I wanted to see if there is one particular single lag that occurs which pauses the processing for some time or if the fade in general is too slow. So I made hue fade from 100 to 160 within 60 seconds and did an output every 3 seconds. So the current fade time and last two digits of the hue value should always match (e.g. after 35 seconds the hue should be at 135).

Setting hue 100 with ramp 1.0 s
Current hue: 259.71 - Time since ramp start: 0.06
Current hue: 100.0 - Time since ramp start: 3.09
Setting hue 160 with ramp 60.0 s
Current hue: 100.0 - Time since ramp start: 0.06
Current hue: 102.99 - Time since ramp start: 3.09
Current hue: 106.04 - Time since ramp start: 6.11
Current hue: 109.03 - Time since ramp start: 9.16
Current hue: 112.08 - Time since ramp start: 12.19
Current hue: 115.07 - Time since ramp start: 15.21
Current hue: 118.12 - Time since ramp start: 18.24
Current hue: 121.11 - Time since ramp start: 21.27
Current hue: 124.16 - Time since ramp start: 24.30
Current hue: 127.16 - Time since ramp start: 27.32
Current hue: 130.21 - Time since ramp start: 30.35
Current hue: 133.26 - Time since ramp start: 33.38
Current hue: 136.25 - Time since ramp start: 36.41
Current hue: 139.3 - Time since ramp start: 39.44
Current hue: 142.29 - Time since ramp start: 42.46
Current hue: 145.34 - Time since ramp start: 45.49
Current hue: 148.33 - Time since ramp start: 48.52
Current hue: 151.32 - Time since ramp start: 51.53
Current hue: 154.37 - Time since ramp start: 54.56
Current hue: 157.42 - Time since ramp start: 57.61
Current hue: 160.0 - Time since ramp start: 60.63
Setting hue 200 with ramp 1.0 s
Current hue: 160.0 - Time since ramp start: 0.06
Current hue: 200.0 - Time since ramp start: 3.09
Setting hue 260 with ramp 60.0 s
Current hue: 200.0 - Time since ramp start: 0.07
Current hue: 202.7 - Time since ramp start: 3.10
Current hue: 205.4 - Time since ramp start: 6.12
Current hue: 207.98 - Time since ramp start: 9.13
Current hue: 210.67 - Time since ramp start: 12.16
Current hue: 213.37 - Time since ramp start: 15.19
Current hue: 216.01 - Time since ramp start: 18.21
Current hue: 218.71 - Time since ramp start: 21.24
Current hue: 221.41 - Time since ramp start: 24.27
Current hue: 223.93 - Time since ramp start: 27.29
Current hue: 226.51 - Time since ramp start: 30.32
Current hue: 229.21 - Time since ramp start: 33.35
Current hue: 231.91 - Time since ramp start: 36.37
Current hue: 234.49 - Time since ramp start: 39.39
Current hue: 239.18 - Time since ramp start: 44.68
Current hue: 241.82 - Time since ramp start: 47.71
Current hue: 244.52 - Time since ramp start: 50.74
Current hue: 249.09 - Time since ramp start: 56.04
Current hue: 251.79 - Time since ramp start: 59.06
Current hue: 254.37 - Time since ramp start: 62.09
!!!!!!!!! Ramp taking too long!
Current hue: 256.95 - Time since ramp start: 65.12
!!!!!!!!! Ramp taking too long!
Current hue: 259.65 - Time since ramp start: 68.14
Setting hue 100 with ramp 1.0 s
Current hue: 259.71 - Time since ramp start: 0.06
Current hue: 100.0 - Time since ramp start: 3.09
Setting hue 160 with ramp 60.0 s
Current hue: 100.0 - Time since ramp start: 0.06
Current hue: 102.99 - Time since ramp start: 3.09
Current hue: 106.04 - Time since ramp start: 6.11
Current hue: 109.03 - Time since ramp start: 9.14
Current hue: 112.08 - Time since ramp start: 12.16
Current hue: 115.07 - Time since ramp start: 15.19
Current hue: 118.12 - Time since ramp start: 18.22
Current hue: 121.11 - Time since ramp start: 21.26
Current hue: 124.16 - Time since ramp start: 24.29
Current hue: 127.16 - Time since ramp start: 27.32
Current hue: 130.21 - Time since ramp start: 30.35
Current hue: 133.2 - Time since ramp start: 33.38
Current hue: 136.25 - Time since ramp start: 36.40
Current hue: 139.24 - Time since ramp start: 39.43
Current hue: 142.29 - Time since ramp start: 42.45
Current hue: 145.28 - Time since ramp start: 45.48
Current hue: 148.33 - Time since ramp start: 48.51
Current hue: 151.32 - Time since ramp start: 51.53
Current hue: 154.37 - Time since ramp start: 54.57
Current hue: 157.36 - Time since ramp start: 57.59
Current hue: 160.0 - Time since ramp start: 60.62

So, what we see is:

• first there is a correctly working fade (matching time/hue values from start to end)
• then there is an erroneous fade (time/hue values NOT matching from start to end)
• directly after there is again a working fade

Correct me if I am wrong but it does not look to me as there are certain moments where the controller is busy and some particular lags occur. To me it looks like for some reasons certain fades are executed wrongly. Maybe some miscalculation regarding start or end HSV values or something like that?

Please find the updated script here:
led_fade.zip