After network outage Homematic items are visible and receiving updates on the device, but not updating values in Openhab

Add-ons Bindings
1

I have three raspberry pis, one is my central controller, the others two are running homegear with a CUL stick to control Max devices.

This works remarkably well, and is generally successful for me.

However, I’m noticing a problem (which may or may not have only started happening after the upgrade to Openhab 3). I’m having some instability in my wifi, and so the two homegear pis will sometimes go offline (usually because they’ve decided to connect to an access point that is too far away from them, and so have very poor connectivity). Openhab/HomeMatic Binding notices they’re offline. When I restart their networking (or sometimes reboot them), Openhab notices that they’re now online, and successfully starts sending them set point changes. However, the valve state, temperature and some other values don’t appear to be coming back into Openhab. I can fix this by restarting openhab, at which point it all springs into life, but this isn’t really desirable for me - I’d like it to self heal when the devices are reachable again.

Before I spend time diagnosing/debugging/providing logs etc, I’m interested in whether this is a known issue, or something that has been reported before. If there’s a known and simple fix then I should do that. For example, I did see in the extras some switches to restart the binding or the gateway - perhaps they exist for this purpose?

Thanks for any information provided,

Paul

2

Replying to myself after more research.

This problem sounds vaguely similar to this thread: Debugging Homematic IP: no updates on some HmIP devices after some time - #13 by haukman

However, that says that it is fixed in 3.1, and I’m on 3.1.0-1, so presumably I have a fixed version. Having said that, I did just run an upgrade two days ago, before that I was on one of the release candidates for 3.1. Perhaps this fix didn’t go in until the final 3.1?

3

I run the same (3.1, homegear, CUL, all in one box) and have occasionally seen this earlier but not yet since I upgrade to 3.1

I would think it’s in as it was done back in January but @MHerbst can tell.

Have you tried to only restart homegear?

4

3.1 behaves definitely better than previous OH version. But there are a few HmIP devices that still cause problems after a restart of the CCU or Homegear. It seems to happen with HmIP devices that send data to the CCU relatively infrequently, and for which values sometimes only appear in the CCU minutes after a restart.

But unfortunately, the HM binding included in version 3.1 contains a nasty bug (introduced by myself …), that will lead to problems with some devices. You can install a patched version from here: GitHub - MHerbst/openhab-addons-test

What devices do not update their states correctly?

5

For me it’s actually Max devices, and the valve state on the heating thermostats. Restarting Homegear doesn’t seem to fix it, I’m waiting for it to happen again so I can go through systematically a few different resolutions to see what my minimum is to fix it. I’m hoping that using the “reload all” function will fix it, but haven’t quite managed to catch it again to try that.

6

Are you aware that MAX! don’t update the valve and temp values unless the valve gets instructed to turn ?

7

Yes, aware of that. They also update when you change the set point, they return the newly set set point. The wall thermostats do update their temperature regularly.

Having said this morning that I was waiting for it to happen, it looks like it is happening this morning (I’ve had all sorts of network issues overnight for various reasons, so that may have triggered it). I have two separate Homegear installs (the house is too big for one install to reach all the valves). One of them is reporting valve state, the other is reporting all valves set to zero (which is the normal middle of the night state, but not the daytime state).

I tried reloading all, and it didn’t return any change in valve state.

The Homegear log on the gateway I’m not getting updates from looks like this:

07/19/21 08:39:38.782 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:59898 accepted. Client number: 263
07/19/21 08:39:38.782 RPC Server (Port 2001): Info: RPC server client id for client number 263 is: 254
07/19/21 08:39:38.797 RPC Server (Port 2001): Info: Client number 263 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:39:49.334 IPC Server: Info: Client number 0 is calling RPC method: lifetick Parameters:
07/19/21 08:39:51.913 MAX packet received (KITCHEN-CUL, RSSI: 0x46): 0CB404421367420000000021BE
07/19/21 08:39:51.914 Module MAX: Info: ACTUAL_TEMPERATURE on channel 1 of peer 1 with serial number MEQ0855065 was set to 0x00BE.
07/19/21 08:39:51.914 Module MAX: Info: SET_TEMPERATURE on channel 1 of peer 1 with serial number MEQ0855065 was set to 0x21.
07/19/21 08:39:53.850 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:59914 accepted. Client number: 264
07/19/21 08:39:53.850 RPC Server (Port 2001): Info: RPC server client id for client number 264 is: 255
07/19/21 08:39:53.862 RPC Server (Port 2001): Info: Client number 264 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:40:09.167 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:59932 accepted. Client number: 265
07/19/21 08:40:09.167 RPC Server (Port 2001): Info: RPC server client id for client number 265 is: 256
07/19/21 08:40:09.176 RPC Server (Port 2001): Info: Client number 265 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:40:24.516 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:59946 accepted. Client number: 266
07/19/21 08:40:24.517 RPC Server (Port 2001): Info: RPC server client id for client number 266 is: 257
07/19/21 08:40:24.524 RPC Server (Port 2001): Info: Client number 266 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:40:39.580 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:59956 accepted. Client number: 267
07/19/21 08:40:39.580 RPC Server (Port 2001): Info: RPC server client id for client number 267 is: 258
07/19/21 08:40:39.583 RPC Server (Port 2001): Info: Client number 267 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:40:49.383 IPC Server: Info: Client number 0 is calling RPC method: lifetick Parameters:
07/19/21 08:40:54.910 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:59970 accepted. Client number: 268
07/19/21 08:40:54.910 RPC Server (Port 2001): Info: RPC server client id for client number 268 is: 259
07/19/21 08:40:54.917 RPC Server (Port 2001): Info: Client number 268 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:41:09.969 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:59982 accepted. Client number: 269
07/19/21 08:41:09.969 RPC Server (Port 2001): Info: RPC server client id for client number 269 is: 260
07/19/21 08:41:09.976 RPC Server (Port 2001): Info: Client number 269 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:41:25.303 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:59998 accepted. Client number: 270
07/19/21 08:41:25.303 RPC Server (Port 2001): Info: RPC server client id for client number 270 is: 261
07/19/21 08:41:25.306 RPC Server (Port 2001): Info: Client number 270 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:41:40.511 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:60018 accepted. Client number: 271
07/19/21 08:41:40.511 RPC Server (Port 2001): Info: RPC server client id for client number 271 is: 262
07/19/21 08:41:40.520 RPC Server (Port 2001): Info: Client number 271 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:41:49.434 IPC Server: Info: Client number 0 is calling RPC method: lifetick Parameters:
07/19/21 08:41:55.159 MAX packet received (KITCHEN-CUL, RSSI: 0x51): 0CF50442136E88000000002ACF
07/19/21 08:41:55.696 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:60030 accepted. Client number: 272
07/19/21 08:41:55.696 RPC Server (Port 2001): Info: RPC server client id for client number 272 is: 263
07/19/21 08:41:55.704 RPC Server (Port 2001): Info: Client number 272 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:42:11.045 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:60048 accepted. Client number: 273
07/19/21 08:42:11.045 RPC Server (Port 2001): Info: RPC server client id for client number 273 is: 264
07/19/21 08:42:11.054 RPC Server (Port 2001): Info: Client number 273 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:42:26.395 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:60062 accepted. Client number: 274
07/19/21 08:42:26.395 RPC Server (Port 2001): Info: RPC server client id for client number 274 is: 265
07/19/21 08:42:26.403 RPC Server (Port 2001): Info: Client number 274 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:42:41.748 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:60082 accepted. Client number: 275
07/19/21 08:42:41.748 RPC Server (Port 2001): Info: RPC server client id for client number 275 is: 266
07/19/21 08:42:41.755 RPC Server (Port 2001): Info: Client number 275 is calling RPC method: listBidcosInterfaces (1) Parameters:
07/19/21 08:42:43.912 MAX packet received (KITCHEN-CUL, RSSI: 0x46): 0CB504421367420000000021C0
07/19/21 08:42:43.913 Module MAX: Info: ACTUAL_TEMPERATURE on channel 1 of peer 1 with serial number MEQ0855065 was set to 0x00C0.
07/19/21 08:42:43.913 Module MAX: Info: SET_TEMPERATURE on channel 1 of peer 1 with serial number MEQ0855065 was set to 0x21.
07/19/21 08:42:49.483 IPC Server: Info: Client number 0 is calling RPC method: lifetick Parameters:
07/19/21 08:42:56.891 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.1.15:60098 accepted. Client number: 276
07/19/21 08:42:56.891 RPC Server (Port 2001): Info: RPC server client id for client number 276 is: 267
07/19/21 08:42:56.894 RPC Server (Port 2001): Info: Client number 276 is calling RPC method: listBidcosInterfaces (1) Parameters:

I don’t see the normal transactions that a “reload all” would trigger - I would normally see a bunch of reads.

I tried restarting homegear, I see this in the openhab logs:

2021-07-19 09:01:53.061 [INFO ] [rg.openhab.core.model.script.devices] - Running device rolldown
2021-07-19 09:01:53.184 [INFO ] [rg.openhab.core.model.script.devices] - Set WallMasterSetpoint to 19 pausing before considering next device
2021-07-19 09:05:27.757 [WARN ] [ternal.handler.HomematicThingHandler] - Device with address 'MEQ0855065' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:05:27.856 [WARN ] [ternal.handler.HomematicThingHandler] - Device with address 'MEQ1354474' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:05:27.871 [WARN ] [ternal.handler.HomematicThingHandler] - Device with address 'MEQ1354719' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:05:29.002 [INFO ] [rg.openhab.core.model.script.devices] - Running device rolldown
2021-07-19 09:05:29.010 [WARN ] [ternal.handler.HomematicThingHandler] - Device with address 'MEQ1344573' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:05:33.179 [WARN ] [ternal.handler.HomematicThingHandler] - Device with address 'MEQ1344264' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:05:36.258 [WARN ] [ternal.handler.HomematicThingHandler] - Device with address 'MEQ1344574' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:05:37.778 [WARN ] [ternal.handler.HomematicThingHandler] - Device with address 'MEQ1344632' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:05:38.941 [WARN ] [ternal.handler.HomematicThingHandler] - Device with address 'MEQ1354716' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:06:46.917 [WARN ] [ommunicator.AbstractHomematicGateway] - Connection lost on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D', cause: "IOException java.util.concurrent.
ExecutionException: java.net.ConnectException: Connection refused"
2021-07-19 09:07:17.110 [INFO ] [ommunicator.AbstractHomematicGateway] - Connection resumed on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.116 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'MEQ1344574' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.120 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'MEQ1344573' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.123 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'MEQ0855065' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.129 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'MEQ1344264' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.133 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'GWE00000000' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.137 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'MEQ1354474' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.141 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'MEQ1344632' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.145 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'MEQ1354716' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'
2021-07-19 09:07:17.149 [WARN ] [ernal.handler.HomematicBridgeHandler] - Device with address 'MEQ1354719' not found on gateway 'ABDD5864-8959-5743-FE7A-8ADC71DCD01D'

(I restarted twice to be sure, so the same messages there twice I think).

At this point openhab believed that the setpoints on the devices were 19 degrees, but the devices themselves reported 17 degrees. I changed on the device to 17.5, that didn’t come through to openhab. I changed the setpoint in openhab to 19.5, that didn’t come through to the device.

I then restarted openhab, and all the set points came through accurately and it started working. So I surmise that something at the openhab end is losing connectivity to the gateway itself.

8

Further information. I had this situation again today - a short outage on one of the raspberry pis. I can see the set points updating as expected at the times they change. However, no information about valve state is flowing back.

Interestingly, this time I successfully used the “reload all” function on that gateway, and the valves all updated to their current values. So it wasn’t polling and/or receiving pushes of valve state from the gateway, but when I asked it to query it did receive those updates.

At that point I thought “excellent, that fixes it.” But looking again this evening, I can see that the valves have been static for quite some time. Pressing “reload all” again updated the valves to their current states again. But I suspect I’ll need an openhab restart to have it receive these updates automatically.

9

And further information. Today I had no network outage, but one of the two gateways isn’t updating valve positions. When I press “reload all” on that gateway, it gets what appear to be correct valve settings (i.e. matches what I’d expect). If I leave it alone, they then simply stay at that setting. After a couple of hours it’s clear they’re incorrect, if I press “reload all” again it then reloads what look to be correct settings. So openhab is able to communicate with the gateway and get the correct setting, but it’s clearly not automatically receiving that when they change. It is also correctly setting the setpoints on the valves.

Is the mechanism a poll, or is there some sort of pub/sub regime with the homegear instance?

10

I stumbled upon this thread only after opening a new thread for what I believe is at least a similar root cause (if not the same) for what I have experienced (lost updates / connection of some Homematic devices). My description: Homematic IP device status updates stop being received by openHAB (but controlling these devices still works)