sidoh / esp8266_milight_hub

Replacement for a Milight/LimitlessLED hub hosted on an ESP8266
MIT License
936 stars 220 forks source link

Transition time only works for temp or brightness, not both #544

Closed VossenTech closed 4 years ago

VossenTech commented 4 years ago

Describe the bug

When an MQTT message is sent with both brightness and color_temp with a duration, only one of the two will be applied for the duration specified.

Steps to reproduce

Sending the following as MQTT payloads to RGB+CCT bulbs reliably causes this bug for me.

This will transition temp in ~30 sec, brightness over 3600 sec {"state": "ON", "transition": 3600, "brightness": 244, "color_temp": 200}

This will transition brightness in ~30 sec, temp over 3600 sec {"state": "ON", "transition": 3600, "brightness": 80, "color_temp": 349}

Expected behavior

Both the color_temp and brightness should transition over the specified duration.

Setup information

Firmware version

1.10.3 (nodemcuv2) 1.10.2 (nodemcuv2)

Output of http://milight-hub.local/about

{"firmware":"milight-hub","version":"1.10.3","ip_address":"REDACTED","reset_reason":"Software/System restart","variant":"nodemcuv2","free_heap":15928,"arduino_version":"2_4_2","queue_stats":{"length":0,"dropped_packets":0}}

Output of http://milight-hub.local/settings

{"admin_username":"REDACTED","admin_password":"REDACTED","ce_pin":16,"csn_pin":15,"reset_pin":0,"led_pin":-2,"radio_interface_type":"nRF24","packet_repeats":50,"http_repeat_factor":1,"auto_restart_period":0,"mqtt_server":"REDACTED:1883","mqtt_username":"REDACTED","mqtt_password":"REDACTED","mqtt_topic_pattern":"milight/:device_id/:device_type/:group_id","mqtt_update_topic_pattern":"","mqtt_state_topic_pattern":"milight/states/:device_id/:device_type/:group_id","mqtt_client_status_topic":"","simple_mqtt_client_status":false,"discovery_port":48899,"listen_repeats":0,"state_flush_interval":0,"mqtt_state_rate_limit":0,"packet_repeat_throttle_sensitivity":0,"packet_repeat_throttle_threshold":200,"packet_repeat_minimum":3,"enable_automatic_mode_switching":false,"led_mode_wifi_config":"Fast toggle","led_mode_wifi_failed":"On","led_mode_operating":"Off","led_mode_packet":"Flicker","led_mode_packet_count":3,"hostname":"milight-hub","rf24_power_level":"MAX","rf24_listen_channel":"LOW","wifi_static_ip":"","wifi_static_ip_gateway":"","wifi_static_ip_netmask":"","packet_repeats_per_loop":10,"home_assistant_discovery_prefix":"","wifi_mode":"n","default_transition_period":500,"rf24_channels":["MID","HIGH"],"device_ids":[1,32,33,34,36,37,38,39,48,102,580,2311,32776],"gateway_configs":[[2311,8000,6],[1,8001,6]],"group_state_fields":["state","status","brightness","level","hue","saturation","color","mode","kelvin","color_temp","bulb_mode","computed_color","effect","device_id","group_id","device_type"],"group_id_aliases":{}}

sidoh commented 4 years ago

Can you check the output of /transitions after issuing a command? This should definitely work, and it does for me locally:

$ curl 10.133.8.158/gateways/0x118d/rgb_cct/1 -X PUT -d '{"brightness":255,"color_temp":370,"transition":30}' -H 'content-type: application/json' -v
*   Trying 10.133.8.158...
* TCP_NODELAY set
* Connected to 10.133.8.158 (10.133.8.158) port 80 (#0)
> PUT /gateways/0x118d/rgb_cct/1 HTTP/1.1
> Host: 10.133.8.158
> User-Agent: curl/7.54.0
> Accept: */*
> content-type: application/json
> Content-Length: 51
>
* upload completely sent off: 51 out of 51 bytes
< HTTP/1.1 200 OK
< Content-Type: application/json
< Content-Length: 16
< Connection: close
<
* Closing connection 0
{"success":true}%
$ curl 10.133.8.158/transitions | jq
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   403  100   403    0     0  10299      0 --:--:-- --:--:-- --:--:-- 10333
{
  "transitions": [
    {
      "id": 7,
      "period": 500,
      "last_sent": 199327974,
      "bulb": {
        "device_id": 4493,
        "group_id": 1,
        "device_type": "rgb_cct"
      },
      "type": "field",
      "field": "color_temp",
      "current_value": 291,
      "end_value": 370,
      "step_size": 2
    },
    {
      "id": 8,
      "period": 500,
      "last_sent": 199328206,
      "bulb": {
        "device_id": 4493,
        "group_id": 1,
        "device_type": "rgb_cct"
      },
      "type": "field",
      "field": "brightness",
      "current_value": 100,
      "end_value": 255,
      "step_size": 5
    }
  ]
}
VossenTech commented 4 years ago

Here is the output, step sizes appear to be different for temp vs brightness: {"transitions":[{"id":0,"period":500,"last_sent":156726,"bulb":{"device_id":2312,"group_id":2,"device_type":"rgb_cct"},"type":"field","field":"color_temp","current_value":269,"end_value":200,"step_size":-1},{"id":1,"period":6061,"last_sent":154115,"bulb":{"device_id":2312,"group_id":2,"device_type":"rgb_cct"},"type":"field","field":"brightness","current_value":86,"end_value":244,"step_size":1}]}

Looks like you set a transition time of 30 sec in your test, did you test it was a longer transition duration? I would assume at 30 secs it would appear to be working since that's about how long the non-working element takes to transition.

VossenTech commented 4 years ago

Oh, I suppose step size is just different bc temp is going down while brightness is going up.

sidoh commented 4 years ago

sure. seems right to me.

$ curl 10.133.8.158/gateways/0x118d/rgb_cct/1 -X PUT -d '{"brightness":255,"color_temp":370,"transition":3600}' -H 'content-type: application/json' -v
*   Trying 10.133.8.158...
* TCP_NODELAY set
* Connected to 10.133.8.158 (10.133.8.158) port 80 (#0)
> PUT /gateways/0x118d/rgb_cct/1 HTTP/1.1
> Host: 10.133.8.158
> User-Agent: curl/7.54.0
> Accept: */*
> content-type: application/json
> Content-Length: 53
>
* upload completely sent off: 53 out of 53 bytes
< HTTP/1.1 200 OK
< Content-Type: application/json
< Content-Length: 16
< Connection: close
<
* Closing connection 0
{"success":true}%

$ curl 10.133.8.158/transitions | jq
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   406  100   406    0     0   9765      0 --:--:-- --:--:-- --:--:--  9902
{
  "transitions": [
    {
      "id": 9,
      "period": 30253,
      "last_sent": 202200633,
      "bulb": {
        "device_id": 4493,
        "group_id": 1,
        "device_type": "rgb_cct"
      },
      "type": "field",
      "field": "color_temp",
      "current_value": 252,
      "end_value": 370,
      "step_size": 1
    },
    {
      "id": 10,
      "period": 14118,
      "last_sent": 202200633,
      "bulb": {
        "device_id": 4493,
        "group_id": 1,
        "device_type": "rgb_cct"
      },
      "type": "field",
      "field": "brightness",
      "current_value": 1,
      "end_value": 255,
      "step_size": 1
    }
  ]
}
VossenTech commented 4 years ago

What does the "period" represent? Whichever value changes quickly always seems to be set to 500. In the first example below temp changes in 30 seconds, in the second the brightness changes in 30 seconds.

curl 10.0.0.30/gateways/0x908/rgb_cct/2 -X PUT -d '{"brightness":244,"color_temp":200,"transition":3600}' -H 'content-type: application/json' -v
*   Trying 10.0.0.30...
* TCP_NODELAY set
* Connected to 10.0.0.30 (10.0.0.30) port 80 (#0)
> PUT /gateways/0x908/rgb_cct/2 HTTP/1.1
> Host: 10.0.0.30
> User-Agent: curl/7.58.0
> Accept: */*
> content-type: application/json
> Content-Length: 53
>
* upload completely sent off: 53 out of 53 bytes
< HTTP/1.1 200 OK
< Content-Type: application/json
< Content-Length: 16
< Connection: close
<
* Closing connection 0
{"success":true}

transitions | jq
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   397  100   397    0     0   2512      0 --:--:-- --:--:-- --:--:--  2512
{
  "transitions": [
    {
      "id": 0,
      "period": 500,
      "last_sent": 45179,
      "bulb": {
        "device_id": 2312,
        "group_id": 2,
        "device_type": "rgb_cct"
      },
      "type": "field",
      "field": "color_temp",
      "current_value": 307,
      "end_value": 200,
      "step_size": -1
    },
    {
      "id": 1,
      "period": 21819,
      "last_sent": 25180,
      "bulb": {
        "device_id": 2312,
        "group_id": 2,
        "device_type": "rgb_cct"
      },
      "type": "field",
      "field": "brightness",
      "current_value": 80,
      "end_value": 244,
      "step_size": 1
    }
  ]
}
-----------------------
curl 10.0.0.30/gateways/0x908/rgb_cct/2 -X PUT -d '{"brightness":80,"color_temp":349,"transition":3600}' -H 'content-type: application/json' -v
*   Trying 10.0.0.30...
* TCP_NODELAY set
* Connected to 10.0.0.30 (10.0.0.30) port 80 (#0)
> PUT /gateways/0x908/rgb_cct/2 HTTP/1.1
> Host: 10.0.0.30
> User-Agent: curl/7.58.0
> Accept: */*
> content-type: application/json
> Content-Length: 52
>
* upload completely sent off: 52 out of 52 bytes
< HTTP/1.1 200 OK
< Content-Type: application/json
< Content-Length: 16
< Connection: close
<
* Closing connection 0
{"success":true}

transitions | jq
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   397  100   397    0     0  10447      0 --:--:-- --:--:-- --:--:-- 10447
{
  "transitions": [
    {
      "id": 0,
      "period": 24325,
      "last_sent": 70095,
      "bulb": {
        "device_id": 2312,
        "group_id": 2,
        "device_type": "rgb_cct"
      },
      "type": "field",
      "field": "color_temp",
      "current_value": 202,
      "end_value": 349,
      "step_size": 1
    },
    {
      "id": 1,
      "period": 500,
      "last_sent": 80596,
      "bulb": {
        "device_id": 2312,
        "group_id": 2,
        "device_type": "rgb_cct"
      },
      "type": "field",
      "field": "brightness",
      "current_value": 223,
      "end_value": 80,
      "step_size": -1
    }
  ]
}
sidoh commented 4 years ago

Period means frequency -- it's the number of milliseconds that elapse between updates.

The default period is 500. It's adjusted up if the transition doesn't fit. The step size is adjusted up if the transition is too fast.

This doesn't look like expected behavior, though. The period should not be 0.5s when the other period is 21s.

sidoh commented 4 years ago

This is a bug with negative step sizes. I'll push a fix shortly. Thanks for reporting.

VossenTech commented 4 years ago

Sweet thanks.

While testing things with this bug I believe I noticed another as well, when a light is turned off or a new transition is sent the existing transition does not get canceled. So if a light is turned back on after being turned off it will change the levels to reflect wherever you are in the previous transition. If a second transition is sent after the first they will actually "fight" back and forth. I would expect the behavior to be that any new command for a bulb would cancel all previous commands for that bulb.

poudenes commented 4 years ago

Sweet thanks.

While testing things with this bug I believe I noticed another as well, when a light is turned off or a new transition is sent the existing transition does not get canceled. So if a light is turned back on after being turned off it will change the levels to reflect wherever you are in the previous transition. If a second transition is sent after the first they will actually "fight" back and forth. I would expect the behavior to be that any new command for a bulb would cancel all previous commands for that bulb.

I had same idea. Would be nice to have a cancel command or something

sidoh commented 4 years ago

While testing things with this bug I believe I noticed another as well, when a light is turned off or a new transition is sent the existing transition does not get canceled. So if a light is turned back on after being turned off it will change the levels to reflect wherever you are in the previous transition. If a second transition is sent after the first they will actually "fight" back and forth. I would expect the behavior to be that any new command for a bulb would cancel all previous commands for that bulb.

Makes sense for a field transition for a bulb to clobber any currently active field transitions for the same bulb.

I unfortunately don't have a ton of time for this project right now, but I'll open a separate issue for this.

I had same idea. Would be nice to have a cancel command or something

There is a route in the REST API to delete an active transition, but obviously this isn't the most accessible interface. Had planned on having a UI element to show/schedule transitions, but didn't have time. Obviously

sidoh commented 4 years ago

Going to close since the original issue is solved. Will open a separate issue for "fighting" transitions.

VossenTech commented 4 years ago

Is the original issue solved? There have not been any new releases since it was reported, the current 1.10.3 still has the negative number issue.

sidoh commented 4 years ago

It's fixed with this commit: https://github.com/sidoh/esp8266_milight_hub/commit/95bd7fca2cdc77c3b32a70774b55fa4a4f29d704

I forgot to cut a new release, but am going to do so shortly.

sidoh commented 4 years ago

Change is live in 1.10.4.