Aeotec rgbw bulb zwa002 issue - wrong color reported

Configuration Z-Wave
1

I just installed 4 aeotec bulbs in my zwave network (running on a aeotec usb stick/hassio on raspberry pi3 b+)
I’ll explain my issue using images and zwave log:
Initial bulb color (yellow, correctly reported because I just refreshed this entity):

colorwheel
colorwheel349×779 48.3 KB

I select a new color (blue, the log starts here) :

colorSelected
colorSelected354×782 48.2 KB

The bulb start the transition to the new color but I think it’s reporting the color change too soon (the color reported inside home assistant is this one but the bulb light is blue):

wrongColorReport
wrongColorReport356×782 47.9 KB

The log

2019-07-10 11:18:25.177 Info, Node010, Value::Set - COMMAND_CLASS_COLOR - Color - 0 - 1 - #0000ff0000
2019-07-10 11:18:25.177 Info, Node010, Color::SetValue - Setting Color value
2019-07-10 11:18:25.178 Detail, Node010, Queuing (Send) ColorCmd_Set (Node=10): 0x01, 0x14, 0x00, 0x13, 0x0a, 0x0d, 0x33, 0x05, 0x05, 0x02, 0x00, 0x03, 0x00, 0x04, 0xff, 0x00, 0x00, 0x01, 0x00, 0x25, 0x69, 0x7b
2019-07-10 11:18:25.178 Detail, Node010, Queuing (Send) ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x00, 0x25, 0x6a, 0x90
2019-07-10 11:18:25.178 Detail, Node010, Queuing (Send) ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x01, 0x25, 0x6b, 0x90
2019-07-10 11:18:25.178 Detail, Node010, Queuing (Send) ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x02, 0x25, 0x6c, 0x94
2019-07-10 11:18:25.178 Detail, Node010, Queuing (Send) ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x03, 0x25, 0x6d, 0x94
2019-07-10 11:18:25.178 Detail, Node010, Queuing (Send) ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x04, 0x25, 0x6e, 0x90
2019-07-10 11:18:25.179 Info, Node010, Value::Set - COMMAND_CLASS_SWITCH_MULTILEVEL - Dimming Duration - 5 - 1 - 255
2019-07-10 11:18:25.179 Detail, Node010, Refreshed Value: old value=255, new value=255, type=byte
2019-07-10 11:18:25.179 Detail, Node010, Changes to this value are not verified
2019-07-10 11:18:25.181 Info, Node010, Value::Set - COMMAND_CLASS_SWITCH_MULTILEVEL - Level - 0 - 1 - 255
2019-07-10 11:18:25.181 Info, Node010, SwitchMultilevel::Set - Setting to level 255
2019-07-10 11:18:25.181 Info, Node010,   Duration: Default
2019-07-10 11:18:25.181 Detail, Node010, Queuing (Send) SwitchMultilevelCmd_Set (Node=10): 0x01, 0x0b, 0x00, 0x13, 0x0a, 0x04, 0x26, 0x01, 0xff, 0xff, 0x25, 0x6f, 0x84
2019-07-10 11:18:25.181 Detail, Node010, Queuing (Send) SwitchMultilevelCmd_Get (Node=10): 0x01, 0x09, 0x00, 0x13, 0x0a, 0x02, 0x26, 0x02, 0x25, 0x70, 0x9c
2019-07-10 11:18:25.181 Detail, Node010, Notification: ValueChanged
2019-07-10 11:18:25.198 Detail,
2019-07-10 11:18:25.198 Info, Node010, Sending (Send) message (Callback ID=0x69, Expected Reply=0x00) - ColorCmd_Set (Node=10): 0x01, 0x14, 0x00, 0x13, 0x0a, 0x0d, 0x33, 0x05, 0x05, 0x02, 0x00, 0x03, 0x00, 0x04, 0xff, 0x00, 0x00, 0x01, 0x00, 0x25, 0x69, 0x7b
2019-07-10 11:18:25.207 Detail, Node010,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-10 11:18:25.207 Detail, Node010,   ZW_SEND_DATA delivered to Z-Wave stack
2019-07-10 11:18:25.366 Detail, Node010,   Received: 0x01, 0x07, 0x00, 0x13, 0x69, 0x00, 0x00, 0x11, 0x93
2019-07-10 11:18:25.367 Detail, Node010,   ZW_SEND_DATA Request with callback ID 0x69 received (expected 0x69)
2019-07-10 11:18:25.367 Info, Node010, Request RTT 168 Average Request RTT 210
2019-07-10 11:18:25.367 Detail,   Expected callbackId was received
2019-07-10 11:18:25.367 Detail,   Message transaction complete
2019-07-10 11:18:25.367 Detail,
2019-07-10 11:18:25.367 Detail, Node010, Removing current message
2019-07-10 11:18:25.367 Detail,
2019-07-10 11:18:25.367 Info, Node010, Sending (Send) message (Callback ID=0x6a, Expected Reply=0x04) - ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x00, 0x25, 0x6a, 0x90
2019-07-10 11:18:25.375 Detail, Node010,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-10 11:18:25.376 Detail, Node010,   ZW_SEND_DATA delivered to Z-Wave stack
2019-07-10 11:18:25.535 Detail, Node010,   Received: 0x01, 0x07, 0x00, 0x13, 0x6a, 0x00, 0x00, 0x10, 0x91
2019-07-10 11:18:25.535 Detail, Node010,   ZW_SEND_DATA Request with callback ID 0x6a received (expected 0x6a)
2019-07-10 11:18:25.535 Info, Node010, Request RTT 167 Average Request RTT 188
2019-07-10 11:18:25.536 Detail,   Expected callbackId was received
2019-07-10 11:18:25.703 Detail, Node010,   Received: 0x01, 0x0a, 0x00, 0x04, 0x00, 0x0a, 0x04, 0x33, 0x04, 0x00, 0x00, 0xc8
2019-07-10 11:18:25.704 Detail,
2019-07-10 11:18:25.704 Info, Node010, Response RTT 336 Average Response RTT 360
2019-07-10 11:18:25.704 Detail, Node010,   Expected reply and command class was received
2019-07-10 11:18:25.704 Detail, Node010,   Message transaction complete
2019-07-10 11:18:25.704 Detail,
2019-07-10 11:18:25.704 Detail, Node010, Removing current message
2019-07-10 11:18:25.704 Detail,
2019-07-10 11:18:25.704 Info, Node010, Sending (Send) message (Callback ID=0x6b, Expected Reply=0x04) - ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x01, 0x25, 0x6b, 0x90
2019-07-10 11:18:25.712 Detail, Node010,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-10 11:18:25.713 Detail, Node010,   ZW_SEND_DATA delivered to Z-Wave stack
2019-07-10 11:18:25.956 Detail, Node010,   Received: 0x01, 0x07, 0x00, 0x13, 0x6b, 0x00, 0x00, 0x19, 0x99
2019-07-10 11:18:25.956 Detail, Node010,   ZW_SEND_DATA Request with callback ID 0x6b received (expected 0x6b)
2019-07-10 11:18:25.956 Info, Node010, Request RTT 251 Average Request RTT 219
2019-07-10 11:18:25.956 Detail,   Expected callbackId was received
2019-07-10 11:18:26.104 Detail, Node010,   Received: 0x01, 0x0a, 0x00, 0x04, 0x00, 0x0a, 0x04, 0x33, 0x04, 0x01, 0x00, 0xc9
2019-07-10 11:18:26.104 Detail,
2019-07-10 11:18:26.104 Info, Node010, Response RTT 400 Average Response RTT 380
2019-07-10 11:18:26.104 Detail, Node010,   Expected reply and command class was received
2019-07-10 11:18:26.104 Detail, Node010,   Message transaction complete
2019-07-10 11:18:26.104 Detail,
2019-07-10 11:18:26.104 Detail, Node010, Removing current message
2019-07-10 11:18:26.104 Detail,
2019-07-10 11:18:26.104 Info, Node010, Sending (Send) message (Callback ID=0x6c, Expected Reply=0x04) - ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x02, 0x25, 0x6c, 0x94
2019-07-10 11:18:26.113 Detail, Node010,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-10 11:18:26.113 Detail, Node010,   ZW_SEND_DATA delivered to Z-Wave stack
2019-07-10 11:18:26.376 Detail, Node010,   Received: 0x01, 0x07, 0x00, 0x13, 0x6c, 0x00, 0x00, 0x1b, 0x9c
2019-07-10 11:18:26.376 Detail, Node010,   ZW_SEND_DATA Request with callback ID 0x6c received (expected 0x6c)
2019-07-10 11:18:26.376 Info, Node010, Request RTT 271 Average Request RTT 245
2019-07-10 11:18:26.376 Detail,   Expected callbackId was received
2019-07-10 11:18:26.510 Detail, Node010,   Received: 0x01, 0x0a, 0x00, 0x04, 0x00, 0x0a, 0x04, 0x33, 0x04, 0x02, 0xcd, 0x07
2019-07-10 11:18:26.510 Detail,
2019-07-10 11:18:26.510 Info, Node010, Response RTT 405 Average Response RTT 392
2019-07-10 11:18:26.510 Detail, Node010,   Expected reply and command class was received
2019-07-10 11:18:26.510 Detail, Node010,   Message transaction complete
2019-07-10 11:18:26.511 Detail,
2019-07-10 11:18:26.511 Detail, Node010, Removing current message
2019-07-10 11:18:26.511 Detail,
2019-07-10 11:18:26.511 Info, Node010, Sending (Send) message (Callback ID=0x6d, Expected Reply=0x04) - ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x03, 0x25, 0x6d, 0x94
2019-07-10 11:18:26.519 Detail, Node010,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-10 11:18:26.519 Detail, Node010,   ZW_SEND_DATA delivered to Z-Wave stack
2019-07-10 11:18:26.777 Detail, Node010,   Received: 0x01, 0x07, 0x00, 0x13, 0x6d, 0x00, 0x00, 0x1b, 0x9d
2019-07-10 11:18:26.777 Detail, Node010,   ZW_SEND_DATA Request with callback ID 0x6d received (expected 0x6d)
2019-07-10 11:18:26.777 Info, Node010, Request RTT 265 Average Request RTT 255
2019-07-10 11:18:26.777 Detail,   Expected callbackId was received
2019-07-10 11:18:26.925 Detail, Node010,   Received: 0x01, 0x0a, 0x00, 0x04, 0x00, 0x0a, 0x04, 0x33, 0x04, 0x03, 0xb9, 0x72
2019-07-10 11:18:26.925 Detail,
2019-07-10 11:18:26.925 Info, Node010, Response RTT 413 Average Response RTT 402
2019-07-10 11:18:26.925 Detail, Node010,   Expected reply and command class was received
2019-07-10 11:18:26.925 Detail, Node010,   Message transaction complete
2019-07-10 11:18:26.925 Detail,
2019-07-10 11:18:26.925 Detail, Node010, Removing current message
2019-07-10 11:18:26.925 Detail,
2019-07-10 11:18:26.925 Info, Node010, Sending (Send) message (Callback ID=0x6e, Expected Reply=0x04) - ColorCmd_Get (Node=10): 0x01, 0x0a, 0x00, 0x13, 0x0a, 0x03, 0x33, 0x03, 0x04, 0x25, 0x6e, 0x90
2019-07-10 11:18:26.934 Detail, Node010,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-10 11:18:26.934 Detail, Node010,   ZW_SEND_DATA delivered to Z-Wave stack
2019-07-10 11:18:27.198 Detail, Node010,   Received: 0x01, 0x07, 0x00, 0x13, 0x6e, 0x00, 0x00, 0x1b, 0x9e
2019-07-10 11:18:27.198 Detail, Node010,   ZW_SEND_DATA Request with callback ID 0x6e received (expected 0x6e)
2019-07-10 11:18:27.198 Info, Node010, Request RTT 273 Average Request RTT 264
2019-07-10 11:18:27.198 Detail,   Expected callbackId was received
2019-07-10 11:18:27.345 Detail, Node010,   Received: 0x01, 0x0a, 0x00, 0x04, 0x00, 0x0a, 0x04, 0x33, 0x04, 0x04, 0x5b, 0x97
2019-07-10 11:18:27.345 Detail,
2019-07-10 11:18:27.345 Info, Node010, Response RTT 420 Average Response RTT 411
2019-07-10 11:18:27.346 Info, Node010, Received a updated Color from Device: #CDB95B0000
2019-07-10 11:18:27.346 Detail, Node010, Refreshed Value: old value=#FFFF000000, new value=#CDB95B0000, type=string
2019-07-10 11:18:27.346 Detail, Node010, Changes to this value are not verified
2019-07-10 11:18:27.346 Detail, Node010, Refreshed Value: old value=6, new value=17, type=list
2019-07-10 11:18:27.346 Detail, Node010, Changes to this value are not verified
2019-07-10 11:18:27.346 Detail, Node010,   Expected reply and command class was received
2019-07-10 11:18:27.346 Detail, Node010,   Message transaction complete
2019-07-10 11:18:27.346 Detail,
2019-07-10 11:18:27.346 Detail, Node010, Removing current message
2019-07-10 11:18:27.347 Detail, Node010, Notification: ValueChanged
2019-07-10 11:18:27.366 Detail, Node010, Notification: ValueChanged
2019-07-10 11:18:27.375 Detail,
2019-07-10 11:18:27.375 Info, Node010, Sending (Send) message (Callback ID=0x6f, Expected Reply=0x13) - SwitchMultilevelCmd_Set (Node=10): 0x01, 0x0b, 0x00, 0x13, 0x0a, 0x04, 0x26, 0x01, 0xff, 0xff, 0x25, 0x6f, 0x84
2019-07-10 11:18:27.384 Detail, Node010,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-10 11:18:27.384 Detail, Node010,   ZW_SEND_DATA delivered to Z-Wave stack
2019-07-10 11:18:27.623 Detail, Node010,   Received: 0x01, 0x07, 0x00, 0x13, 0x6f, 0x00, 0x00, 0x18, 0x9c
2019-07-10 11:18:27.623 Detail, Node010,   ZW_SEND_DATA Request with callback ID 0x6f received (expected 0x6f)
2019-07-10 11:18:27.623 Info, Node010, Request RTT 247 Average Request RTT 255
2019-07-10 11:18:27.623 Detail,   Expected callbackId was received
2019-07-10 11:18:27.623 Detail,   Expected reply was received
2019-07-10 11:18:27.623 Detail,   Message transaction complete
2019-07-10 11:18:27.624 Detail,
2019-07-10 11:18:27.624 Detail, Node010, Removing current message
2019-07-10 11:18:27.624 Detail,
2019-07-10 11:18:27.624 Info, Node010, Sending (Send) message (Callback ID=0x70, Expected Reply=0x04) - SwitchMultilevelCmd_Get (Node=10): 0x01, 0x09, 0x00, 0x13, 0x0a, 0x02, 0x26, 0x02, 0x25, 0x70, 0x9c
2019-07-10 11:18:27.632 Detail, Node010,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-10 11:18:27.632 Detail, Node010,   ZW_SEND_DATA delivered to Z-Wave stack
2019-07-10 11:18:27.797 Detail, Node010,   Received: 0x01, 0x07, 0x00, 0x13, 0x70, 0x00, 0x00, 0x11, 0x8a
2019-07-10 11:18:27.797 Detail, Node010,   ZW_SEND_DATA Request with callback ID 0x70 received (expected 0x70)
2019-07-10 11:18:27.798 Info, Node010, Request RTT 173 Average Request RTT 214
2019-07-10 11:18:27.798 Detail,   Expected callbackId was received
2019-07-10 11:18:27.943 Detail, Node010,   Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x0a, 0x03, 0x26, 0x03, 0x63, 0xbd
2019-07-10 11:18:27.943 Detail,
2019-07-10 11:18:27.943 Info, Node010, Response RTT 318 Average Response RTT 364
2019-07-10 11:18:27.943 Info, Node010, Received SwitchMultiLevel report: level=99
2019-07-10 11:18:27.943 Detail, Node010, Refreshed Value: old value=99, new value=99, type=byte
2019-07-10 11:18:27.943 Detail, Node010, Changes to this value are not verified
2019-07-10 11:18:27.943 Detail, Node010,   Expected reply and command class was received
2019-07-10 11:18:27.943 Detail, Node010,   Message transaction complete
2019-07-10 11:18:27.943 Detail,
2019-07-10 11:18:27.943 Detail, Node010, Removing current message
2019-07-10 11:18:27.943 Detail, Node010, Notification: ValueChanged

How can I fix it?
thank you!

2

Same problem detected here (HA 0.90.2)

I also note that the request to report color to the node is made 4 times in quick sequence in my case (Once per each color channel??)

2019-07-14 12:38:00.610 Detail, **Node097** , Queuing (Send) SwitchBinaryCmd_Get (Node=97): 0x01, 0x09, 0x00, 0x13, 0x61, 0x02, 0x25, 0x02, 0x25, 0x80, 0x04
2019-07-14 12:38:00.610 Detail, **Node097** , Queuing (Send) SwitchMultilevelCmd_Get (Node=97): 0x01, 0x09, 0x00, 0x13, 0x61, 0x02, 0x26, 0x02, 0x25, 0x81, 0x06
2019-07-14 12:38:00.610 Detail, **Node097** , Queuing (Send) ColorCmd_Get (Node=97): 0x01, 0x0a, 0x00, 0x13, 0x61, 0x03, 0x33, 0x03, 0x00, 0x25, 0x82, 0x13
2019-07-14 12:38:00.610 Detail, **Node097** , Queuing (Send) ColorCmd_Get (Node=97): 0x01, 0x0a, 0x00, 0x13, 0x61, 0x03, 0x33, 0x03, 0x02, 0x25, 0x83, 0x10
2019-07-14 12:38:00.610 Detail, **Node097** , Queuing (Send) ColorCmd_Get (Node=97): 0x01, 0x0a, 0x00, 0x13, 0x61, 0x03, 0x33, 0x03, 0x03, 0x25, 0x84, 0x16
2019-07-14 12:38:00.611 Detail, **Node097** , Queuing (Send) ColorCmd_Get (Node=97): 0x01, 0x0a, 0x00, 0x13, 0x61, 0x03, 0x33, 0x03, 0x04, 0x25, 0x85, 0x10
3

The bulb is reporting the “instant” values as the bulb transitions to the new color. Only way in HA right now is to refresh the bulb.

(Once per each color channel??)

Yep.

4

I’m quite new to HA and z-wave, the only way I found to avoid this issue is an automation and a script for each of my bulbs (and I disabled parameter 80 on the bulbs (basic reporting) )

Automation :

- alias: 'aggiorna_colore_luce_1'
  trigger:
    - platform: state
      entity_id: light.aeotec_limited_zwa002_led_bulb_6_multi_color_level

  condition:
    - condition: template
      value_template: '{{ as_timestamp(now()) - as_timestamp(states.script.aggiorna_colore_luce_1.attributes.last_triggered) | int > 9 }}'  
  action:
    - service: script.turn_off
      entity_id: script.aggiorna_colore_luce_1
    - service: script.aggiorna_colore_luce_1

script

aggiorna_colore_luce_1:
  alias: "Aggiorna il colore della luce rgb zwave 1"
  sequence:

    - delay:
        seconds: 7
    - service: zwave.refresh_entity
      data_template:
        entity_id: 'light.aeotec_limited_zwa002_led_bulb_6_multi_color_level'

All my 4 bulbs are on the same lamp but with different colors, I had to put slightly different delays for each bulb to reduce the spam on my network

Is there any better way to do this?

5

Hi Fishwaldo,

I managed to properly refresh the device color marking it as a “polled” one. It causes a new color refresh request to be sent about 5 seconds after and it properly reflects the right color on the UI.

However, making three repetitive ColorCmd_Get request in fast succession giving to the device no time to produce any noticeable status change does not seem to be a smart coding design.

The problem in my case gets worse because the device is suffering from a poor RF connection, and overloading it with unnecessary repeated ColorCmd_Get commands in so fast pace only makes the things worse.

I’m right now working over a custom ZWave light component and a custom open-zwave codebase (to support Central Scene and another stuff not yet implemented in the master branch) so, I would have no problem to try to modify any Python or C++ code needed to fix this weird behavior. Could you point me in the right direction?

Is it a OZW problem? A HA problem? Is it by design?

Thanks for you support!

Alberto

6

Found it!

Culprit is https://github.com/OpenZWave/open-zwave/blob/3b84138ddecad8fb9d3fe233de38d9f116682cae/cpp/src/command_classes/Color.cpp

There, Color::RequestValue() and Color::RequestState() functions send a request for each channel, even when any response will contain the 4 channels.

There’s a COMPAT_FLAG_COLOR_IDXBUG flag there (apparently intended to support a Fibaro bug) that could help to prevent this. But don’t know what other problems it may cause. Haven’t tested.

@Fishwaldo: Any hint on how to delay the color update request from HA? Or it’s handled automatically by OZW after any color SET request?

Alberto

7

Any SET is followed by a GET in OZW (as there is no other way to ensure that a SET message was successful on a device).
The Z-Wave Specifications doesn’t say if a device should report the instant value, or final value in GET messages when its transitioning between values. its about 50/50 split on what vendors do what.

Solution - OZW 1.6 already has a option you can set in the config file that will refresh the values till it gets two readings that are identical - You just need to set VerifyChanged in the Color CC (https://github.com/OpenZWave/open-zwave/wiki/CommandClass-Compatibility-Flags#all-commandclasses) in the config file for the device.

8

I already tried to enable verifychange in zwcfg but when I turn on my lights or change the color or do anything with my 4 bulbs (99% of the time they’re enabled/disabled at the same time with different colors) my network becomes completely unresposive

9

Good tip!!

Unfortunatelly I’m still running a patched version based on 1.4.3212. Last time I tried 1.6 there were so many changes that either PyOzw or HA started behave in a weird and unpredictable fashion.

I read the latest HA versions started the migration toward 1.6… Perhaps when it’s ready I’l give it another shot.

In the meantime I guess I’ll add to my custom ZWave Light component a delayed update using a timer.

10

I justed wanted to ask if you can use this bulb normally? I have a new one and it cannot be turned off. Did you change anything in the default z wave config file?