search

openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.58k forks source link

[deconz] openHab does not set brightness correctly #10858

Closed junalmeida closed 1 year ago

junalmeida commented 3 years ago

Expected Behavior

openHab should set the correct brightness.

Current Behavior

When I change brightness using openhab item, it does not set the correct brightness, however if I call api endpoint /lights/number, I can see the brightness (bri property) set to the expected value. If then I call PUT /lights/number/state with { bri: 254 } then the bulb finally goes to full brightness. This also happens when bulb is initially in full brightness and I want to reduce it, it won't fade untill I call manually the api endpoint. Using the bulbs manually in phoscon app or by calling the api seems to work, so there should be something to investigate on openhab site. I'm happy to send logs if you direct me to what logs should I get.

Possible Solution

Steps to Reproduce (for Bugs)

  1. Have an item connected to an ikea bulb channel in deconz
  2. Set item brightness through openhab3 UI

Context

Your Environment

MHerbst commented 3 years ago

I have tested it with an LED strip from Dresden Consulting and this seems to work correctly.

Can you give me some more information? I think it would be helpful to have the brightness value set in OH and the complete JSON structure that is returned for this bulb.

How is the thing defined? Does it only contain a brightness channel or is it al color device with a color channel?

junalmeida commented 3 years ago

@MHerbst 

UID: deconz:colorlight:000000000000:000d6ffffe1be41701
label: Ikea Light 1 (IKEA of Sweden)
thingTypeUID: deconz:colorlight
configuration:
  transitiontime: 9
  id: "2"
  colormode: xy
  lastSeenPolling: 1440
bridgeUID: deconz:deconz:000000000000

This is the thing definition; I have 3 lights like this, all of them behave erratic. It is a color device with xy color channel.

And...

{
  "colorcapabilities": 8,
  "etag": "87a139e64a214b76b28bb74308558db0",
  "hascolor": true,
  "lastannounced": "2021-06-13T12:57:25Z",
  "lastseen": "2021-06-13T12:57Z",
  "manufacturername": "IKEA of Sweden",
  "modelid": "TRADFRI bulb E26 CWS opal 600lm",
  "name": "Ikea Light 1",
  "state": {
    "alert": "none",
    "bri": 254,
    "colormode": "xy",
    "effect": "none",
    "hue": 0,
    "on": true,
    "reachable": true,
    "sat": 0,
    "xy": [
      0.458,
      0.41
    ]
  },
  "swversion": "1.3.002",
  "type": "Color light",
  "uniqueid": "00:0d:6f:ff:fe:1b:e4:17-01"
}

This is what the API returns if I manually call /lights/2/state

MHerbst commented 3 years ago

Sorry, I forgot an important thing. How are your items defined. If you have an item of type color than it has three settings for hue, saturation and brightness. What happens if you set the brightness? Is the "bri" value changed?

You can also try to change the colormode in the thing definition to hsb. Does this help?

junalmeida commented 3 years ago

This is the item: image

It is connected to 3 channels using FOLLOW profile image

Yes, when I change only brightness, I can see the bri value changing, but the bulb only "blinks" and goes back to the initial brightness.

MHerbst commented 3 years ago

Can you try to set the brightness of a thing directly and not with the FOLLOW profile? Is it the same behavior or different?

If it is the same problem, please enable TRACE log mode, change the brightness and post the log file.

BTW: did you try to set brightness directly via the DECONZ REST API? If the bulb shows the same behavior, I would think that there is an incompatibility between the bulb and DECONZ.

junalmeida commented 3 years ago

If I set directly using deconz api it works as expected. Not sure if you mean to set it using the thing in openhab, if you mean to have a separate Item connected to the thing channel on default profile I already did that and the erratic behavior is the same.

MHerbst commented 3 years ago

Not sure if you mean to set it using the thing in openhab, if you mean to have a separate Item connected to the thing channel on default profile I already did that and the erratic behavior is the same.

That's exactly what I meant.

Can you creat log file with TRACE messages. Would like to see what the binding sends.

junalmeida commented 3 years ago

So what I did below is: I turn the light on, then I hit by down brightness button a couple of times, then it turned off (because I reached brightness=0). Then I pushed the brightness up button couple of times, brightness is now 100 and yet the actual brightness of the bulb is low, very dimmed. 

2021-06-23 10:42:14.612 [INFO ] [openhab.event.ChannelTriggeredEvent ] - deconz:switch:000000000000:d0cf5efffe0df8e5011000:buttonevent triggered 2002
2021-06-23 10:42:14.630 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'LightAction' received command setBrightness|DiningTableColor|50
2021-06-23 10:42:14.665 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'DiningTableColor' received command 0,0,100
2021-06-23 10:42:14.674 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'DiningTableColor' predicted to become 0,0,100
==> /var/log/openhab/openhab.log <==
2021-06-23 10:42:15.208 [TRACE] [nternal.netutils.WebSocketConnection] - Websocket$1624366360265-1 received raw data: {"attr":{"colorcapabilities":8,"id":"5","lastannounced":"2021-06-22T12:34:45Z","lastseen":"2021-06-23T15:42Z","manufacturername":"IKEA of Sweden","modelid":"TRADFRI bulb E26 CWS opal 600lm","name":"Ikea Light 3","swversion":"1.3.002","type":"Color light","uniqueid":"00:0d:6f:ff:fe:22:65:c5-01"},"e":"changed","id":"5","r":"lights","t":"event","uniqueid":"00:0d:6f:ff:fe:22:65:c5-01"}
2021-06-23 10:42:15.210 [TRACE] [z.internal.handler.LightThingHandler] - deconz:colorlight:000000000000:000d6ffffe2265c501 received LightMessage{hascolor=null, ctmax=null, ctmin=null, type=null, state=null, e='changed', r='LIGHTS', t='event', id='5', manufacturername='', modelid='', name='', swversion='', ep='', uniqueid='00:0d:6f:ff:fe:22:65:c5-01'}
2021-06-23 10:42:15.333 [TRACE] [nternal.netutils.WebSocketConnection] - Websocket$1624366360265-1 received raw data: {"e":"changed","id":"2","r":"sensors","state":{"buttonevent":2002,"lastupdated":"2021-06-23T15:42:15.330"},"t":"event","uniqueid":"d0:cf:5e:ff:fe:0d:f8:e5-01-1000"}
2021-06-23 10:42:15.335 [TRACE] [ernal.handler.SensorBaseThingHandler] - deconz:switch:000000000000:d0cf5efffe0df8e5011000 received SensorMessage{type='', config=null, state=SensorState{dark=null, daylight=null, lightlevel=null, lux=null, temperature=null, humidity=null, open=null, fire=null, water=null, alarm=null, tampered=null, vibration=null, carbonmonoxide=null, pressure=null, presence=null, power=null, battery=null, consumption=null, voltage=null, current=null, status=null, buttonevent=2002, gesture=null, valve=null, windowopen='null', lastupdated='2021-06-23T15:42:15.330', xy=null}, e='changed', r='SENSORS', t='event', id='2', manufacturername='', modelid='', name='', swversion='', ep='', lastseen='null', uniqueid='d0:cf:5e:ff:fe:0d:f8:e5-01-1000'}
2021-06-23 10:42:15.339 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger '1' of rule '1500c58e7d' is triggered.
2021-06-23 10:42:15.353 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '1500c58e7d' is executed.
2021-06-23 10:42:15.357 [DEBUG] [e.automation.internal.RuleEngineImpl] - The trigger '1' of rule '5587a2ffe7' is triggered.
2021-06-23 10:42:15.367 [DEBUG] [.openhab.core.model.script.lights.js] - executing setBrightness|DiningTableColor|50
2021-06-23 10:42:15.375 [DEBUG] [.openhab.core.model.script.lights.js] - DiningTableColor - 0,0,100
2021-06-23 10:42:15.378 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '5587a2ffe7' is executed.
2021-06-23 10:42:15.417 [TRACE] [internal.handler.DeconzBridgeHandler] - Sending {"on":true,"bri":254,"xy":[0.31271591,0.32900149999999995],"transitiontime":90} via PUT to http://smarthome:80/api/0D234FD02F/lights/5/state
2021-06-23 10:42:15.418 [TRACE] [internal.handler.DeconzBridgeHandler] - Sending {"on":true,"bri":254,"xy":[0.31271591,0.32900149999999995],"transitiontime":90} via PUT to http://smarthome:80/api/0D234FD02F/lights/4/state
2021-06-23 10:42:15.418 [TRACE] [internal.handler.DeconzBridgeHandler] - Sending {"on":true,"bri":254,"xy":[0.31271591,0.32900149999999995],"transitiontime":90} via PUT to http://smarthome:80/api/0D234FD02F/lights/2/state
2021-06-23 10:42:15.424 [TRACE] [ernal.handler.DeconzBaseThingHandler] - Result code=200, body=[{"success":{"/lights/5/state/on":true}},{"success":{"/lights/5/state/bri":254}},{"success":{"/lights/5/state/xy":[0.312716,0.329001]}}]
2021-06-23 10:42:15.433 [TRACE] [ernal.handler.DeconzBaseThingHandler] - Result code=200, body=[{"success":{"/lights/2/state/on":true}},{"success":{"/lights/2/state/bri":254}},{"success":{"/lights/2/state/xy":[0.312716,0.329001]}}]
2021-06-23 10:42:15.445 [TRACE] [ernal.handler.DeconzBaseThingHandler] - Result code=200, body=[{"success":{"/lights/4/state/on":true}},{"success":{"/lights/4/state/bri":254}},{"success":{"/lights/4/state/xy":[0.312716,0.329001]}}]
==> /var/log/openhab/events.log <==
2021-06-23 10:42:15.338 [INFO ] [openhab.event.ChannelTriggeredEvent ] - deconz:switch:000000000000:d0cf5efffe0df8e5011000:buttonevent triggered 2002
2021-06-23 10:42:15.354 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'LightAction' received command setBrightness|DiningTableColor|50
2021-06-23 10:42:15.379 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'DiningTableColor' received command 0,0,100
2021-06-23 10:42:15.390 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'DiningTableColor' predicted to become 0,0,100
==> /var/log/openhab/openhab.log <==
2021-06-23 10:42:16.368 [TRACE] [nternal.netutils.WebSocketConnection] - Websocket$1624366360265-1 received raw data: {"e":"changed","id":"5","r":"lights","state":{"alert":null,"bri":2,"colormode":"xy","effect":"none","hue":0,"on":true,"reachable":true,"sat":0,"xy":[0.3127,0.329]},"t":"event","uniqueid":"00:0d:6f:ff:fe:22:65:c5-01"}
2021-06-23 10:42:16.370 [TRACE] [z.internal.handler.LightThingHandler] - deconz:colorlight:000000000000:000d6ffffe2265c501 received LightMessage{hascolor=null, ctmax=null, ctmin=null, type=null, state=LightState{reachable=true, on=true, bri=2, alert='null', colormode='xy', effect='none', effectSpeed=null, ontime=null, hue=0, sat=0, ct=null, xy=[0.3127, 0.329], transitiontime=null}, e='changed', r='LIGHTS', t='event', id='5', manufacturername='', modelid='', name='', swversion='', ep='', uniqueid='00:0d:6f:ff:fe:22:65:c5-01'}
2021-06-23 10:42:23.781 [TRACE] [nternal.netutils.WebSocketConnection] - Websocket$1624366360265-1 received raw data: {"attr":{"colorcapabilities":8,"id":"2","lastannounced":"2021-06-22T12:34:45Z","lastseen":"2021-06-23T15:42Z","manufacturername":"IKEA of Sweden","modelid":"TRADFRI bulb E26 CWS opal 600lm","name":"Ikea Light 1","swversion":"1.3.002","type":"Color light","uniqueid":"00:0d:6f:ff:fe:1b:e4:17-01"},"e":"changed","id":"2","r":"lights","t":"event","uniqueid":"00:0d:6f:ff:fe:1b:e4:17-01"}
2021-06-23 10:42:23.783 [TRACE] [z.internal.handler.LightThingHandler] - deconz:colorlight:000000000000:000d6ffffe1be41701 received LightMessage{hascolor=null, ctmax=null, ctmin=null, type=null, state=null, e='changed', r='LIGHTS', t='event', id='2', manufacturername='', modelid='', name='', swversion='', ep='', uniqueid='00:0d:6f:ff:fe:1b:e4:17-01'}
2021-06-23 10:42:40.883 [TRACE] [internal.handler.DeconzBridgeHandler] - deconz:deconz:000000000000 starts refreshing the fullStateCache
2021-06-23 10:42:42.412 [TRACE] [nternal.netutils.WebSocketConnection] - Websocket$1624366360265-1 received raw data: {"attr":{"id":"3","lastannounced":null,"lastseen":"2021-06-23T15:42Z","manufacturername":"SONOFF","modelid":"01MINIZB","name":"Fireplace","swversion":"20200927","type":"On/Off light","uniqueid":"84:2e:14:ff:fe:65:50:5b-01"},"e":"changed","id":"3","r":"lights","t":"event","uniqueid":"84:2e:14:ff:fe:65:50:5b-01"}
2021-06-23 10:42:42.414 [TRACE] [z.internal.handler.LightThingHandler] - deconz:onofflight:000000000000:842e14fffe65505b01 received LightMessage{hascolor=null, ctmax=null, ctmin=null, type=null, state=null, e='changed', r='LIGHTS', t='event', id='3', manufacturername='', modelid='', name='', swversion='', ep='', uniqueid='84:2e:14:ff:fe:65:50:5b-01'}
MHerbst commented 3 years ago

From the log I can't see a problem caused by the binding. The binding sends brightness values of 254 to Deconz and Deconz confirms these values. Maybe Deconz has a problem if it receives several messages at the same time. You can see in the log that the result messages appear in a different order.

junalmeida commented 3 years ago

@MHerbst ok, but even if I stop pressing buttons for a couple of seconds to then press the brightness up button again, nothing changes. Isn't it supposed to go full brightness in that scenario? The behavior is the same either sending commands fast or slowly.

MHerbst commented 3 years ago

I can only judge it now based on the log output and there I don't see any error in the binding. Maybe @j-n-k has an idea.

J-N-K commented 3 years ago

I have no idea what the rule is doing. What exactly is the "pushing the button" supposed to do? Please show the rule.

I only see one command to the deconz gateway and that sets the brightness to 254 (what is acknowledged with 200/OK).

The received websocket event shows a lower brightness. This could be related to the transition time, try setting that to 0.

I don't think you can overload the gateway with three commands. I'm not sure what happens if you send multiple commands within the time that is needed fo reach the final state of the previous command. This could also be a bug in deconz, you can enable deconz logs to see what is happening there. What deconz version are you using? Did you try upgrading to lastet deconz stable?

junalmeida commented 3 years ago

I'm always using latest deconz beta from their docker container. I can try setting the transition time to 0, however I remember I've already done that before. And yes, you are correct, I can see on logs a 200 ok when setting the brightness to 254. But it doesn't work when this comes from openhab. When I set brightness using phoscon web app it works.

lsiepel commented 1 year ago

@junalmeida can i assume this issue is fixed ?

jlaur commented 1 year ago

@lsiepel - watch out with deCONZ issues. There are a lot of issues that still exist. The binding was forked to SmartHome/J on Feb 18, 2021, and since then many issues were solved, while the official binding has been mostly left behind. We should probably try to backport the fixes made here (or delete the binding).

lsiepel commented 1 year ago

Ah, thanks. Didn't know that. Is there a discussion at maintainers level to this topic? As i think it is rather confusiong have a binding maintained at two places. Where do users go for issues etc.

jlaur commented 1 year ago

Ah, thanks. Didn't know that. Is there a discussion at maintainers level to this topic? As i think it is rather confusiong have a binding maintained at two places. Where do users go for issues etc.

No, but see also https://github.com/openhab/openhab-addons/issues/13706#issuecomment-1321076327 and https://github.com/openhab/openhab-addons/pull/12223#issuecomment-1326870016.

jlaur commented 1 year ago

Ah, thanks. Didn't know that. Is there a discussion at maintainers level to this topic? As i think it is rather confusiong have a binding maintained at two places. Where do users go for issues etc.

14124

stale[bot] commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.