Strange behaviour - Item update frequency gets slower over time

boehan · August 21, 2025, 8:51pm

Hi,

since a few days I see a really strange behavior in my openHAB system. After a few hours of operation, (some) items start updating with decreasing frequency and I can’t tell why. AFAIR, there were no changes to the system (upgraded to OH5 a month ago, but the issue only came up lately). Also, other items still seem to be receiving updates at normal frequency. But it seems that this behavior cannot be attributed to any specific binding, as it effects items of different bindings and also not all items of a binding are effected.

After a restart of openHAB update frequency is back to normal for a few hour before it starts showing the same behavior again.

The following graph tries to show this using some differently effected items:

a temperature sensor connected to a Z-Wave thermostat - effected by slowdown (seems to not update at all anymore)
fan speed of comfoair ventilation system connected via RS232 - effected
a bluetooth sensor connected to OH via MQTT (broker not on OH device) - NOT effected
current temperature via OpenWeatherMap - effected
power consumption from a Z-Wave smart plug - NOT effected
current system load via systemInfo binding - effected

At the same time, it does not appear to be a general overload of the system, as I cannot detect any restrictions in responsiveness, either within openHAB or in the rest of the OS.

Any ideas what could cause this?

System details

Summary

runtimeInfo:
  version: 5.0.0
  buildString: Release Build
locale: de-AT
systemInfo:
  configFolder: /etc/openhab
  userdataFolder: /var/lib/openhab
  logFolder: /var/log/openhab
  javaVersion: 21.0.8
  javaVendor: Eclipse Adoptium
  javaVendorVersion: Temurin-21.0.8+9
  osName: Linux
  osVersion: 6.6.20+rpt-rpi-2712
  osArchitecture: aarch64
  availableProcessors: 4
  freeMemory: 134261080
  totalMemory: 565182464
  uptime: 52223
  startLevel: 100
addons:
  - automation-jsscripting
  - automation-jythonscripting
  - binding-astro
  - binding-comfoair
  - binding-denonmarantz
  - binding-exec
  - binding-freecurrency
  - binding-gpio
  - binding-heos
  - binding-http
  - binding-kodi
  - binding-lgtvserial
  - binding-mqtt
  - binding-network
  - binding-openweathermap
  - binding-systeminfo
  - binding-unifi
  - binding-zwave
  - misc-metrics
  - persistence-inmemory
  - persistence-mapdb
  - persistence-rrd4j
  - transformation-jinja
  - transformation-map
  - transformation-scale
  - ui-basic
clientInfo:
  device:
    ios: false
    android: false
    androidChrome: false
    desktop: true
    iphone: false
    ipod: false
    ipad: false
    edge: false
    ie: false
    firefox: true
    macos: false
    windows: false
    cordova: false
    phonegap: false
    electron: false
    nwjs: false
    webView: false
    webview: false
    standalone: false
    pixelRatio: 1
    prefersColorScheme: light
  isSecureContext: true
  locationbarVisible: true
  menubarVisible: true
  navigator:
    cookieEnabled: true
    deviceMemory: N/A
    hardwareConcurrency: 16
    language: de
    languages:
      - de
      - en-US
      - en
    onLine: true
    platform: Linux x86_64
  screen:
    width: 1920
    height: 1200
    colorDepth: 24
  support:
    touch: false
    pointerEvents: true
    observer: true
    passiveListener: true
    gestures: false
    intersectionObserver: true
  themeOptions:
    dark: light
    filled: true
    pageTransitionAnimation: default
    bars: light
    homeNavbar: simple
    homeBackground: default
    expandableCardAnimation: default
    blocklyRenderer: null
  userAgent: Mozilla/5.0 (X11; Linux x86_64; rv:141.0) Gecko/20100101 Firefox/141.0
timestamp: 2025-08-21T20:45:20.276Z

Exemplary log for the comfoair item shown above - usually receives updates every minute, from about 16:40 on updates come in much slower:

Summary

2025-08-21 16:19:57.814 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.43333333333333 Hz to 47.916666666666664 Hz
2025-08-21 16:20:58.172 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 47.916666666666664 Hz to 48.06666666666667 Hz
2025-08-21 16:21:56.725 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.06666666666667 Hz to 49.28333333333333 Hz
2025-08-21 16:22:55.877 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.28333333333333 Hz to 49.43333333333333 Hz
2025-08-21 16:23:56.839 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.43333333333333 Hz to 49.6 Hz
2025-08-21 16:24:58.019 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.6 Hz to 48.21666666666667 Hz
2025-08-21 16:25:56.363 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.21666666666667 Hz to 49.6 Hz
2025-08-21 16:26:56.738 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.6 Hz to 49.28333333333333 Hz
2025-08-21 16:28:00.498 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.28333333333333 Hz to 49.43333333333333 Hz
2025-08-21 16:28:58.653 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.43333333333333 Hz to 49.28333333333333 Hz
2025-08-21 16:31:33.819 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.28333333333333 Hz to 48.36666666666667 Hz
2025-08-21 16:32:26.150 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.36666666666667 Hz to 49.28333333333333 Hz
2025-08-21 16:33:24.903 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.28333333333333 Hz to 47.916666666666664 Hz
2025-08-21 16:34:29.469 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 47.916666666666664 Hz to 49.6 Hz
2025-08-21 16:35:29.216 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.6 Hz to 47.916666666666664 Hz
2025-08-21 16:36:27.763 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 47.916666666666664 Hz to 48.21666666666667 Hz
2025-08-21 16:37:31.328 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.21666666666667 Hz to 47.916666666666664 Hz
2025-08-21 16:38:31.281 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 47.916666666666664 Hz to 49.13333333333333 Hz
2025-08-21 16:40:01.101 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.13333333333333 Hz to 47.766666666666666 Hz
2025-08-21 16:48:11.194 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 47.766666666666666 Hz to 47.63333333333333 Hz
2025-08-21 16:55:25.577 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 47.63333333333333 Hz to 49.13333333333333 Hz
2025-08-21 17:05:51.474 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.13333333333333 Hz to 48.06666666666667 Hz
2025-08-21 17:21:11.146 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.06666666666667 Hz to 49.13333333333333 Hz
2025-08-21 17:43:55.463 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.13333333333333 Hz to 48.21666666666667 Hz
2025-08-21 18:16:50.426 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.21666666666667 Hz to 49.75 Hz
2025-08-21 19:04:57.568 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 49.75 Hz to 48.516666666666666 Hz
2025-08-21 20:10:19.924 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.516666666666666 Hz to 50.06666666666667 Hz
2025-08-21 21:11:58.521 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 50.06666666666667 Hz to 48.516666666666666 Hz
2025-08-21 21:52:02.756 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.516666666666666 Hz to 48.36666666666667 Hz
2025-08-21 22:18:30.317 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.36666666666667 Hz to 50.55 Hz
2025-08-21 22:36:01.762 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 50.55 Hz to 50.06666666666667 Hz
2025-08-21 22:47:37.457 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 50.06666666666667 Hz to 48.96666666666667 Hz
2025-08-21 22:55:19.397 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'WRL_Abluftventilator_RPM' changed from 48.96666666666667 Hz to 48.36666666666667 Hz

AndrewFG · August 21, 2025, 9:18pm

I guess this is another thread starvation issue. What bindings are you running?

boehan · August 21, 2025, 9:25pm

boehan:

addons:
  - automation-jsscripting
  - automation-jythonscripting
  - binding-astro
  - binding-comfoair
  - binding-denonmarantz
  - binding-exec
  - binding-freecurrency
  - binding-gpio
  - binding-heos
  - binding-http
  - binding-kodi
  - binding-lgtvserial
  - binding-mqtt
  - binding-network
  - binding-openweathermap
  - binding-systeminfo
  - binding-unifi
  - binding-zwave
  - misc-metrics
  - persistence-inmemory
  - persistence-mapdb
  - persistence-rrd4j
  - transformation-jinja
  - transformation-map
  - transformation-scale
  - ui-basic

But I just noticed in the console that the Freecurrency binding was stuck in waiting. Maybe because I installed it out of interest lately but never used or even configured it. Uninstalled it now and items seem to be updating normally again. Let’s wait until tomorrow, if this is only temporary or the issue comes back.

AndrewFG · August 21, 2025, 9:36pm

Try setting log:set TRACE on that binding and post whatever you see that may be noteworthy.

justaoldman · August 22, 2025, 3:06am

You may also consider collecting the following data as well to give a little more insight also, If the issue comes back again grab a thread dump from console

shell:threads >threads.txt
then parse the file and search for Blocked note what if any Blocked threads show up .

boehan · August 24, 2025, 8:31am

Thanks, for your help so far. After removing the stuck freecurrency binding, the item updates went smooth for 35 hours and I considered the issue to be fixed. But then I noticed today that the issue came back yesterday morning…

shell:threads shows a lot of threads (122) in TIMED_WAITING (AFAICT the new slowdown started about 24h ago), but I’m not sure what to do with this information now…

threads.txt (295.8 KB)

AndrewFG · August 24, 2025, 11:53am

Me neither. But as a wild guess I would look at those thread names which have the highest occurrence of waiting states.

The ones that I noticed (but may or may not be the cause of your issue) are the “httpclient” threads; this would probably indicate that you have either a) a general networking or routing issue (e.g. no internet connection, dhcp issue, dns issue, firewall etc.), or b) a specific binding is blocking on a call to its cloud server or lan based bridge. In case b) try disabling bindings one by one until the problem goes away.

justaoldman · August 24, 2025, 3:29pm

have a look at this.

“OH-thingHandler-1” Id=918 in BLOCKED on lock=org.openhab.binding.comfoair.internal.ComfoAirSerialConnector@5d7d1231
owned by OH-thingHandler-4 Id=929
“OH-thingHandler-2” Id=919 in BLOCKED on lock=org.openhab.binding.comfoair.internal.ComfoAirSerialConnector@5d7d1231
owned by OH-thingHandler-4 Id=929
“OH-thingHandler-3” Id=924 in BLOCKED on lock=org.openhab.binding.comfoair.internal.ComfoAirSerialConnector@5d7d1231
owned by OH-thingHandler-4 Id=929
“OH-thingHandler-4” Id=929 in TIMED_WAITING
“OH-thingHandler-5” Id=930 in BLOCKED on lock=org.openhab.binding.comfoair.internal.ComfoAirSerialConnector@5d7d1231
owned by OH-thingHandler-4 Id=929
owned by OH-thingHandler-4 Id=929

Bingo

different binding same issue where OH has choked down to a single thread available for Thing handling.