Homematic IP device status updates stop being received by openHAB (but controlling these devices still works)

[Cplant]

Platform information:

• Homematic IP Hardware: CCU2 (2.59.7), multiple Homematic IP devices
• openHAB Hardware: Raspi 3 (Raspian OS 10)
• openHAB Software: 3.1.0 Release Build, running on Docker 2.6.2
• openHAB Bindings: Homematic Binding (logging the heating, controlling lights and blinds), Gardena Binding for Gardena Gateway / smart irrigation control (logging soil humidity), Alexa Binding (controlling the Homematic lights)

I observed a rather odd behavior with my Homematic binding. While I could fix it easily with a reboot of openHAB, I’d like to know whether this is either a (known) bug or a configuration issue on my side.

Observation:
(log entries illustrative, so log times do not match my observation)
Until around 4:12 pm today, things worked perfectly: I was able to control Homematic items perfectly via openHAB…

22:49:24.360 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'Stehlampe' received command ON
22:49:24.368 [INFO ] [openhab.event.ItemStatePredictedEvent] - Item 'Stehlampe' predicted to become ON
22:49:24.379 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Stehlampe' changed from 14 to 100

… and sensors and devices (if switched on the device itself / not via openHAB) regularly sent their status updates to openHAB…

23:16:08.637 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Lichtsensor_Garten_HighestIllumination' changed from 1.08 lx to 1.09 lx
23:16:50.843 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Thermostat_Garten_ActualTemperature' changed from 23.3 °C to 23.2 °C
23:30:52.802 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Stehlampe' changed from 0 to 100
23:30:55.839 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Stehlampe' changed from 100 to 0

At 4:12 something odd happened: While I could continue to control my Homematic devices via openHAB, the status updates of the sensors and devices stopped reaching openHAB.

Example:
While the CCU2 continued to monitor my light sensor with a time resolution of 1 - 3 minutes…

… it did not reach openHAB anymore (refer to the straight line at the end of the graph)…

… even though the communication between openHAB and the CCU was still in place (I could still control devices).

What’s even more odd: The communication between the CCU and Openhab did not stop completely at 4:12. After a short break there was one more update at 4:32, and then after a loooong break another update only at 10:15 (~ 6 hours later).

After doing an openHAB reboot, everything went back to normal (devices and sensors sending their status updates regularly again).

My interpretation: Since…

• …everything was still logged correctly at the CCU…
• … a reboot of the openHAB binding fixed the problem…
• … and, during the time of the odd behavior, devices could still be controlled via openHAB…
• … the problem can’t be on the CCU-side…
• … and I suspect maybe a bug in the openHAB Homematic binding?

Or is it a configuration issue?

Problem is that, if this happens unnoticed, it prevents logging altogether for as long as you reboot openHAB.

Looking forward to your thoughts.

Update: What I experienced sounds similar to what has been described here After network outage Homematic items are visible and receiving updates on the device, but not updating values in Openhab - #10 by Cplant and here Debugging Homematic IP: no updates on some HmIP devices after some time

Update 2: After having had a bunch of connectivity problems for months, and after (unsuccessfully) having changed almost everything except the rounter, I finally replaced the router with something decent (Fritz! Box). And voillà: All my connectivity problems are gone.

[MHerbst (Martin Herbst)]

The IP devices are a bit “stubborn”. I have tried to find a solution and you can download a test version of the binding here: https://github.com/MHerbst/openhab-addons-test

I am not sure whether it will work with 3.1. Maybe you have to use a Milestone release of 3.2. Because you are using the binding in a Docker container you also have to configure the correct callback address.

[mschlee (Martin)]

I observed the same behaviour including the most recent Openhab 4.04. However I noticed that after rebooting the Homematic binding the problem shows up again after only a couple of hours. Restarting openhab itself fixes the problem for a couple of days to a couple of weeks.

[madattack]

I can confirm @mschlee observation. Also after update to 4.04 homematic binding stop updating values w/o any log messages. All things show up as online. A restart of the binding solves the issue for a couple of hours.
Updating to 4.1.0.M4 did not help.

A very weired observation. I also have the NTP binding stopis being updated. There often it helps to restart the Spotify binding.

This leads me to the hypothesis that these issues might be correlated / originated from I have a the the issues reported around Heap, threads, memory issues mentioned:

OH4 runs out of memory

PR #15798 is ready to merge, check out: https://github.com/openhab/openhab-addons/pull/15798 which includes OOM Fix #2 and #3 and some other important fixes. since then you could use https://github.com/markus7017/myfiles/blob/master/shelly/org.openhab.binding.shelly-4.1.0-SNAPSHOToom.jar?raw=true

[madattack]

Even after restart of openHAB homematic binding only runs stable for apporx 24h. Then no updates are received. I have th following log entry. in openhab.log.

2023-12-17 02:40:05.113 [ERROR] [ommunicator.AbstractHomematicGateway] - java.util.concurrent.ExecutionException: java.util.concurrent.TimeoutException: Total timeout 15000 ms elapsed
2023-12-17 02:40:40.704 [WARN ] [ternal.handler.HomematicThingHandler] - Value for datapoint HmDatapoint[name=TX_THRESHOLD_POWER,value=0.0,defaultValue=100.0,type=FLOAT,minValue=0.01,maxValue=160000.0,options=null,readOnly=false,readable=true,unit=W,description=TX_THRESHOLD_POWER,info=null,paramsetType=MASTER,virtual=false,trigger=false] is outside of valid range, using default value for config.
2023-12-17 02:40:42.021 [WARN ] [ternal.handler.HomematicThingHandler] - Value for datapoint HmDatapoint[name=TX_THRESHOLD_POWER,value=0.0,defaultValue=100.0,type=FLOAT,minValue=0.01,maxValue=160000.0,options=null,readOnly=false,readable=true,unit=W,description=TX_THRESHOLD_POWER,info=null,paramsetType=MASTER,virtual=false,trigger=false] is outside of valid range, using default value for config.
2023-12-17 02:40:49.405 [WARN ] [ternal.handler.HomematicThingHandler] - Value for datapoint HmDatapoint[name=TX_THRESHOLD_POWER,value=0.0,defaultValue=100.0,type=FLOAT,minValue=0.01,maxValue=160000.0,options=null,readOnly=false,readable=true,unit=W,description=TX_THRESHOLD_POWER,info=null,paramsetType=MASTER,virtual=false,trigger=false] is outside of valid range, using default value for config.
2023-12-17 02:40:49.495 [WARN ] [ternal.handler.HomematicThingHandler] - Value for datapoint HmDatapoint[name=TX_THRESHOLD_POWER,value=0.0,defaultValue=100.0,type=FLOAT,minValue=0.01,maxValue=160000.0,options=null,readOnly=false,readable=true,unit=W,description=TX_THRESHOLD_POWER,info=null,paramsetType=MASTER,virtual=false,trigger=false] is outside of valid range, using default value for config.

Here my thing configuration:

UID: homematic:bridge:LEQ1005809
label: thi_HM-CCU3-App - 192.168.0.236
thingTypeUID: homematic:bridge
configuration:
  cuxdPort: 8701
  socketMaxAlive: 900
  installModeDuration: 60
  callbackRegTimeout: 120
  hmIpPort: 2010
  timeout: 15
  factoryResetOnDeletion: false
  discoveryTimeToLive: -1
  wiredPort: 2000
  gatewayType: ccu
  groupPort: 9292
  gatewayAddress: 192.168.0.236
  unpairOnDeletion: false
  rfPort: 2001
  bufferSize: 2048
channels:
  - id: DUTY_CYCLE_RATIO
    channelTypeUID: homematic:DUTY_CYCLE_RATIO
    label: Auslastungsgrad
    description: Aktuelle Zyklusbenutzung
    configuration: {}

My info:

                           _   _     _     ____
   ___   ___   ___   ___  | | | |   / \   | __ )
  / _ \ / _ \ / _ \ / _ \ | |_| |  / _ \  |  _ \
 | (_) | (_) |  __/| | | ||  _  | / ___ \ | |_) )
  \___/|  __/ \___/|_| |_||_| |_|/_/   \_\|____/
       |_|       4.1.0.M4 - Milestone Build

Use '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
To exit, use '<ctrl-d>' or 'logout'.

openhab> info
Karaf
  Karaf version               4.4.4
  Karaf home                  /usr/share/openhab/runtime
  Karaf base                  /var/lib/openhab
  OSGi Framework              org.eclipse.osgi-3.18.0.v20220516-2155

JVM
  Java Virtual Machine        OpenJDK 64-Bit Server VM version 17.0.9+8-LTS
  Version                     17.0.9
  Vendor                      Azul Systems, Inc.
  Pid                         1338504
  Uptime                      1 day 14 hours
  Process CPU time            1 hour 37 minutes
  Process CPU load            0.03
  System CPU load             0.09
  Open file descriptors       239
  Max file descriptors        102,642
  Total compile time          9 minutes
Threads
  Live threads                297
  Daemon threads              138
  Peak                        313
  Total started               78989
Memory
  Current heap size           618,353 kbytes
  Maximum heap size           2,048,000 kbytes
  Committed heap size         845,824 kbytes
  Pending objects             0
  Garbage collector           Name = 'G1 Young Generation', Collections = 872, Time = 24.253 seconds
  Garbage collector           Name = 'G1 Old Generation', Collections = 0, Time = 0.000 seconds
Classes
  Current classes loaded      34,543
  Total classes loaded        39,929
  Total classes unloaded      5,386
Operating system
  Name                        Linux version 6.2.16-3-pve
  Architecture                amd64
  Processors                  2
  Total physical memory       3,432,636 kbytes
  Free physical memory        119,040 kbytes

It seems the be same issue as decribed here:

Homematic java.util.concurrent.TimeoutException

Hey guys, since few days i receive some error logs related to my homematic. several items are not available and after few minutes everything seems to be fine. Can you help me to identify the reason? CCU3 (debmatic) and openHAB 3.3.0.M3 Binding Homematic 3.3.0.M3 are on the same PI java -version openjdk version “11.0.14” 2022-01-18 OpenJDK Runtime Environment (build 11.0.14+9-post-Raspbian-1deb11u1) OpenJDK Server VM (build 11.0.14+9-post-Raspbian-1deb11u1, mixed mode) ```yaml 2022-04-0…

Anyone an idea how to approach this?

[madattack]

The issue is not appearing any more. Most likely updating CCU3 to latest firmware version 3.73.9 was the solution.

Homematic binding is now stable since 7 days.

[Cplant]

Opening up a thread from 2021 and 2023 again, since I started having the same problems (controlling my HmIP-devices via OH 4.3.0 on Raspi 5 works, but updates are not received anymore at OH even though they’re received by my Raspberrymatic 3.79.6.20241122, running on the same Raspi via Docker).

Not sure if it has something to do with my OH update to 4.3.0, but the problems appeared around the same time (after more than a year) after I did the update of OH.

Here’s what I tried:

• Rebooting Raspberrymatic → No change
• Checking the OH-logs (down to TRACE or DEBUG) → No change. No entries at all when a HmIP sensor is updated (and confirmed to be updated as visible at Raspberrymatic)
• In OH: Disabling and enabling the CCU-bridge → No chnage: No updates at OH when a HmIP sensor is updated (and confirmed to be updated as visible at Raspberrymatic)
• Raspberrymatic-logs looked ok, though I can’t tell for sure since I had to reboot Raspberrymatic and then also OH, which then fixed the problem.

As mentioned, restarting the entire Raspi (incl. all containers) fixed the problem, but that’s hardly a solution… :-/

Anyone else having the same problem?

[Oliver2 (Oliver)]

did you do a clean-cache?

[Christian_Kittel]

I’m running OH and Raspberrymatic in K3s. The communication work without problems.

In the past I had some problems. At that time, the problem was seen in the CCU logs. No connection to the OH could be established. Problem was the wrong OH IP in the callback network address configuration in CCU binding in OH

[Cplant]

@Christian_Kittel

Problem was the wrong OH IP in the callback network address configuration in CCU binding in OH

Some time back I had problems due to the callback network address, but I fixed this two years ago and did not touch the setting again / the setting is still correct.

@Oliver2

did you do a clean-cache?

Not this time after the update. So far a reboot did the trick for everything to work again. Will try the cache-cleaning if the problem comes back. Thanks.

[Martin_HD (Martin)]

…Same for me. And the errors happened randomly, so very hard to debug. So I am now using CCU-Jack and mosquitto and generic mqtt binding. With this completely decoupled communication everything runs perfect.

[Cplant]

Thanks. Interesting approach going via CCU-Jack, but which I’d try to avoid for complexity reasons.

Now that I think about it: I’ve had this problem sporadically now and then (and not only in the wake of the 4.3.0-update), so I guesss a difficult-to-reproduce bug in the Homematic-binding?

[Piffer (Tim)]

I had a similiar issue, but I since I restart the CCU3 Thing after every Boot of openHAB and the CCU3, never noticed any.

[Cplant]

@Oliver2

did you do a clean-cache?

Had the same problem of „no updates of Homematic items“ again, even though I cleaned cache and tmp before. Now did an update to 4.3.2, trying again.

Pretty annoying bug (if it‘s a bug)…

[mr.airworthy (Alrik)]

Hi all!

I do have the same issue with 4.3.3 - all Homematic things are online and can be updated (the change shows up in my CCU2 right away) but no updates anymore. After a restart of OH the values refresh only once.

Any advice? Thanks!

[Cplant]

Not 100% sure, but my Raspi 5 was connected via ethernet and wifi (the latter without me really knowing). Since I deactivating wifi, the problem has not materialized ever since. Not sure if that was the root cause / fix…

Will report back once I hear something.

[mr.airworthy (Alrik)]

Thanks. I’m running homematic on a CCU2 (connected via ethernet) and openHAB 4.3.3 in a docker on my Synology Diskatation 720+.
CCU2 I didn’t change nothing, just updated OH.

[mr.airworthy (Alrik)]

Unfortunately still no update/change. No matter how often I restart OH, CCU2 or Diskstation, the Homematic binding updates the values only ones and doesn’t do anything thereafter.

Am I the only one having this issue?

Have a great weekend!

[Cplant]

Anything in the logs?

[mr.airworthy (Alrik)]

2025-03-14 22:56:31.693 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name 'Chart Temperatur Buero' contains invalid characters, new Datapoint name 'Chart_Temperatur_Buero'
2025-03-14 22:56:31.694 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name 'Remote Angelika * Carport Licht' contains invalid characters, new Datapoint name 'Remote_Angelika___Carport_Licht'
2025-03-14 22:56:32.760 [WARN ] [ternal.handler.HomematicThingHandler] - Value for datapoint HmDatapoint[name=CONF_BUTTON_TIME,value=255,defaultValue=255,type=INTEGER,minValue=1,maxValue=254,options=null,readOnly=false,readable=true,unit=minutes,description=CONF_BUTTON_TIME,info=null,paramsetType=MASTER,virtual=false,trigger=false] is outside of valid range, using default value for config.
2025-03-14 23:00:43.708 [INFO ] [ommunicator.AbstractHomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=2.61.7,address=MEQ1490729,rf=true,wired=false,hmip=true,cuxd=true,group=true]
2025-03-14 23:00:53.979 [WARN ] [very.HomematicDeviceDiscoveryService] - Failed to set Homematic controller in install mode
java.io.IOException: -1 setInstallMode: unknown.method name (sending setInstallMode()
true
60
1
)
	at org.openhab.binding.homematic.internal.communicator.parser.RpcResponseParser.parse(RpcResponseParser.java:50) ~[?:?]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:83) ~[?:?]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:95) ~[?:?]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:95) ~[?:?]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:95) ~[?:?]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:71) ~[?:?]
	at org.openhab.binding.homematic.internal.communicator.client.RpcClient.setInstallMode(RpcClient.java:439) ~[?:?]
	at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.setInstallMode(AbstractHomematicGateway.java:602) ~[?:?]
	at org.openhab.binding.homematic.internal.discovery.HomematicDeviceDiscoveryService.enableInstallMode(HomematicDeviceDiscoveryService.java:82) ~[?:?]
	at org.openhab.binding.homematic.internal.discovery.HomematicDeviceDiscoveryService.startScan(HomematicDeviceDiscoveryService.java:67) ~[?:?]
	at org.openhab.core.config.discovery.AbstractDiscoveryService.startScanInternal(AbstractDiscoveryService.java:253) ~[?:?]
	at org.openhab.core.config.discovery.AbstractDiscoveryService.startScan(AbstractDiscoveryService.java:216) ~[?:?]
	at org.openhab.binding.homematic.internal.handler.HomematicBridgeHandler.initializeInternal(HomematicBridgeHandler.java:123) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.lang.Thread.run(Thread.java:840) [?:?]

This is what I found.