openhab-addons: [tellstick] Sensor item updates get duplicated close to 100 times after lowering refresh interval

Expected Behavior

Lowering the refresh interval simply updates states of lights faster.

Current Behavior

The state of lights is updated faster as expected, but in addition, the sensor updates are repeated close to 100 times within less than a second.

Notes about the behavior:

  • The default refresh interval was changed from 60 s to 3 s
  • After resetting the refresh interval back to the original, issue disappeared
  • Issue is accumulating over time. Within an hour, a few extra updates are seen, after months 75 updates have been counted
  • The issue seems to affect other bindings as well: My Verisure binding (also communicating over an API) also gets duplicated sensor readings.
  • The sensor burst readings happen at the expected time interval (every 5 min)
  • Timeout expection sometimes happen (see second log below)

Example of logging: image

Logging with Trace enabled for the tellstick binding:

2022-09-12 19:17:30.305 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Updated sensors:[TellstickNetSensor [deviceId=1540384552, protocol=fineoffset, name=Basement, online=true, data=[DataTypeValue [dataType=temp, data=17.2, unit=°C], DataTypeValue [dataType=humidity, data=78, unit=%]], lastUpdated=1663002946, updated=false], TellstickNetSensor [deviceId=1540555924, protocol=fineoffset, name=Crawl space, online=true, data=[DataTypeValue [dataType=temp, data=16.4, unit=°C], DataTypeValue [dataType=humidity, data=82, unit=%]], lastUpdated=1663002427, updated=false], TellstickNetSensor [deviceId=1540556014, protocol=fineoffset, name=Outdoor, online=true, data=[DataTypeValue [dataType=temp, data=16.7, unit=°C], DataTypeValue [dataType=humidity, data=80, unit=%]], lastUpdated=1663002797, updated=false]]
2022-09-12 19:17:30.306 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensors, reset updated flag
2022-09-12 19:17:30.307 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensors, reset updated flag1
2022-09-12 19:17:30.308 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensor 1540384552, prev update 1663002946, new update 1663002946
2022-09-12 19:17:30.309 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensor 1540555924, prev update 1663002427, new update 1663002427
2022-09-12 19:17:30.309 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensor 1540556014, prev update 1663002797, new update 1663002797
2022-09-12 19:17:33.421 [TRACE] [nal.live.TelldusLiveDeviceController] - Request [http://api.telldus.com/xml/devices/list?supportedMethods=19] Response:<?xml version="1.0" encoding="utf-8" ?>
<devices>
	<device id="9945431" clientDeviceId="14" name="Carport Inner Lights" state="2" statevalue="" methods="3" metadataHash="" parametersHash="7c36bf492221e43b2065609d9b46fe7dd402eae8" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
	<device id="10666457" clientDeviceId="15" name="Dusk Sensor" state="1" statevalue="" methods="3" metadataHash="" parametersHash="f5b96d8776b5945bc86e355d54bc1fab278fcdca" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
	<device id="8597597" clientDeviceId="11" name="D&#246;rrklocka" state="2" statevalue="" methods="3" metadataHash="" parametersHash="18ad0b3f18aa1c4d9a24045e4c322f047b1d555f" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
	<device id="7969581" clientDeviceId="6" name="Ek/V&#228;g-lampa" state="2" statevalue="" methods="3" metadataHash="" parametersHash="00c8346f30f4a05cba3c6bb783201d2d3b81cd0f" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
	<device id="588090" clientDeviceId="2" name="Element h&#246;ger" state="2" statevalue="unde" methods="3" metadataHash="" parametersHash="673f0bf447780556fba79c0d476c11ac2eb12812" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
	<device id="8468702" clientDeviceId="8" name="Element v&#228;nster" state="2" statevalue="" methods="3" metadataHash="" parametersHash="bafbd01080b4c074b19e0ff6974dc4e1eb49a460" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
	<device id="9918531" clientDeviceId="13" name="Framd&#246;rr lampa" state="2" statevalue="" methods="3" metadataHash="" parametersHash="9d06f3925130649b157c489c14077eea7f33932e" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
	<device id="9918526" clientDeviceId="12" name="K&#228;llarlampa" state="2" statevalue="" methods="3" metadataHash="" parametersHash="1828f54a12ce36b352f8202e3b7f12c507ec9b63" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
	<device id="7969671" clientDeviceId="7" name="Lyktstolpe" state="2" statevalue="" methods="3" metadataHash="" parametersHash="bf7ea38193dd79b833ac27ac1f87216d4b5d4a8c" type="device" client="126139" clientName="Stanstorp" online="1" editable="1" ignored="0" />
</devices>

2022-09-12 19:17:33.422 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device list [TellstickNetDevice [deviceId=9945431, name=Carport Inner Lights, online=true, state=2, statevalue=, updated=false], TellstickNetDevice [deviceId=10666457, name=Dusk Sensor, online=true, state=1, statevalue=, updated=false], TellstickNetDevice [deviceId=8597597, name=Dörrklocka, online=true, state=2, statevalue=, updated=false], TellstickNetDevice [deviceId=7969581, name=Ek/Väg-lampa, online=true, state=2, statevalue=, updated=false], TellstickNetDevice [deviceId=588090, name=Element höger, online=true, state=2, statevalue=unde, updated=false], TellstickNetDevice [deviceId=8468702, name=Element vänster, online=true, state=2, statevalue=, updated=false], TellstickNetDevice [deviceId=9918531, name=Framdörr lampa, online=true, state=2, statevalue=, updated=false], TellstickNetDevice [deviceId=9918526, name=Källarlampa, online=true, state=2, statevalue=, updated=false], TellstickNetDevice [deviceId=7969671, name=Lyktstolpe, online=true, state=2, statevalue=, updated=false]]
2022-09-12 19:17:33.423 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - updateDevices, Updating devices.
2022-09-12 19:17:33.424 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=9945431, name=Carport Inner Lights, online=true, state=2, statevalue=, updated=false] found at 0
2022-09-12 19:17:33.425 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=10666457, name=Dusk Sensor, online=true, state=1, statevalue=, updated=false] found at 1
2022-09-12 19:17:33.426 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=8597597, name=Dörrklocka, online=true, state=2, statevalue=, updated=false] found at 2
2022-09-12 19:17:33.427 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=7969581, name=Ek/Väg-lampa, online=true, state=2, statevalue=, updated=false] found at 3
2022-09-12 19:17:33.428 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=588090, name=Element höger, online=true, state=2, statevalue=unde, updated=false] found at 4
2022-09-12 19:17:33.428 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=8468702, name=Element vänster, online=true, state=2, statevalue=, updated=false] found at 5
2022-09-12 19:17:33.429 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=9918531, name=Framdörr lampa, online=true, state=2, statevalue=, updated=false] found at 6
2022-09-12 19:17:33.430 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=9918526, name=Källarlampa, online=true, state=2, statevalue=, updated=false] found at 7
2022-09-12 19:17:33.431 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=7969671, name=Lyktstolpe, online=true, state=2, statevalue=, updated=false] found at 8
2022-09-12 19:17:33.555 [TRACE] [nal.live.TelldusLiveDeviceController] - Request [http://api.telldus.com/xml/sensors/list?includeValues=1&includeScale=1&includeUnit=1] Response:<?xml version="1.0" encoding="utf-8" ?>
<sensors>
	<sensor id="1540384552" name="Basement" lastUpdated="1663002946" ignored="0" client="126139" clientName="Stanstorp" online="1" editable="1" battery="254" keepHistory="1" protocol="fineoffset" model="temperaturehumidity" sensorId="135" miscValues="null">
		<data name="temp" value="17.2" scale="0" lastUpdated="1663002946" max="24.4" maxTime="1606649223" min="6.9" minTime="1613117078" unit="&#176;C" />
		<data name="humidity" value="78" scale="0" lastUpdated="1663002946" max="95" maxTime="1626245828" min="40" minTime="1613204486" unit="%" />
	</sensor>
	<sensor id="1540555924" name="Crawl space" lastUpdated="1663003051" ignored="0" client="126139" clientName="Stanstorp" online="1" editable="1" battery="254" keepHistory="1" protocol="fineoffset" model="temperaturehumidity" sensorId="151" miscValues="null">
		<data name="temp" value="16.4" scale="0" lastUpdated="1663003051" max="23.7" maxTime="1607250269" min="6.9" minTime="1613117078" unit="&#176;C" />
		<data name="humidity" value="82" scale="0" lastUpdated="1663003051" max="89" maxTime="1657275991" min="45" minTime="1607251277" unit="%" />
	</sensor>
	<sensor id="1540556014" name="Outdoor" lastUpdated="1663002797" ignored="0" client="126139" clientName="Stanstorp" online="1" editable="1" battery="254" keepHistory="1" protocol="fineoffset" model="temperaturehumidity" sensorId="167" miscValues="{}">
		<data name="temp" value="16.7" scale="0" lastUpdated="1663002797" max="29.1" maxTime="1659616571" min="-10.3" minTime="1613117101" unit="&#176;C" />
		<data name="humidity" value="80" scale="0" lastUpdated="1663002797" max="99" maxTime="1607967323" min="34" minTime="1618835035" unit="%" />
	</sensor>
</sensors>

2022-09-12 19:17:33.556 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Updated sensors:[TellstickNetSensor [deviceId=1540384552, protocol=fineoffset, name=Basement, online=true, data=[DataTypeValue [dataType=temp, data=17.2, unit=°C], DataTypeValue [dataType=humidity, data=78, unit=%]], lastUpdated=1663002946, updated=false], TellstickNetSensor [deviceId=1540555924, protocol=fineoffset, name=Crawl space, online=true, data=[DataTypeValue [dataType=temp, data=16.4, unit=°C], DataTypeValue [dataType=humidity, data=82, unit=%]], lastUpdated=1663003051, updated=false], TellstickNetSensor [deviceId=1540556014, protocol=fineoffset, name=Outdoor, online=true, data=[DataTypeValue [dataType=temp, data=16.7, unit=°C], DataTypeValue [dataType=humidity, data=80, unit=%]], lastUpdated=1663002797, updated=false]]
2022-09-12 19:17:33.557 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensors, reset updated flag
2022-09-12 19:17:33.558 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensors, reset updated flag1
2022-09-12 19:17:33.558 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensor 1540384552, prev update 1663002946, new update 1663002946
2022-09-12 19:17:33.559 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensor 1540555924, prev update 1663002427, new update 1663003051
2022-09-12 19:17:33.559 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update for sensor:TellstickNetSensor [deviceId=1540555924, protocol=fineoffset, name=Crawl space, online=true, data=[DataTypeValue [dataType=temp, data=16.4, unit=°C], DataTypeValue [dataType=humidity, data=82, unit=%]], lastUpdated=1663003051, updated=false]
2022-09-12 19:17:33.560 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Update sensor 1540556014, prev update 1663002797, new update 1663002797
2022-09-12 19:17:33.560 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540556014 or 1540556014
2022-09-12 19:17:33.561 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540556014 or 1540556014
2022-09-12 19:17:33.561 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540555924 or 1540555924
2022-09-12 19:17:33.563 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540555924 or 1540555924
2022-09-12 19:17:33.565 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540384552 or 1540384552
2022-09-12 19:17:33.566 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'SENSORCrawlspace_Temperature' updated to 16.4 °C
2022-09-12 19:17:33.566 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540384552 or 1540384552
2022-09-12 19:17:33.567 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:588090 or 588090
2022-09-12 19:17:33.568 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:588090 or 588090
2022-09-12 19:17:33.569 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'SENSORCrawlspace_Humidity' updated to 82 %
2022-09-12 19:17:33.568 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9918531 or 9918531
2022-09-12 19:17:33.570 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9918531 or 9918531
2022-09-12 19:17:33.571 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9918526 or 9918526
2022-09-12 19:17:33.571 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9918526 or 9918526
2022-09-12 19:17:33.572 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:8468702 or 8468702
2022-09-12 19:17:33.572 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:8468702 or 8468702
2022-09-12 19:17:33.573 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:7969581 or 7969581
2022-09-12 19:17:33.573 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:7969581 or 7969581
2022-09-12 19:17:33.574 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:7969671 or 7969671
2022-09-12 19:17:33.575 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:7969671 or 7969671
2022-09-12 19:17:33.575 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9945431 or 9945431
2022-09-12 19:17:33.576 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9945431 or 9945431
2022-09-12 19:17:33.576 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:8597597 or 8597597
2022-09-12 19:17:33.576 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:8597597 or 8597597
2022-09-12 19:17:33.577 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540555924 or 1540555924
2022-09-12 19:17:33.578 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540555924 or 1540555924
2022-09-12 19:17:33.579 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540556014 or 1540556014
2022-09-12 19:17:33.580 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'SENSORCrawlspace_Temperature' updated to 16.4 °C
2022-09-12 19:17:33.580 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540556014 or 1540556014
2022-09-12 19:17:33.581 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:588090 or 588090
2022-09-12 19:17:33.581 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'SENSORCrawlspace_Humidity' updated to 82 %
2022-09-12 19:17:33.581 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:588090 or 588090
2022-09-12 19:17:33.582 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9918531 or 9918531
2022-09-12 19:17:33.582 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9918531 or 9918531
2022-09-12 19:17:33.583 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:8468702 or 8468702
2022-09-12 19:17:33.583 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:8468702 or 8468702
2022-09-12 19:17:33.584 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540384552 or 1540384552
2022-09-12 19:17:33.584 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540384552 or 1540384552
2022-09-12 19:17:33.584 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:7969581 or 7969581
2022-09-12 19:17:33.585 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:7969581 or 7969581
2022-09-12 19:17:33.585 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:7969671 or 7969671
2022-09-12 19:17:33.585 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:7969671 or 7969671
2022-09-12 19:17:33.586 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9918526 or 9918526
2022-09-12 19:17:33.586 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9918526 or 9918526
2022-09-12 19:17:33.586 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9945431 or 9945431
2022-09-12 19:17:33.587 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:9945431 or 9945431
2022-09-12 19:17:33.587 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:8597597 or 8597597
2022-09-12 19:17:33.587 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:8597597 or 8597597
2022-09-12 19:17:33.588 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540555924 or 1540555924
2022-09-12 19:17:33.589 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540555924 or 1540555924
2022-09-12 19:17:33.590 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540556014 or 1540556014
2022-09-12 19:17:33.591 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'SENSORCrawlspace_Temperature' updated to 16.4 °C
2022-09-12 19:17:33.591 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540556014 or 1540556014
2022-09-12 19:17:33.592 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:588090 or 588090
2022-09-12 19:17:33.592 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:switch:5cb57369ab:588090 or 588090
2022-09-12 19:17:33.593 [DEBUG] [ternal.handler.TelldusDevicesHandler] - Updating states of (SENSOR Crawl space (1540555924) id: tellstick:sensor:5cb57369ab:1540384552 or 1540384552
2022-09-12 19:17:33.593 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'SENSORCrawlspace_Humidity' updated to 82 %

TimeoutException error message that sometimes appear:

2022-09-11 20:20:02.903 [DEBUG] [ternal.live.TelldusLiveBridgeHandler] - Device:TellstickNetDevice [deviceId=7969671, name=Lyktstolpe, online=true, state=2, statevalue=, updated=false] found at 8
2022-09-11 20:20:07.906 [WARN ] [nal.live.TelldusLiveDeviceController] - TimeoutException error in get
java.util.concurrent.TimeoutException: null
	at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1886) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2021) ~[?:?]
	at org.asynchttpclient.netty.NettyResponseFuture.get(NettyResponseFuture.java:206) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.innerCallRest(TelldusLiveDeviceController.java:309) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.callRestMethod(TelldusLiveDeviceController.java:283) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveBridgeHandler.updateSensors(TelldusLiveBridgeHandler.java:181) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveBridgeHandler.refreshDeviceList(TelldusLiveBridgeHandler.java:117) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:834) [?:?]
2022-09-11 20:20:08.229 [WARN ] [nal.live.TelldusLiveDeviceController] - Encoding error in get
javax.xml.bind.UnmarshalException: null
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.handleStreamException(UnmarshallerImpl.java:453) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal0(UnmarshallerImpl.java:387) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal(UnmarshallerImpl.java:356) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.innerCallRest(TelldusLiveDeviceController.java:319) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.callRestMethod(TelldusLiveDeviceController.java:283) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveBridgeHandler.updateSensors(TelldusLiveBridgeHandler.java:181) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveBridgeHandler.refreshDeviceList(TelldusLiveBridgeHandler.java:117) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: com.sun.istack.SAXParseException2: unexpected element (uri:"", local:"html"). Expected elements are <{}data>,<{}sensor>,<{}sensors>
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext.handleEvent(UnmarshallingContext.java:712) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportError(Loader.java:232) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportError(Loader.java:227) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportUnexpectedChildElement(Loader.java:94) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext$DefaultRootLoader.childElement(UnmarshallingContext.java:1117) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext._startElement(UnmarshallingContext.java:542) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext.startElement(UnmarshallingContext.java:524) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.StAXStreamConnector.handleStartElement(StAXStreamConnector.java:216) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.StAXStreamConnector.bridge(StAXStreamConnector.java:150) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal0(UnmarshallerImpl.java:385) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	... 11 more
Caused by: javax.xml.bind.UnmarshalException: unexpected element (uri:"", local:"html"). Expected elements are <{}data>,<{}sensor>,<{}sensors>
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext.handleEvent(UnmarshallingContext.java:712) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportError(Loader.java:232) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportError(Loader.java:227) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportUnexpectedChildElement(Loader.java:94) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext$DefaultRootLoader.childElement(UnmarshallingContext.java:1117) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext._startElement(UnmarshallingContext.java:542) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext.startElement(UnmarshallingContext.java:524) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.StAXStreamConnector.handleStartElement(StAXStreamConnector.java:216) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.StAXStreamConnector.bridge(StAXStreamConnector.java:150) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal0(UnmarshallerImpl.java:385) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	... 11 more
2022-09-11 20:20:08.236 [WARN ] [nal.live.TelldusLiveDeviceController] - Request [http://api.telldus.com/xml/sensors/list?includeValues=1&includeScale=1&includeUnit=1] Failure:null
2022-09-11 20:20:08.238 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tellstick:telldus-live:5cb57369ab' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.238 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 1540555924 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.240 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 1540556014 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.240 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 9918531 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.241 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 588090 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.242 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 1540384552 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.242 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tellstick:sensor:5cb57369ab:1540555924' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.242 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 9918526 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.242 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 7969581 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.243 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 8468702 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.243 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 9945431 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.244 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 8597597 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.245 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tellstick:switch:5cb57369ab:9918531' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.246 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tellstick:sensor:5cb57369ab:1540556014' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.247 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tellstick:switch:5cb57369ab:9918526' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.243 [ERROR] [ternal.live.TelldusLiveBridgeHandler] - Failed to update
org.openhab.binding.tellstick.internal.live.TelldusLiveException: null
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.callRestMethod(TelldusLiveDeviceController.java:294) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveBridgeHandler.updateSensors(TelldusLiveBridgeHandler.java:181) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveBridgeHandler.refreshDeviceList(TelldusLiveBridgeHandler.java:117) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: javax.xml.bind.UnmarshalException
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.handleStreamException(UnmarshallerImpl.java:453) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal0(UnmarshallerImpl.java:387) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal(UnmarshallerImpl.java:356) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.innerCallRest(TelldusLiveDeviceController.java:319) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.callRestMethod(TelldusLiveDeviceController.java:283) ~[?:?]
	... 8 more
Caused by: com.sun.istack.SAXParseException2: unexpected element (uri:"", local:"html"). Expected elements are <{}data>,<{}sensor>,<{}sensors>
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext.handleEvent(UnmarshallingContext.java:712) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportError(Loader.java:232) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportError(Loader.java:227) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportUnexpectedChildElement(Loader.java:94) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext$DefaultRootLoader.childElement(UnmarshallingContext.java:1117) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext._startElement(UnmarshallingContext.java:542) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext.startElement(UnmarshallingContext.java:524) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.StAXStreamConnector.handleStartElement(StAXStreamConnector.java:216) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.StAXStreamConnector.bridge(StAXStreamConnector.java:150) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal0(UnmarshallerImpl.java:385) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal(UnmarshallerImpl.java:356) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.innerCallRest(TelldusLiveDeviceController.java:319) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.callRestMethod(TelldusLiveDeviceController.java:283) ~[?:?]
	... 8 more
Caused by: javax.xml.bind.UnmarshalException: unexpected element (uri:"", local:"html"). Expected elements are <{}data>,<{}sensor>,<{}sensors>
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext.handleEvent(UnmarshallingContext.java:712) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportError(Loader.java:232) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportError(Loader.java:227) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.Loader.reportUnexpectedChildElement(Loader.java:94) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext$DefaultRootLoader.childElement(UnmarshallingContext.java:1117) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext._startElement(UnmarshallingContext.java:542) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallingContext.startElement(UnmarshallingContext.java:524) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.StAXStreamConnector.handleStartElement(StAXStreamConnector.java:216) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.StAXStreamConnector.bridge(StAXStreamConnector.java:150) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal0(UnmarshallerImpl.java:385) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal(UnmarshallerImpl.java:356) ~[jaxb-runtime-2.3.3.jar:2.3.3]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.innerCallRest(TelldusLiveDeviceController.java:319) ~[?:?]
	at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.callRestMethod(TelldusLiveDeviceController.java:283) ~[?:?]
	... 8 more
2022-09-11 20:20:08.248 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tellstick:switch:5cb57369ab:7969581' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2022-09-11 20:20:08.244 [DEBUG] [ternal.handler.TelldusDevicesHandler] - device: 7969671 bridgeStatusChanged: OFFLINE (COMMUNICATION_ERROR)

Possible Solution

Input from rossko57 in the community thread: “This feels more like faulty task re-scheduling after query/response, in some circumstance or other (quite possibly a remote timeout, though that would be the trigger not the root cause). That would be a binding issue.”

Steps to Reproduce (for Bugs)

  1. Lower tellstick refresh interval to 3s
  2. Wait for a few hours
  3. Observe in the log that sensor values are duplicated

Context

The excess points in the influxdb database makes graphs very slow.

A potential work around would be to only store changes in the database, but then I loose information about when sensor values are missing. E.g. in the crawl space, the humidity might not change for a whole day, which would give an empty graph.

Your Environment

Hardware: Raspberry pi 4, 4GB OS: openhabian openHAB version: 3.3.0.M3 Persistence: Influxdb Configuration method: GUI only, no files. Semantic model is used Tellstick usage: Live (cloud API)

Link to community thread: https://community.openhab.org/t/tellstick-binding-item-updates-get-duplicated-around-75-times-after-lowering-refresh-interval/138634

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 16 (16 by maintainers)

Commits related to this issue

Most upvoted comments

Is there perhaps a way to change the timeout to something higher, and see if the duplications disappear?

Yes, we can create a first PR just to increase this timeout.

I will analyze the code, the problem should rather be in the scheduling of data refresh.