Item values are often not updated although new values are received from MQTT

Setup, Configuration and Use Items & Sitemaps
1

Hi guys,

This looks like a bug to me, but a guru opinion would be nice before filing a bug report.

I am having this strange problem that values sent from ESP via mqtt are sometimes parsed and sometimes not.
For each ESP node I have three OH items: VCC, temperature and humidity.

Number Spalnica_temp		"Spalnica [%.1f °C]"  <temperature> (gTemp)  {mqtt="<[mosquitto:/hooks/devices/21/SensorData/Temperature:state:default]"}
Number Spalnica_hum			"Spalnica [%.1f %% RH]" <humidity> (gTemp)  {mqtt="<[mosquitto:/hooks/devices/21/SensorData/Humidity:state:default]"}
Number Spalnica_VCC			"Spalnica [%.1f V]" <voltage> (gMonitoring)  {mqtt="<[mosquitto:/hooks/devices/21/SensorData/VCC:state:default]"}

Number Tine_temp			"Tinetova soba [%.1f °C]"  <temperature> (gTemp)  {mqtt="<[mosquitto:/hooks/devices/20/SensorData/Temperature:state:default]"}
Number Tine_hum				"Tinetova soba [%.1f %% RH]" <humidity> (gTemp)  {mqtt="<[mosquitto:/hooks/devices/20/SensorData/Humidity:state:default]"}
Number Tine_VCC				"Tinetova soba [%.1f V]" <voltage> (gMonitoring)  {mqtt="<[mosquitto:/hooks/devices/20/SensorData/VCC:state:default]"}

Data is sent every 5 minutes. Debug shows that values are correctly received through MQTT, but somehow OH does not parse them and update the values. I noticed this when updated to OH 2.2 snapshot, however it might be happening before,
because I didn’t have persistence graphs and without those, you don’t really notice it. The values on the panels are there, they are just updated rarely…

Below there are two logs: in the first VCC is not parsed, but temperature and humidity are. Next packet received (5 minutes later) only parsed humidity.

I disabled persistence, but it didn’t help. Can I try something else? Should I try another version? Thanx for help!

22:13:39.263 [DEBUG] [.mqttv3.internal.wire.MqttInputStream] - null: Automatic Reconnect Successful: PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/VCC" payload:[hex:332e3338 utf8:"3.38" length:4]
22:13:39.267 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received key=0 message=PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/VCC" payload:[hex:332e3338 utf8:"3.38" length:4]
22:13:39.270 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: new msg avail, notify workAvailable
22:13:39.273 [DEBUG] [.client.mqttv3.internal.CommsReceiver] - openHab-Id: network read message
22:13:39.274 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: call messageArrived key=0 topic=/hooks/devices/21/SensorData/VCC
22:13:39.279 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: notify spaceAvailable
22:13:39.283 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: wait for workAvailable
22:13:40.302 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=1
22:13:40.315 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=46
22:13:40.318 [DEBUG] [.mqttv3.internal.wire.MqttInputStream] - null: Automatic Reconnect Successful: PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/Temperature" payload:[hex:32332e32 utf8:"23.2" length:4]
22:13:40.322 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received key=0 message=PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/Temperature" payload:[hex:32332e32 utf8:"23.2" length:4]
22:13:40.326 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: new msg avail, notify workAvailable
22:13:40.329 [DEBUG] [.client.mqttv3.internal.CommsReceiver] - openHab-Id: network read message
22:13:40.330 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: call messageArrived key=0 topic=/hooks/devices/21/SensorData/Temperature
22:13:40.333 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=1
22:13:40.337 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=43
22:13:40.339 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: notify spaceAvailable
22:13:40.342 [DEBUG] [.mqttv3.internal.wire.MqttInputStream] - null: Automatic Reconnect Successful: PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/Humidity" payload:[hex:35392e36 utf8:"59.6" length:4]
22:13:40.343 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: wait for workAvailable
22:13:40.346 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received key=0 message=PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/Humidity" payload:[hex:35392e36 utf8:"59.6" length:4]
22:13:40.349 [INFO ] [smarthome.event.ItemStateChangedEvent] - Spalnica_temp changed from 23.1 to 23.2
22:13:40.350 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: new msg avail, notify workAvailable
22:13:40.354 [DEBUG] [.client.mqttv3.internal.CommsReceiver] - openHab-Id: network read message
22:13:40.354 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: call messageArrived key=0 topic=/hooks/devices/21/SensorData/Humidity
22:13:40.362 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: notify spaceAvailable
22:13:40.365 [INFO ] [smarthome.event.ItemStateChangedEvent] - Spalnica_hum changed from 59.7 to 59.6
22:13:40.366 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: wait for workAvailable
22:13:41.669 [DEBUG] [org.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
22:14:08.595 [DEBUG] [org.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
22:14:34.307 [DEBUG] [org.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
...



22:17:36.421 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: notify spaceAvailable
22:17:36.424 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: wait for workAvailable
22:17:57.641 [DEBUG] [org.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
22:18:24.909 [DEBUG] [org.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
22:18:29.091 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=1
22:18:29.094 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=38
22:18:29.098 [DEBUG] [.mqttv3.internal.wire.MqttInputStream] - null: Automatic Reconnect Successful: PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/VCC" payload:[hex:332e3338 utf8:"3.38" length:4]
22:18:29.101 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received key=0 message=PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/VCC" payload:[hex:332e3338 utf8:"3.38" length:4]
22:18:29.104 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: new msg avail, notify workAvailable
22:18:29.108 [DEBUG] [.client.mqttv3.internal.CommsReceiver] - openHab-Id: network read message
22:18:29.108 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: call messageArrived key=0 topic=/hooks/devices/21/SensorData/VCC
22:18:29.114 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: notify spaceAvailable
22:18:29.118 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: wait for workAvailable
22:18:30.132 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=1
22:18:30.136 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=46
22:18:30.140 [DEBUG] [.mqttv3.internal.wire.MqttInputStream] - null: Automatic Reconnect Successful: PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/Temperature" payload:[hex:32332e32 utf8:"23.2" length:4]
22:18:30.144 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received key=0 message=PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/Temperature" payload:[hex:32332e32 utf8:"23.2" length:4]
22:18:30.147 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: new msg avail, notify workAvailable
22:18:30.150 [DEBUG] [.client.mqttv3.internal.CommsReceiver] - openHab-Id: network read message
22:18:30.151 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: call messageArrived key=0 topic=/hooks/devices/21/SensorData/Temperature
22:18:30.154 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=1
22:18:30.158 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received bytes count=43
22:18:30.161 [DEBUG] [.mqttv3.internal.wire.MqttInputStream] - null: Automatic Reconnect Successful: PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/Humidity" payload:[hex:36312e31 utf8:"61.1" length:4]
22:18:30.162 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: notify spaceAvailable
22:18:30.165 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: received key=0 message=PUBLISH qos:0 retained:false dup:false topic:"/hooks/devices/21/SensorData/Humidity" payload:[hex:36312e31 utf8:"61.1" length:4]
22:18:30.170 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: wait for workAvailable
22:18:30.175 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: new msg avail, notify workAvailable
22:18:30.178 [DEBUG] [.client.mqttv3.internal.CommsReceiver] - openHab-Id: network read message
22:18:30.179 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: call messageArrived key=0 topic=/hooks/devices/21/SensorData/Humidity
22:18:30.185 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: notify spaceAvailable
22:18:30.189 [INFO ] [smarthome.event.ItemStateChangedEvent] - Spalnica_hum changed from 59.6 to 61.1
22:18:30.190 [DEBUG] [.client.mqttv3.internal.CommsCallback] - openHab-Id: wait for workAvailable
22:18:36.347 [DEBUG] [se.paho.client.mqttv3.TimerPingSender] - null: Check schedule at 1,505,337,516,346
22:18:36.350 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: checkForActivity entered
22:18:36.354 [DEBUG] [ho.client.mqttv3.internal.ClientState] - openHab-Id: ping needed. keepAlive=60,000 lastOutboundActivity=1,505,337,456,352 lastInboundActivity=1,505,337,510,164
22:18:36.358 [DEBUG] [lient.mqttv3.internal.CommsTokenStore] - openHab-Id: key=Ping message=PINGREQ
22:18:36.361 [DEBUG] [lient.mqttv3.internal.CommsTokenStore] - openHab-Id: key=Ping token=org.eclipse.paho.client.mqttv3.MqttToken@1afb06b
2

Do you notice any pattern with the numbers that don’t get parsed? For example, numbers < 10 fail or numbers > 50 fail or something like that.

Change your Item types to Strings and log the actual message received in a rule. Make sure to log it in such a way that you can see if there is extraneous white space before or after the number.

Usually, problems like this are caused by the sender including white space or other stray characters in the message. Number can not handle that. Every character in the message must be parsable as a number.

3

Oops, it looks like this was my bad. Numbers whose values stay the same don’t get updated. As soon as the value changes an updated is performed.