[homekit] Homekit sending ON and 100 Command

now I got the right log, I guess. I de-/reinstalled the binding via PaperUI

openhab> log:display | grep OHItemProxy
13:40:29.433 [TRACE] [essories.HomekitCharacteristicFactory] - createCharacteristic, type BRIGHTNESS item Item:org.openhab.io.homekit.internal.HomekitOHItemProxy@272c91b8 HomeKit type:LIGHTBULB HomeKit characteristic:BRIGHTNESS
13:40:29.441 [TRACE] [essories.HomekitCharacteristicFactory] - createCharacteristic, type BRIGHTNESS item Item:org.openhab.io.homekit.internal.HomekitOHItemProxy@272c91b8 HomeKit type:LIGHTBULB HomeKit characteristic:BRIGHTNESS
13:40:29.450 [TRACE] [essories.HomekitCharacteristicFactory] - createCharacteristic, type BRIGHTNESS item Item:org.openhab.io.homekit.internal.HomekitOHItemProxy@2301342f HomeKit type:LIGHTBULB HomeKit characteristic:BRIGHTNESS
13:40:29.455 [TRACE] [essories.HomekitCharacteristicFactory] - createCharacteristic, type BRIGHTNESS item Item:org.openhab.io.homekit.internal.HomekitOHItemProxy@2301342f HomeKit type:LIGHTBULB HomeKit characteristic:BRIGHTNESS
13:42:08.859 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2301342f, command type ON_COMMAND, command state ON. cache state after: {ON_COMMAND=ON}
13:42:08.862 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2301342f, command type BRIGHTNESS_COMMAND, command state 41. cache state after: {ON_COMMAND=ON, BRIGHTNESS_COMMAND=41}
13:42:08.863 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send OnOff command for item knopf2 (Type=DimmerItem, State=100, Label=knopf2, Category=null) with value ON
13:42:08.864 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send Brightness command for item knopf2 (Type=DimmerItem, State=100, Label=knopf2, Category=null) with value 41
13:42:12.090 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2301342f, command type ON_COMMAND, command state OFF. cache state after: {ON_COMMAND=OFF}
13:42:12.192 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - timer of 100 ms is over, sending the command
13:42:12.192 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send OnOff command for item knopf2 (Type=DimmerItem, State=41, Label=knopf2, Category=null) with value OFF
13:42:13.418 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2301342f, command type ON_COMMAND, command state ON. cache state after: {ON_COMMAND=ON}
13:42:13.419 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2301342f, command type BRIGHTNESS_COMMAND, command state 100. cache state after: {ON_COMMAND=ON, BRIGHTNESS_COMMAND=100}
13:42:13.419 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send OnOff command for item knopf2 (Type=DimmerItem, State=0, Label=knopf2, Category=null) with value ON
13:42:14.917 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2301342f, command type ON_COMMAND, command state OFF. cache state after: {ON_COMMAND=OFF}
13:42:15.018 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - timer of 100 ms is over, sending the command
13:42:15.019 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send OnOff command for item knopf2 (Type=DimmerItem, State=100, Label=knopf2, Category=null) with value OFF
openhab>

I observed something. Maybe interesting for you: The delay is now 5000ms. If I click the icon in the home app, it stays on the past value (eg. 65%) for the 5 seconds and then goes back to 100%.

here the logs:
openhab> log:clear
openhab> log:display
13:52:13.184 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2a81e6f0, command type ON_COMMAND, command state ON. cache state after: {ON_COMMAND=ON}
13:52:13.186 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2a81e6f0, command type BRIGHTNESS_COMMAND, command state 100. cache state after: {ON_COMMAND=ON, BRIGHTNESS_COMMAND=100}
13:52:13.186 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send OnOff command for item knopf2 (Type=DimmerItem, State=NULL, Label=knopf2, Category=null) with value ON
13:52:13.206 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘knopf2’ received command ON
13:52:13.216 [INFO ] [smarthome.event.ItemStateChangedEvent] - knopf2 changed from NULL to 100
13:52:18.519 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2a81e6f0, command type ON_COMMAND, command state ON. cache state after: {ON_COMMAND=ON}
13:52:18.519 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2a81e6f0, command type BRIGHTNESS_COMMAND, command state 64. cache state after: {ON_COMMAND=ON, BRIGHTNESS_COMMAND=64}
13:52:18.519 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send OnOff command for item knopf2 (Type=DimmerItem, State=100, Label=knopf2, Category=null) with value ON
13:52:18.520 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send Brightness command for item knopf2 (Type=DimmerItem, State=100, Label=knopf2, Category=null) with value 64
13:52:18.521 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘knopf2’ received command ON
13:52:18.522 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘knopf2’ received command 64
13:52:18.536 [INFO ] [smarthome.event.ItemStateChangedEvent] - knopf2 changed from 100 to 64
13:52:22.897 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2a81e6f0, command type ON_COMMAND, command state OFF. cache state after: {ON_COMMAND=OFF}
13:52:24.535 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2a81e6f0, command type ON_COMMAND, command state ON. cache state after: {ON_COMMAND=ON}
13:52:27.900 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - timer of 5000 ms is over, sending the command
13:52:27.901 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send OnOff command for item knopf2 (Type=DimmerItem, State=64, Label=knopf2, Category=null) with value ON
13:52:27.902 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘knopf2’ received command ON
13:52:27.906 [INFO ] [smarthome.event.ItemStateChangedEvent] - knopf2 changed from 64 to 100

good logs. so, it works as designed. binding gets ON and Brightness=100 from home app and sends only ON to the Item

13:52:13.186 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - add command to command cache: item org.openhab.io.homekit.internal.HomekitOHItemProxy@2a81e6f0, command type BRIGHTNESS_COMMAND, command state 100. cache state after: {ON_COMMAND=ON, BRIGHTNESS_COMMAND=100}
13:52:13.186 [TRACE] [o.homekit.internal.HomekitOHItemProxy] - send OnOff command for item knopf2 (Type=DimmerItem, State=NULL, Label=knopf2, Category=null) with value ON
13:52:13.206 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘knopf2’ received command ON
13:52:13.216 [INFO ] [smarthome.event.ItemStateChangedEvent] - knopf2 changed from NULL to 100

Knopf2 say also that it has received ON command (no brightness)… but than for some reason it changes the brightness from NULL to 100 or later from 64 to 100.

do you have any rules? or maybe device itself set brightness to 100 on “On” event?

btw, you can reduce delay back to 50ms. home app sends commands within 5ms

It‘s a plane installation in Debian (as a VM on Paralles running on a Mac). There are no rules. And there isn‘t any hardware attached either. There are just two items defined in one items file.

ok. i checked the source code one more time. it is normal logic.
the complete flow looks like this

  1. home app sends 2 commands: “ON” and “100%” brightness
  2. homekit binding filters the “100%” command and keep only “ON” command. it sends “ON” command to the dimmerItem
  3. DimmerItem receives “ON” command and according to openhab-core logic it set state brightness = 100. important, it is a state change and not a command, and hence should not trigger any actions or commands to other bindings.
  4. your device, e.g. KNX dimmer, receives only “ON” command via KNX binding
  5. your device reports back the brightness level, which gets updated on Dimmer item

to me, the device logic should work as configured for “ON”, e.g. soft launch (slow increase of brightness) or restore previous brightness

an alternative would be to filter “ON” commands and keep only brightness (if you device understand to swicht the light on if brightness is set to 100). for this replace
dimmerMode="filterOnExceptBrightness1002
with
dimmerMode="filterOn"

I guess, I found the problem. I just added a simple sitemap with a slider and a switch, both attached to the very same item “knopf2”. When I dim with the “Basic UI” the light to 50%, turn it off and on (still in the Basic UI), it jumps back to 100%. I’m pretty sure it will change, as soon as I use a physical ZWave Dimmer that recalls its old value.

I will keep you posted.

Thanks for your help and sorry for the hassle.

I missed this comment of you. You are absolutely right. The code is fine. The problem is the missing hardware.

It is now installed on the productive system. Almost everything works. Well done! Thanks.

I made a few observations and have a few questions (if you still have time and energy):

1 )
Turning on a dimmable actuator (which had a last value of 50%) by clicking on the icon in the home app, shows first 100%, then 50% as soon as the actuator updates its state. The actuator never goes to 100%. Can we eliminate the short presentation of the false “100%”?

2 )
It’s hardly possible now to dim to 100%. I understand that this is due to the workaround. But there are still many situations where the user wants 100%. And “navigating” to 99% is far from practical. Is there any configuration possible, so that the user still can voluntarily go to 100%?

Both 1) and 2) worked with NodeRed. And I guess it works with homebridge in combination with the “homebridge-mqttthing” plugin and mosquitto. (I haven’t yet connected the openhab item with the MQTT broker - will do this asap. But you can already see the dimmer accessory in homebridge and controlling it flawlessly with the home app.

3 )
on the pi (its running raspian and I installed openhab with the apt packages) in items files openhab only accepts ’ . If I use " the item disappears in the PaperUI and HomeKit.
{homekit='Lighting, Lighting.Brightness' [dimmerMode="filterOnExceptBrightness100"]}

On my test environment it works with " . This is how its documented in the documentation on openhab.org.
{homekit="Lighting, Lighting.Brightness" [dimmerMode="filterOnExceptBrightness100"]}

Any ideas?

thank you Simon for the analysis! it helps a lot to make homekit binding bettet.
i will take a look on your points.

but can i ask you to test in meantime it with

dimmerMode="filterOn"

this mode reassembles the logic of openhab-homebridge solution which basically always sends “brightness” and sends “ON” only if there no brightness update in the last 100ms. this could solve 2) but it will probably put dimmer always on 100% on “ON” event.

Thanks Eugen.

My test results using:
dimmerMode="filterOn"

This solves my “2 )”.

But it obviously now always goes back to 100%.

PS1 )
Just to be sure we talk about the same: My observation regarding the flawless operation of homebridge is based on the installation of hombridge and the verified homebridge plugin MQTTTHING and the MQTT broker mosquitto. Openhab is not involved at all (for now). It only shows that it is possible to tackle this HomeKit accessory with a smart home platform similar to openhab.
https://github.com/arachnetech/homebridge-mqttthing#readme

The homebridge plugin OPENHAB2-COMPLETE from @steilerDev does show very similar shortcomings than the current openhab add-on we are discussing here.

PS2 )
Miraculously openhab (on my raspian installation) now accepts " again. I cannot replicate his again.

Let me know, if I can test anything else.
Best,
Simon

Hi Simon,

i checked MQTTTHING but could not find any special logic for Dimmer. the only logic i saw was “if brightness =100 and state=OFF then state =ON” and the similar for brightness=0. basically switch dimmer on/off depending on brightness. but this is not the issue here. home app sends anyway ON/OFF always.

probably i need to dig deeper in homebridge and nodeRed to understand how it works end-to-end.

on your points:

  1. “first 100%, then 50% as soon as the actuator updates its state”
    im afraid i cannot do much here. it is openhab core logic: if dimmer state = ON then set brightness=100.

(State)target.cast(this == ON ? PercentType.HUNDRED : PercentType.ZERO);

we could try to filter brightness=100 update out and dont send it to home app. but it would require pretty complex logic to find which one needs to filtered and which not.
the proper solution would be to fix it in openhab core.

  1. “hardly possible now to dim to 100%”
    i think i have solution for this. the idea - if dimmer is already on and we get brightness=100 then we should update brightness. if dimmer is off and we get brightness=100 then we just sends “ON”.
    the PR for this is already in place
    https://github.com/openhab/openhab-addons/pull/7932

i would like to ask you to test it again, once it is merged.

PS: i should buy a dimmer device to test it myself with the physical device.

It works! Great thanks.

1 Like

I still seem to be seeing the original issue, i.e. even when I have the filterBrightness100 selected I still see both the ON event and the filterBrightness100 events fired when I turn on a dimmer from homekit.

hm. make sure you have the recent homekit binding version (not sure anymore in which version the filter was introduce).
what is in your openhab event log? do you see the events you get from homekit there?

make sure you have the recent homekit binding version

Is it included in the most recent stable (I think 2.5.9) or do I need to switch to snapshot?

what is in your openhab event log? do you see the events you get from homekit there?

I see two events being fired when I turn the dimmer from off to on through homekit:

  • Status changed from OFF to ON
  • Brightness changed from 0 to 100

By the way, thanks for all the work on homekit recently - I have been waiting almost three years for garage door support.

strange. it should filter it out.
can you share your config for that item and the events log? do you have any rules which could set brightness to 100? maybe the device itself doing it.

Okay so it seems to work now, the switch defaults to the previous value when turned on but in HomeKit the item presents as 100% initially then is updated to the correct value after a few seconds.

All of my rules are defined in HomeKit so I don’t think that was causing the issue.

maybe

 autoupdate="false"}

will solve this issue, e.g.

{homekit="Lighting, Lighting.Brightness" [dimmerMode="filterBrightness100"],  autoupdate="false"}

Continuing the discussion from [homekit] Homekit sending ON and 100 Command:

While facing the same issue, I tried your suggestion and added autoupdate statement

{homekit="Lighting, Lighting.Brightness" [dimmermode="filterOnExceptBrightness100"], autoupdate="false"}

Observation is that an ON command is fired before the new brightness level is set.

Not working In OpenHAB 3 :–
value: Lighting,Lighting.Brightness
[dimmerMode=“filterBrightness100”], autoupdate=“false”
config: {}

also tried :–
value: Lighting,Lighting.OnState,Lighting.Brightness
config:
dimmerMode: filterOn, filterBrightness100
autoupdate: false

and tried :–
value: Lighting,Lighting.Brightness
config:
dimmerMode: filterOn
autoupdate: false