Off-by-1 value in events with Trädfri dimmer levels

shutterfreak · February 12, 2019, 8:24pm

There seems to be frequent off-by-1 errors in setting the dimmer value in Trädfri dimmers and Trädfri light remotes. I can confirm it in the Event log, as the values are often off by 1. This also results in the chosen switch value not being highlighted as it doesn’t match the value selected (e.g. click “1”, get “2”).

Here’s an example switch element in home.sitemap:

Switch item=GF_Kitchen_Light_Dimmer label="GK dimmer settings [%f]" mappings=[
  0="Off",1="1%",10="10%",25="25%",50="Half",75="75%",90="90%",100="Full"
]

The Event log (/var/log/openhab2/events.log) reports the following state changes:

2019-02-12 21:11:48.196 [ome.event.ItemCommandEvent] - Item 'GF_Kitchen_Light_Dimmer' received command 1
2019-02-12 21:11:48.203 [nt.ItemStatePredictedEvent] - GF_Kitchen_Light_Dimmer predicted to become 1
2019-02-12 21:11:48.208 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 0 to 1
2019-02-12 21:11:48.209 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 1 to 0
2019-02-12 21:11:48.223 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Toggle changed from OFF to ON
2019-02-12 21:11:48.224 [vent.ItemStateChangedEvent] - tradfri_0100_GATEWAY_ID_65560_brightness changed from 0 to 2
2019-02-12 21:11:48.225 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 0 to 2
2019-02-12 21:11:48.271 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Toggle changed from ON to OFF
2019-02-12 21:11:48.272 [vent.ItemStateChangedEvent] - tradfri_0100_GATEWAY_ID_65560_brightness changed from 2 to 0
2019-02-12 21:11:48.274 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 2 to 0
2019-02-12 21:11:48.321 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Toggle changed from OFF to ON
2019-02-12 21:11:48.322 [vent.ItemStateChangedEvent] - tradfri_0100_GATEWAY_ID_65560_brightness changed from 0 to 1
2019-02-12 21:11:48.323 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 0 to 1
2019-02-12 21:11:50.139 [vent.ItemStateChangedEvent] - tradfri_0100_GATEWAY_ID_65560_brightness changed from 1 to 2
2019-02-12 21:11:50.140 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 1 to 2
2019-02-12 21:11:54.475 [ome.event.ItemCommandEvent] - Item 'GF_Kitchen_Light_Dimmer' received command 90
2019-02-12 21:11:54.480 [nt.ItemStatePredictedEvent] - GF_Kitchen_Light_Dimmer predicted to become 90
2019-02-12 21:11:54.482 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 2 to 90
2019-02-12 21:11:54.484 [vent.ItemStateChangedEvent] - tradfri_0100_GATEWAY_ID_65560_brightness changed from 2 to 91
2019-02-12 21:11:54.484 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 90 to 91
2019-02-12 21:11:56.985 [ome.event.ItemCommandEvent] - Item 'GF_Kitchen_Light_Dimmer' received command 100
2019-02-12 21:11:56.990 [nt.ItemStatePredictedEvent] - GF_Kitchen_Light_Dimmer predicted to become 100
2019-02-12 21:11:56.991 [vent.ItemStateChangedEvent] - GF_Kitchen_Light_Dimmer changed from 91 to 100

I’m running OpenHAB 2.4.0:

openhab> feature:list|grep -i tradfri
esh-binding-tradfri                         │ 0.10.0.oh240     │          │ Started     │ openhab-addons-2.4.0    │
openhab-binding-tradfri                     │ 2.4.0            │ x        │ Started     │ openhab-addons-2.4.0    │ TRÅDFRI Binding

Is this a bug in the TRÄDFRI binding?

rossko57 · February 12, 2019, 8:32pm

I doubt the dimmer really has 100 steps, so when you get the feedback about its real position, it gets rounded or truncated e.g. like 66.6 to 66

You might find a set of real allowed values by experimentation.

Or perhaps use a Scale transform on incoming values to a set that you define.

shutterfreak · February 12, 2019, 8:49pm

I’m not excluding this, but other apps I frequently use don’t display this behaviour (e.g., Home app on iOS, Eve app).

Here’s the OpenHAB2 event log when using the Home app on an iPhone to set the dimmer value to 1:

2019-02-12 21:43:49.210 [vent.ItemStateChangedEvent] - tradfri_0100_GATEWAY_ID_65553_brightness changed from 1 to 0
2019-02-12 21:43:49.212 [vent.ItemStateChangedEvent] - AT_GuestRoom_Light_Toggle changed from ON to OFF
2019-02-12 21:43:49.212 [vent.ItemStateChangedEvent] - AT_GuestRoom_Light_Dimmer changed from 1 to 0
2019-02-12 21:43:50.858 [vent.ItemStateChangedEvent] - tradfri_0100_GATEWAY_ID_65553_brightness changed from 0 to 1
2019-02-12 21:43:50.859 [vent.ItemStateChangedEvent] - AT_GuestRoom_Light_Toggle changed from OFF to ON
2019-02-12 21:43:50.860 [vent.ItemStateChangedEvent] - AT_GuestRoom_Light_Dimmer changed from 0 to 1
2019-02-12 21:43:52.217 [vent.ItemStateChangedEvent] - tradfri_0100_GATEWAY_ID_65553_brightness changed from 1 to 0
2019-02-12 21:43:52.219 [vent.ItemStateChangedEvent] - AT_GuestRoom_Light_Toggle changed from ON to OFF
2019-02-12 21:43:52.221 [vent.ItemStateChangedEvent] - AT_GuestRoom_Light_Dimmer changed from 1 to 0

It’s another light that’s being manipulated here, but you see that the state neatly toggles between 0 and 1 (1%), as opposed to the almost always off-by-1 state updates in OpenHAB.

rossko57 · February 12, 2019, 9:04pm

To complete the circle, what do these other apps think when openHAB sets a dimmer to “1” ?

Might have to use debug on the binding, see what it’s really sending over the wire.

cweitkamp · February 12, 2019, 9:10pm

Hi Olivier,

I think both of you are right. The TRÅDFRI API expects a value from 0 to 254. We have to map it to a range from 0 to 100. Therefore rounding is used. But similar to this Hue binding issue, the binding uses rounding inconsistently. Meaning it uses Math.round() for outgoing values (from OH2 towards TRÅDFRI) and Math.ceil() for incoming values. Changing the outgoing calculation to Math.floor() will solve this issue. I will prepare a fix for it.

shutterfreak · February 13, 2019, 8:12am

They don’t as ‘1’ cannot be set, apparently due to a rounding error. But if I set a value in OpenHAB then other apps will pick up the changes. At least that’s the case for the Trädfri binding.

cweitkamp · February 13, 2019, 2:14pm

Done.

https://github.com/openhab/openhab2-addons/pull/4895

shutterfreak · February 13, 2019, 3:54pm

I suppose you want to use either Math.floor() or Math.round() in outgoing and incoming messages, instead of using 2 different rounding methods?

Anyway, I’m looking forward to see the fix deployed.

cweitkamp · February 13, 2019, 4:04pm

No, that will not work smoothly. The problem is the edge case when we receive a 1 for the brightness from TRADFRI. That will result in 0 (Math.round(1 / 2.54) = 0) after rounding and will show the bulb as OFF.

shutterfreak · February 13, 2019, 6:11pm

I see. So it’s either (a) making use of a lookup table or (b) use a combination of Math.floor() for outbound and Math.ceil() for inbound levels.

Likewise I suppose the Trädfri remote / dimmer battery levels are also quantised and may have a similar issue:

2019-02-13 18:25:52.427 [vent.ItemStateChangedEvent] - TradfriDimmer1BatteryLevel changed from 74 to 60
2019-02-13 18:25:52.429 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 74 to 60
2019-02-13 18:26:06.000 [vent.ItemStateChangedEvent] - TradfriDimmer1BatteryLevel changed from 60 to 74
2019-02-13 18:26:06.001 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 60 to 74

cweitkamp · February 14, 2019, 6:36pm

Yes, I think so. But I could not figure out how it is supposed to work.

shutterfreak · February 14, 2019, 8:46pm

From the reported battery levels, it seems to me that there are 7 or probably 8 discreet battery levels reported by OpenHAB. Right now I have seen: (NULL), 34%, 47%, 60%, 74%, 87% and 100%.

And sometimes battery levels seem to jump between 2 states:

2019-02-13 13:48:55.097 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 60 to 74
2019-02-13 14:06:48.512 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 74 to 60
2019-02-13 16:51:12.174 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 60 to 74
2019-02-13 16:51:33.067 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 74 to 60
2019-02-13 17:47:06.238 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 60 to 74
2019-02-13 18:25:52.429 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 74 to 60
2019-02-13 18:26:06.001 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 60 to 74
2019-02-13 18:49:26.270 [vent.ItemStateChangedEvent] - tradfri_0820_GATEWAY_ID_65559_battery_level changed from 74 to 60

UPDATE - from all data I collected so far, I can conclude the following:

There seems to be only a few battery level steps: 100%, 87%, 74%, 60%, 47%, 34% I can relate; likewise I’m expecting to see 20% and 7% (to be confirmed).
The “low battery” channel appears to be ON when the battery level drops below 50% (actually, 47% due to the discrete battery level steps)
Sometimes the battery level transitions between 2 discrete levels (see the line for Dimmer 1 in green)

Here’s the Influx data rendered in Grafana spanning 9 days and covering 5 Trädfri remotes and one dimmer:

The green zone relates to 50% or more battery level (when the “low battery” signal is off). The red zone relates to less than 10% battery level.

cweitkamp · February 21, 2019, 6:35am

@shutterfreak Thanks for the update. Indeed some nice information. I never persisted my battery levels, thus a deeper analysis was not possible.

Are you talking about the OH2 “low battery” channel? I guess not because this only will be ON if the battery level drops below 10% (see TradfriWirelessDeviceData.java).

shutterfreak · February 21, 2019, 7:43am

The OH2 :battery_low channel apparently switches ON earlier than that, as I get warnings when the :battery_level drops below 50%.

I define dimmers and wireless remotes as follows:

Number TradfriDimmer1BatteryLevel "Dimmer 1 - Kitchen [%.0f %%]" (BatteryOperated, gBattery) {
    channel="tradfri:0820:GATEWAY_ID:65559:battery_level"
}
Switch TradfriDimmer1BatteryLevel_Low "Dimmer 1 - Kitchen" (gBattery) {
    channel="tradfri:0820:GATEWAY_ID:65559:battery_low"
}

I then read the battery level and conditionally display the low battery warning as follows in my sitemap:

Frame label="Dimmers" icon="wallswitch" {
	Default icon="battery"  item=TradfriDimmer1BatteryLevel
	Text    icon="error"    item=TradfriDimmer1BatteryLevel  label="Low battery [%s %%]"  visibility=[TradfriDimmer1BatteryLevel_Low == ON]
}

As you can see, the “Low battery” warning appears earlier:

FWIW - I’m running OH2.5.0M1 for about a week now.

shutterfreak · February 24, 2019, 10:36am

Is there a way for me to selectively enable the debug log level fo the Trädfri binding?

cweitkamp · February 24, 2019, 4:19pm

Yes, of course. To enable logging do the following steps:

open the Karaf console: https://www.openhab.org/docs/administration/console.html
set the logging level to TRACE for binding ( log:set TRACE org.openhab.binding.tradfri , or on older builds log:set TRACE org.eclipse.smarthome.binding.tradfri )
https://www.openhab.org/docs/administration/logging.html#defining-what-to-log
view log with log:tail or log:tail org.openhab.binding.tradfri

shutterfreak · February 28, 2019, 7:03pm

Something weird happens.

On Paper UI the battery_low channels are OFF:

While they seem to be ON on my sitemap (Basic UI).

So I’m not sure where the problem originates from. Is there somewhere a concealed Number transform at play?

cweitkamp · March 2, 2019, 8:28am

Why are you thinking the battery_low channels state ON in your Basic UI sitemap? I cannot find them in your screenshots.

shutterfreak · March 2, 2019, 11:13am

I added the battery_low channel items for debugging purposes so you could see for yourself.

home.items: see one of my previous posts in this thread.

home.sitemap:

	Frame label="Low battery level items" icon="battery-10" {
		Default item=TradfriDimmer1BatteryLevel_Low			label="Low battery indicator [%s]"
		Default item=TradfriRemoteControl1BatteryLevel_Low	label="Low battery indicator [%s]"
		Default item=TradfriRemoteControl2BatteryLevel_Low	label="Low battery indicator [%s]"
		Default item=TradfriRemoteControl3BatteryLevel_Low	label="Low battery indicator [%s]"
		Default item=TradfriRemoteControl4BatteryLevel_Low	label="Low battery indicator [%s]"
		Default item=TradfriRemoteControl5BatteryLevel_Low	label="Low battery indicator [%s]"
	}
	Frame label="Low battery level items" icon="battery-10" {
		Text item=TradfriDimmer1BatteryLevel_Low			label="Low battery indicator [%s]"
		Text item=TradfriRemoteControl1BatteryLevel_Low	label="Low battery indicator [%s]"
		Text item=TradfriRemoteControl2BatteryLevel_Low	label="Low battery indicator [%s]"
		Text item=TradfriRemoteControl3BatteryLevel_Low	label="Low battery indicator [%s]"
		Text item=TradfriRemoteControl4BatteryLevel_Low	label="Low battery indicator [%s]"
		Text item=TradfriRemoteControl5BatteryLevel_Low	label="Low battery indicator [%s]"
	}
	Frame label="Dimmers" icon="wallswitch" {
		Default icon="battery"      item=TradfriDimmer1BatteryLevel
		Text icon="error" label="Low battery [%s %%]"     	item=TradfriDimmer1BatteryLevel visibility=[TradfriDimmer1BatteryLevel_Low == ON]
	}
	Frame label="Remote switches" icon="light" {
		Default icon="battery"      item=TradfriRemoteControl1BatteryLevel
		Text icon="error" label="Low battery [%s %%]"	item=TradfriRemoteControl1BatteryLevel visibility=[TradfriRemoteControl1BatteryLevel_Low == ON]
		Default icon="battery"      item=TradfriRemoteControl2BatteryLevel
		Text icon="error" label="Low battery [%s %%]"	item=TradfriRemoteControl2BatteryLevel visibility=[TradfriRemoteControl2BatteryLevel_Low == ON]
		Default icon="battery"      item=TradfriRemoteControl3BatteryLevel
		Text icon="error" label="Low battery [%s %%]"	item=TradfriRemoteControl3BatteryLevel visibility=[TradfriRemoteControl3BatteryLevel_Low == ON]
		Default icon="battery"      item=TradfriRemoteControl4BatteryLevel
		Text icon="error" label="Low battery [%s %%]"	item=TradfriRemoteControl4BatteryLevel visibility=[TradfriRemoteControl4BatteryLevel_Low == ON]
		Default icon="battery"      item=TradfriRemoteControl5BatteryLevel
		Text icon="error" label="Low battery [%s %%]"	item=TradfriRemoteControl5BatteryLevel visibility=[TradfriRemoteControl5BatteryLevel_Low == ON]
	}

Output:

Note: some items display a text icon; I forgot to assign a default icon to those (fixed now).

cweitkamp · March 2, 2019, 5:01pm

Okay, I see. But to be honest, I have no ides what went wrong. Sry.