Hue light turning on with 0% brightness using Home Assistant service (re-open)

[kcarriello]

What happened

I'm re-opening the issue since I misreported that it was fixed on issue #3782. When I re-configure the light to 100%, turn-off/turn-on works as desired but if it stays per hours on off state it returns to 0% behavior when turned-on. My workaround was to downgrade to 0.13.1, which works flawlessly.

Original #3782 issue:

After upgrade to 1.14 my hue bulbs started to have brightness 0% when turned on. This only happens when service light turn on is used on home assistant, when using hue dimmer the lights bright as expected.

What did you expect to happen

The previous behavior (until 1.13.1), when I turned off a light and turned it on again, using Home Assistant service, the light returned to the previous state or full brightness, now it always turned on with 0% brightness, which makes me every time open brightness configuration to increase the value.

How to reproduce it (minimal and precise)

Add a hue bulb to Home Assistant; Use light turn off service to turn off the bulb; (stays off for more than 4h, don't know exactly how long) Use light turn on service to turn on the bulb;

Debug Info

Version of Zigbee2Mqtt: 1.14 Coordinator version: 20190619 CC2531 Firmware version is zStack12.

[Koenkk]

Can you provide the debug logging of this problem?

To enable debug logging set in configuration.yaml:

advanced:
  log_level: debug

[mr2c12]

Just want to report that:

• can confirm that this is happening in dev branch, too
• it affects also Osram bulbs, not only Philips ones

[mr2c12]

Just got something in the logs.

The relevant light group is:

'2': friendly_name: zgroup_giardino retain: false optimistic: true transition: 0.5 devices:

• '0x0017880106e36d5b'
• 0x0017880106018f9f/11

Composed by two Philips Hue bulbs:

'0x0017880106e36d5b': friendly_name: '0x0017880106e36d5b' '0x0017880106018f9f': friendly_name: philips_hue_A60_3

The interesting part:

1. at 21:38:27 an automation turn on the lights - brightness 0 (as you can see in the log, it was 0 long before I set the debug log)
2. at 21:39:26 I set the brightness to max
3. three seconds later I turn off the group of lights
4. at 21:41:10 the automation (occupancy to off) turn off the lights (which were already off)
5. from that moment, every time the group is switched on, the brightness is set to zero, again.

Starting at 21:58:45 you can see that I make a lot of fail&try to get them back at 100%. Please note that the light philips_hue_A60_3 was powered off most of the time, but I don't think this can affect the problem, since it happens in other groups (where all the bulbs are correctly powered).

Here is the log: log.txt.zip

Hope this helps!

[Koenkk]

Can you remove transition: 0.5 from configuration.yaml and see if that fixes the problem?

[mr2c12]

Yeah sure. Removed from all my groups and will report. At the moment I'm still on dev branch.

[AndrzejOlender]

I have the same problem (Bulb Osram, Ikea and Aqara). It helped remove the transition: 0 from configuration.yaml, but I don't like that I had to give it up.

[mr2c12]

Without the transition, the problem has not happened yet. Dev branch updated to 7-10 days ago.

[sylarevan]

Just to mention I have just noticed the same behaviour with my Hue bulbs just after upgrading to 1.14.1. Turning ON a bulb from home-assistant results in a "brightness":0 message in z2m logs (for a group lampes_sejour of 2 bulbs here) :

Jul 16 18:41:02 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-16 18:41:02: MQTT publish: topic 'zigbee2mqtt/hue-light-petite-lampe', payload '{"state":"ON","color_temp":355,"color":{"x":0.323,"y":0.329,"saturation":55.5,"hue":82.3},"brightness":0,"linkquality":31,"color_mode":2,"update_available":false,"last_seen":"2020-07-14T20:23:29+02:00"}'
Jul 16 18:41:02 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-16 18:41:02: MQTT publish: topic 'zigbee2mqtt/lampes_sejour', payload '{"state":"ON","color_temp":355,"color":{"x":0.323,"y":0.329,"saturation":55.5,"hue":82.3},"brightness":0}'
Jul 16 18:41:02 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-16 18:41:02: MQTT publish: topic 'zigbee2mqtt/hue-light-grande-lampe', payload '{"state":"ON","color_temp":355,"color":{"x":0.323,"y":0.329,"saturation":55.5,"hue":82.3},"brightness":0,"linkquality":47,"color_mode":2,"update_available":false,"last_seen":"2020-06-08T20:01:54+02:00"}'

But after setting brightness to 100% manually, a simple ON from home assistant now brings the correct brightness value in logs:

Jul 16 18:43:37 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-16 18:43:37: MQTT publish: topic 'zigbee2mqtt/hue-light-petite-lampe', payload '{"state":"ON","color_temp":355,"color":{"x":0.323,"y":0.329,"saturation":55.5,"hue":82.3},"brightness":254,"linkquality":31,"color_mode":2,"update_available":false,"last_seen":"2020-07-14T20:23:29+02:00"}'
Jul 16 18:43:37 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-16 18:43:37: MQTT publish: topic 'zigbee2mqtt/lampes_sejour', payload '{"state":"ON","color_temp":355,"color":{"x":0.323,"y":0.329,"saturation":55.5,"hue":82.3},"brightness":254}'
Jul 16 18:43:37 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-16 18:43:37: MQTT publish: topic 'zigbee2mqtt/hue-light-grande-lampe', payload '{"state":"ON","color_temp":355,"color":{"x":0.323,"y":0.329,"saturation":55.5,"hue":82.3},"brightness":254,"linkquality":47,"color_mode":2,"update_available":false,"last_seen":"2020-06-08T20:01:54+02:00"}'

After a given time (about 1 day?), brightness is again set to 0 automagically.

[Koenkk]

@sylarevan is this reproducible? If so, can you provide me the debug logging and your configuration.yaml?

To enable debug logging set in configuration.yaml:

advanced:
  log_level: debug

[sylarevan]

@Koenkk Yes, it seems reproductible, my kids had the same issue yesterday. I'll sent you log+config as soon as I am able to capture the issue.

[sylarevan]

Hi @Koenkk. As promised, here is a capture with log level set to debug.

Here is a non-working ON command triggered from Home Assistant with a call to the turn_on service, with option transition:0.5 as programed in my automations:

Jul 19 19:48:29 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:48:29: Received MQTT message on 'zigbee2mqtt/hue-light-valentine/set' with data '{"state": "ON", "transition": 0.5}'
Jul 19 19:48:29 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:48:29: Publishing 'set' 'state' to 'hue-light-valentine'
Jul 19 19:48:30 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-19 19:48:30: MQTT publish: topic 'zigbee2mqtt/hue-light-valentine', payload '{"state":"ON","brightness":0,"linkquality":31,"color":{"x":0.425311978171859,"y":0.399745377726,"saturation":55.1,"hue":46.2},"color_temp":315,"color_mode":2,"update_available":false,"last_seen":"2020-07-19T19:48:30+02:00"}'
Jul 19 19:48:30 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:48:30: Publishing 'set' 'transition' to 'hue-light-valentine'

Now, a OFF command:

Jul 19 19:48:48 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:48:48: Received MQTT message on 'zigbee2mqtt/hue-light-valentine/set' with data '{"state": "OFF", "transition": 0.5}'
Jul 19 19:48:48 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:48:48: Publishing 'set' 'transition' to 'hue-light-valentine'
Jul 19 19:48:48 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:48:48: Publishing 'set' 'state' to 'hue-light-valentine'
Jul 19 19:48:49 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-19 19:48:49: MQTT publish: topic 'zigbee2mqtt/hue-light-valentine', payload '{"state":"OFF","brightness":0,"linkquality":31,"color":{"x":0.425311978171859,"y":0.399745377726,"saturation":55.1,"hue":46.2},"color_temp":315,"color_mode":2,"update_available":false,"last_seen":"2020-07-19T19:48:49+02:00"}'

And now a ON command with an explicit brightness value passed as an option to the turn_on HA service:

Jul 19 19:49:37 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:49:37: Received MQTT message on 'zigbee2mqtt/hue-light-valentine/set' with data '{"state": "ON", "transition": 0.5, "brightness": 254}'
Jul 19 19:49:37 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:49:37: Publishing 'set' 'state' to 'hue-light-valentine'
Jul 19 19:49:37 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-19 19:49:37: MQTT publish: topic 'zigbee2mqtt/hue-light-valentine', payload '{"state":"ON","brightness":254,"linkquality":31,"color":{"x":0.425311978171859,"y":0.399745377726,"saturation":55.1,"hue":46.2},"color_temp":315,"color_mode":2,"update_available":false,"last_seen":"2020-07-19T19:49:37+02:00"}'
Jul 19 19:49:37 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:49:37: Publishing 'set' 'transition' to 'hue-light-valentine'

If I use now a classical ON command from HA without setting any brightness value, I now get the previously set brightness value and the bulb correctly turns on:

Jul 19 19:50:31 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:50:31: Received MQTT message on 'zigbee2mqtt/hue-light-valentine/set' with data '{"state": "ON", "transition": 0.5}'
Jul 19 19:50:31 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:50:31: Publishing 'set' 'state' to 'hue-light-valentine'
Jul 19 19:50:31 raspberrypi npm[16466]: zigbee2mqtt:info  2020-07-19 19:50:31: MQTT publish: topic 'zigbee2mqtt/hue-light-valentine', payload '{"state":"ON","brightness":254,"linkquality":31,"color":{"x":0.425311978171859,"y":0.399745377726,"saturation":55.1,"hue":46.2},"color_temp":315,"color_mode":2,"update_available":false,"last_seen":"2020-07-19T19:50:31+02:00"}'
Jul 19 19:50:31 raspberrypi npm[16466]: zigbee2mqtt:debug 2020-07-19 19:50:31: Publishing 'set' 'transition' to 'hue-light-valentine'

You can download my configuration.yamlfrom here.

[Koenkk]

Thanks, I've implemented a possible fix

Changes will be available in the latest dev branch in a few hours (https://www.zigbee2mqtt.io/how_tos/how-to-switch-to-dev-branch.html)

[sylarevan]

I've just switched to the dev version. I will comment in a few days to confirm that the issue is solved. Thanks!

[sylarevan]

@Koenkk unfortunately, I can now confirm the bug is still present:

Jul 25 17:50:48 raspberrypi npm[31133]: zigbee2mqtt:info  2020-07-25 17:50:48: MQTT publish: topic 'zigbee2mqtt/hue-light-chambre', payload '{"state":"ON","brightness":0,"linkquality":47,"update_available":false,"last_seen":"2020-07-25T17:50:48+02:00"}'

and

Jul 25 17:51:01 raspberrypi npm[31133]: zigbee2mqtt:info  2020-07-25 17:51:01: MQTT publish: topic 'zigbee2mqtt/hue-light-valentine', payload '{"state":"ON","brightness":0,"linkquality":31,"color":{"x":0.425311978171859,"y":0.399745377726,"saturation":55.1,"hue":46.2},"color_temp":315,"color_mode":2,"update_available":false,"last_seen":"2020-07-25T17:51:01+02:00"}'

Brightness is still set to 0 after a while for a ON action.

[Koenkk]

@sylarevan can you check again with latest dev branch, implemented another possible fix.

[sylarevan]

@Koenkk I'm back to business. I will update tomorrow my installation to latest dev version and report. Thanks!

[sylarevan]

Hi @Koenkk. I can confirm the issue is still not solved, but with some slight differences I think. Here is the log output with a ON command from my hue switch handled by my nodered flow:

Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:32:34: Received Zigbee message from 'hue-switch-chambre', type 'commandHueNotification', cluster 'manuSpecificPhilips', data '{"button":1,"unknown1":3145728,"type":0,"unknown2":0,"time":0}' from endpoint 2 with groupID 0
Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:32:34: Received Zigbee message from 'hue-switch-chambre', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:32:34: Received Zigbee message from 'hue-switch-chambre', type 'commandHueNotification', cluster 'manuSpecificPhilips', data '{"button":1,"unknown1":3145728,"type":2,"unknown2":0,"time":0}' from endpoint 2 with groupID 0
Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:info  2020-08-11 15:32:34: MQTT publish: topic 'zigbee2mqtt/hue-switch-chambre', payload '{"battery":93.5,"linkquality":39,"counter":1,"brightness":255,"update_available":true,"last_seen":"2020-08-11T15:32:34+02:00","action":"on-press","duration":0}'
Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:info  2020-08-11 15:32:34: MQTT publish: topic 'zigbee2mqtt/hue-switch-chambre', payload '{"battery":93.5,"linkquality":39,"counter":1,"brightness":255,"update_available":true,"last_seen":"2020-08-11T15:32:34+02:00","action":""}'
Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:info  2020-08-11 15:32:34: MQTT publish: topic 'zigbee2mqtt/hue-switch-chambre/action', payload 'on-press'
Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:32:34: Received MQTT message on 'zigbee2mqtt/hue-light-chambre/set' with data '{"state": "ON", "transition": 0.5}'
Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:32:34: Publishing 'set' 'state' to 'hue-light-chambre'
Aug 11 15:32:35 raspberrypi npm[12200]: Zigbee2MQTT:info  2020-08-11 15:32:35: MQTT publish: topic 'zigbee2mqtt/hue-light-chambre', payload '{"state":"ON","brightness":1,"linkquality":55,"update_available":false,"last_seen":"2020-08-11T15:32:35+02:00"}'
Aug 11 15:32:35 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:32:35: Publishing 'set' 'transition' to 'hue-light-chambre'

While brightness seems set to 1, I can confirm the bulb is still off, but is reported on in Home Assistant.

Now, if I just turn on the switch of the bulb in Home Assistant (no scripting involved here), it is super weird... First, after a OFF from my switch, If I turn on from HA, I get:

Aug 11 15:35:27 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:35:27: Received MQTT message on 'zigbee2mqtt/hue-light-chambre/set' with data '{"state": "ON"}'
Aug 11 15:35:27 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:35:27: Publishing 'set' 'state' to 'hue-light-chambre'
Aug 11 15:35:28 raspberrypi npm[12200]: Zigbee2MQTT:info  2020-08-11 15:35:27: MQTT publish: topic 'zigbee2mqtt/hue-light-chambre', payload '{"state":"ON","brightness":1,"linkquality":55,"update_available":false,"last_seen":"2020-08-11T15:35:27+02:00"}'

But light is off, no light is coming from the bulb.

If I turn off the light and on again (still from HA) :

Aug 11 15:35:35 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:35:35: Received MQTT message on 'zigbee2mqtt/hue-light-chambre/set' with data '{"state": "OFF"}'
Aug 11 15:35:35 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:35:35: Publishing 'set' 'state' to 'hue-light-chambre'
Aug 11 15:35:35 raspberrypi npm[12200]: Zigbee2MQTT:info  2020-08-11 15:35:35: MQTT publish: topic 'zigbee2mqtt/hue-light-chambre', payload '{"state":"OFF","brightness":0,"linkquality":55,"update_available":false,"last_seen":"2020-08-11T15:35:35+02:00"}'
Aug 11 15:35:38 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:35:38: Received MQTT message on 'zigbee2mqtt/hue-light-chambre/set' with data '{"state": "ON"}'
Aug 11 15:35:38 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:35:38: Publishing 'set' 'state' to 'hue-light-chambre'
Aug 11 15:35:38 raspberrypi npm[12200]: Zigbee2MQTT:info  2020-08-11 15:35:38: MQTT publish: topic 'zigbee2mqtt/hue-light-chambre', payload '{"state":"ON","brightness":1,"linkquality":55,"update_available":false,"last_seen":"2020-08-11T15:35:38+02:00"}'

Brightness is still set to 1, but this time the bulb is really on, I can see light coming from it.

FWIW, I can only see this issue with my hue bulbs, no problem with my IKEA bulb.

[Koenkk]

Aug 11 15:32:34 raspberrypi npm[12200]: Zigbee2MQTT:debug 2020-08-11 15:32:34: Received MQTT message on 'zigbee2mqtt/hue-light-chambre/set' with data '{"state": "ON", "transition": 0.5}'

Can you check if it works when not using a transition?

[sylarevan]

OK, I have just removed all transitions from my automations. I will report if it changes anything.

[sylarevan]

Well, so far, so good. I didn't notice any bug since I removed transitions from my automations. Any ideas on what's going on? Not using transitions is not a long term solution, I already have some kind of pressure to get it back ;)

[Koenkk]

@sylarevan then we at least know the transitions are the issue!

Are you able to reproduce the issue from a fresh start of Zigbee2MQTT and provide the herdsman debug log of this? Running with DEBUG=zigbee-herdsman:controller:* should provide the required logging to investigate further.

[sylarevan]

@Koenkk Sorry for this very late answer. I might be wrong, but I am not able to replicate the bug anymore, the proposed fixes finally seem to solve the issue. I have added again the transition setting directly in z2m configuration (and not in my automations, if that makes any difference), and no problem so far.

[github-actions[bot]]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[MasterDevwi]

I'm frequently hitting this bug as well.

[voc0der]

I am hitting this bug now as well. I am beginning to wonder if it happens on light.somearea only when there's 1 light in that area.