Homematic binding not receiving updates

But openHAB is getting the events, I can see them arriving in the openHAB log. The updates aren’t, however, arriving on the UI unless I stop and start the thing, presumably because it isn’t updating the channel.

For example:

2022-05-30 12:14:34.102 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '19.0' for 'MEQ0856945:1#SET_TEMPERATURE' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
.......
                methodName=event
                params=
                [
                        45bd3a92-d909-4ae2-b810-64a1df03cbca
                        MEQ1354719:1
                        SET_TEMPERATURE
                        22.0
                ]
......
2022-05-30 12:14:34.170 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '22.0' for 'MEQ1354719:1#SET_TEMPERATURE' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'

So my question is why it’s not updating into the UI / the linked field from which all my rules run. The add-on log shows the value arriving (in both instances - at 12:14:34 and again at 12:18:52), but it doesn’t update into openHAB itself.

Interestingly, looking at it again this morning to extract for this comment, it isn’t actually updating the channel, it’s just arriving and then nothing happens. With the second log entry at 12:18:52 you can see it didn’t update the channel until I disabled and reenabled the thing:

                methodName=event
                params=
                [
                        5535563e-0087-4dc9-94bd-968a4335c72b
                        MEQ1354719:1
                        SET_TEMPERATURE
                        18.5
                ]
....
2022-05-30 12:18:52.502 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '18.5' for 'MEQ1354719:1#SET_TEMPERATURE' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
....
2022-05-30 12:19:52.956 [DEBUG] [ternal.handler.HomematicThingHandler] - Initializing thing 'homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719' from gateway 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
....
2022-05-30 12:19:53.028 [DEBUG] [ternal.handler.HomematicThingHandler] - Updating channel 'homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:1#SET_TEMPERATURE' from thing id 'MEQ1354719'
2022-05-30 12:19:53.030 [DEBUG] [converter.type.AbstractTypeConverter] - Converting datapoint 'MEQ1354719:1#SET_TEMPERATURE' (dpType='FLOAT', dpUnit='°C', dpValue='18.5') with QuantityTypeConverter

Is there some state or other behaviour that could cause it to receive the updates but to not update the channel?

In terms of ports and firewalls.

  1. The data is arriving as a push from the Homegear, so it must be connecting to the correct port at the openHAB end
  2. OpenHAB is able to obtain the data when I stop and start the thing, so it must be able to connect to Homegear and Homegear must be listening on the correct port
  3. I have no internal firewalls and everything is on the same network (no transits other than from wifi to wired)
  4. The Homegear it’s communicating with has nothing else of note running on it - no piVCCU or other function

I guess it’s possible that the piVCCU on the second raspberry pi is somehow causing a state problem. I don’t see anything in the logs that indicate that, and when I use my workaround script all the data arrives for every device - so all the connectivity must be in place. I also believe I had a similar problem prior to installing the piVCCU - I’ve always had “stuck” devices but have never been able to recreate. It is now reliably stuck most of the time - but it feels like that’s just a more frequent occurrence of a behaviour I’ve had for a while.

Arguably I’m no longer seeing any pro-active updates at all any more - I’m only getting updates when I stop and start the thing. So perhaps there’s something systemically misconfigured or broken that only stops the pub/sub from working. But that seems weird when I can actually see the data in the openHAB log - so it’s arriving but not being processed.

Sorry, there was a misunderstanding on my side.

How did you define things and items? In Main UI or as text files?
If you are using textual definitions, please post thing and item definitions. Maybe the channels are not correctly connected to their items.

If you are using text files you could try to define an additional item in Main UI and test whether this item is updated correctly.

The things are via the main ui. The items are via a text file, this specific item is defined as follows:

/* Dining */
Group valveDining "Dining" <none> (zoneDevicesLiving, Devices, DevicesValves)
Number DiningSetpoint "Dining Current Setpoint [%.1f °C]" <temperature> (valveDining, DeviceSetpoints, InitSetpoints)  { channel="homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:1#SET_TEMPERATURE" }
Switch DiningBattery "Dining Battery" <battery> (valveDining, DeviceBatteries) { channel="homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:0#LOWBAT" }
Number DiningTemp "Dining Temp [%.1f °C]" <temperature> (valveDining, DeviceTemps) { channel="homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:1#ACTUAL_TEMPERATURE" }
Number DiningValve "Dining Valve [%d %%]" (valveDining, DeviceValves) { channel="homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:1#VALVE_STATE" }
Number DiningSignalStrength "Dining Signal Strength [%d]" <signal> (valveDining, DeviceSignalStrength) { channel="homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:0#SIGNAL_STRENGTH" }
Number DiningDecalTime "Dining Decalcification Time [%d]" <clock> (valveDining, DeviceDecalTime) { channel="homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:1#DECALCIFICATION_TIME" }
Number DiningDecalWeekday "Dining Decalcification Day [%d]" <clock> (valveDining, DeviceDecalWeekday) { channel="homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:1#DECALCIFICATION_WEEKDAY" }
Switch DiningOn "Dining On" (valveDining, DeviceOn, Switches, InitSwitchesOn)
Number DiningValveAdjustor "Dining Room Valve Adjustor [%d %%]" (valveDining, DeviceValveAdjustors) 
Number DiningAdjustedValve "Dining Room Adjusted Valve [%d %%]" (valveDining, DeviceAdjustedValves) 

I presume this config is working for two reasons:

  1. When I restart the thing the data flows through to the item (so it must be connected)
  2. In the main UI, it shows the thing as being correctly connected:

I’m going to be out of town for a couple of days, and can try defining a new item via the UI then, but I don’t see why that would make a difference given those points.

Are you absolutely sure about the channel UID? Did you copy that from the UI or did you create the Items via VSCode by using auto create feature from openHAB plugin?

Please be aware that the Item type (at least for tempoerature) should be Number:temperature, not Number

Thanks Udo.

I copied from the UI, it works when I stop/start the thing, and it shows in the UI as being linked. I think it is correctly linked for those reasons.

What difference would it give if I define as Number:temperature? The other fields (such as the valve state) also have the same problem, so I presume this isn’t the problem, but I could be wrong.

Overall, my suspicion is that there’s something going wrong in the internals. I can see the data flowing through in the log “Receiving new value”, but not updating in the UI. Then after a disable/enable on the individual thing, I can see it updating the channel, and it appears in the UI “Updating channel” and “Converting datapoint”.

From this I would conclude that:

  1. The item must be correctly linked. If it was incorrectly linked it would never update, rather than updating only after a disable/enable on the thing

  2. It probably isn’t any sort of networking issue, as the data is actually arriving and reported as such in the log.

I’ll grant that perhaps the item is somehow incorrectly linked such that it only works after a disable/enable. I’m not aware of what would be wrong to cause that, but it’s possible. I’m not sure how I’d diagnose that though, so open to any ideas on tests or configuration I could try.

I’ll also grant that the networking could be an issue if the design is such that it receives data, but needs some sort of acknowledgement before it processes the data. If that’s the case, then perhaps that acknowledgement is failing, but not writing any information about that failure in the log. If that’s a possibility, then I’m happy to look at the networking - again, I’m interested in what diagnostic steps or configuration I’d try so as to resolve that.

Beyond that, it really looks to me like some sort of stall in the processing. So it’s received the update, but perhaps it’s putting it in a queue that’s getting stuck, or it’s waiting for some other event or timer that’s never happening. But I know nothing about the internals to know what has to happen to move from “data was received” (in the log) to “channel was updated”.

2022-05-30 12:18:52.502 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '18.5' for 'MEQ1354719:1#SET_TEMPERATURE' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
....
2022-05-30 12:19:52.956 [DEBUG] [ternal.handler.HomematicThingHandler] - Initializing thing 'homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719' from gateway 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
....
2022-05-30 12:19:53.028 [DEBUG] [ternal.handler.HomematicThingHandler] - Updating channel 'homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719:1#SET_TEMPERATURE' from thing id 'MEQ1354719'
2022-05-30 12:19:53.030 [DEBUG] [converter.type.AbstractTypeConverter] - Converting datapoint 'MEQ1354719:1#SET_TEMPERATURE' (dpType='FLOAT', dpUnit='°C', dpValue='18.5') with QuantityTypeConverter

I can remember that there was a problem if it is not defined as Number:temperature. Therefore it is generally better to set it.
Regarding the VALVE_STATE, it seems that it is not Number but a String (I have a similar device and the channel is defined as String). Please check the definition in Main UI (it may be different for your device). This could explain why this item is also not updated.

I agree with you that it can be an internal problem. Your installation contain three bridges and in addition one of them uses BinRPC protocol. There can be a problems with the “event routing” and the event received from the CCU is not correctly routed to the correct Thing/Channel.

I can also remember an internal problem in OH were some wrong definitions were store in the OH configuration files (JSONDB). Everything looked fine in Main UI but items were not updated.

I have to look into the code of the binding. Maybe I can see a possible reason or have which additional traces could help.

Thanks very much Martin.

I’ll check when I’m home, but my recollection is that the HMIP devices have VALVE_STATE as a string, and you need to use LEVEL instead (which is a dimmer). So I think I’ve checked that already, I’ll recheck tonight.

On the number:temperature, I’ll make that change. I’ve had this installation since openhab 1, and that isn’t a change that I’d had to make when I moved to OH2 or to OH3, and it definitely worked for a while. But no harm in changing it. Are there any of the other data types that may be problematic? Is there a place I can get a list of them…or do I perhaps just have to match exactly the data type that the UI reports for each field?

I can see that the two temperatures (setpoint and actual) are defined as Number:Temperature. The valve state is a dimensionless number - I’m assuming I don’t need to specify it as Dimensionless in the config?

OK, I’ve spent the time to rework everything to use Number:Temperature, and therefore all rules to use QuantityType for working variables, and then some of the tricks and tips from this thread: Working with Number:Temperature Items in rules. This was all substantially harder than I imagined, so posting the link and detail for others who may find this thread and need to do the same thing.

Having done that, I’m still seeing a number of devices not updating. Interestingly, at the moment all the devices that are not updating are connected to one Homegear instance - the one that doesn’t have the piVCCU on it. I’m not sure if that’s coincidence that one is working and one not, or whether actually the thermostats with problems have always been the ones on that same device. I think I recall having problems with thermostats on the other Homegear, but I will monitor to understand.

I will now do some more diagnosis, and potentially run a reboot cycle on everything once I’m certain it’s stable from the data type changes.

And, final update, because I’m a bit stumped. I ran a full reboot cycle. One of the bridges the updates flow automatically - I have logs that show:

  1. Change the thermostat setting manually on the thermostat
  2. Data arrives via the bridge, visible in the openhab log
  3. Data updated to the channel, and to the associated items

This all flows automatically.

Devices on the other bridge:

  1. Change thermostat setting manually on the thermostat
  2. Data arrives via the bridge, visible in the log
  3. Data never updates to the channel, no errors or other information logged
  4. Disable then enable the thing
  5. Data updated to the channel, log entries very similar to the log entries for point 3 above

I see no differences in the bridge configuration. The physical devices are the same model. The configuration of items etc appears the same (and all this configuration was originally done by copy and paste).

Things I might surmise:

  1. It appears to be all items connected to one particular bridge. Therefore it’s unlikely to be item configuration or channel configuration or thing configuration - if so then I’d expect one or two individual items or channels to not work, not all the channels on a single bridge
  2. The item and thing configuration must be mostly right, because the disable/enable cycle leads to the data flowing. If the UID or channel name or other setting was wrong, then it would never work rather than only working sometimes
  3. It feels like it’s unlikely to be a state issue on the bridge. Because I rebooted and one bridge is working, the other isn’t, that doesn’t seem like a transient state issue. I’m less confident on this though - it could be something about that bridge that consistently drives it into some erroneous state
  4. It’s unlikely to be Homegear configuration, both because one works and one doesn’t, and because the data is actually flowing to Openhab and is visible in the trace log. So it needs to be some interaction at the Openhab end (although I’m not ruling out something in the Homegear configuration or state that leads to a problem at the Openhab end).

My best guess is that there’s something (configuration, timing, settings) that is triggering an error in Openhab. The code may be silently failing, or perhaps is going down an unexpected branch condition that results in the data not being processed.

Looking closely at the log files, for the valve that works, the log looks like this:

2022-06-02 16:54:50.472 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '23.0' for 'LEQ1131072:1#ACTUAL_TEMPERATURE' from gateway with id '4BCAAC30-44F5-BBDE-
DF54-27D1B87DCE09'
2022-06-02 16:54:50.477 [DEBUG] [converter.type.AbstractTypeConverter] - Converting datapoint 'LEQ1131072:1#ACTUAL_TEMPERATURE' (dpType='FLOAT', dpUnit='°C', dpValue='23.0') with Quantity
TypeConverter
2022-06-02 16:54:50.488 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '1' for 'LEQ1131072:1#CONTROL_MODE' from gateway with id '4BCAAC30-44F5-BBDE-DF54-27D
1B87DCE09'
2022-06-02 16:54:50.494 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for 'LEQ1131072:1#LOCKED' from gateway with id '4BCAAC30-44F5-BBDE-DF54-27D1B
87DCE09'
2022-06-02 16:54:50.499 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '19.0' for 'LEQ1131072:1#SET_TEMPERATURE' from gateway with id '4BCAAC30-44F5-BBDE-DF5
4-27D1B87DCE09'
2022-06-02 16:54:50.504 [DEBUG] [converter.type.AbstractTypeConverter] - Converting datapoint 'LEQ1131072:1#SET_TEMPERATURE' (dpType='FLOAT', dpUnit='°C', dpValue='19.0') with QuantityTyp
eConverter
2022-06-02 16:54:50.515 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '0' for 'LEQ1131072:1#VALVE_STATE' from gateway with id '4BCAAC30-44F5-BBDE-DF54-27D1
B87DCE09'
2022-06-02 16:54:50.518 [DEBUG] [converter.type.AbstractTypeConverter] - Converting datapoint 'LEQ1131072:1#VALVE_STATE' (dpType='INTEGER', dpUnit='%', dpValue='0') with QuantityTypeConve
rter

The valve that doesn’t work, the log looks like this:

2022-05-30 12:18:52.496 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '20.4' for 'MEQ1354719:1#ACTUAL_TEMPERATURE' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
2022-05-30 12:18:52.498 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '1' for 'MEQ1354719:1#CONTROL_MODE' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
2022-05-30 12:18:52.500 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Boolean) value 'false' for 'MEQ1354719:1#LOCKED' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
2022-05-30 12:18:52.502 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Double) value '18.5' for 'MEQ1354719:1#SET_TEMPERATURE' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'
2022-05-30 12:18:52.504 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (Integer) value '30' for 'MEQ1354719:1#VALVE_STATE' from gateway with id 'F6B89899-2A5B-533A-A2EC-A308C51F07EF'

The difference seems to be that it’s not invoking the “converting datapoint” pathway. And the associated logic seems to be in or driven from the AbstractHomematicGateway, and an earlier log entry indicates we’re in the BinRpcMessage logic.

Looking in the AbstractHomeGateway.java at line 738 I see what could be relevant. There’s an

if (initialised){

that looks to be the only non-trivial branch condition prior to processing. In a perfect world I think we’d have

else { 
  logger.debug("Not initialized therefore not processing'", dpInfo);
}

I can also see:

} catch (HomematicClientException | IOException ex) {
    // ignore
}

Again, in a perfect world we’d have:

} catch (HomematicClientException | IOException ex) {
    logger.debug("IOException silently suppressed'", ex);
}

I don’t have a development environment, nor the skills, to make and test the changes unfortunately, but I think this could take us some way towards understanding what’s happening.

If it’s the initialised status that’s the cause of the problem, then presumably if I disable and enable the thing I should see initialisation messages, and potentially an error that tells me it’s not getting initialised.

In the log I see:

2022-06-02 18:04:46.470 [DEBUG] [ommunicator.AbstractHomematicGateway] - Loading values for channel HmChannel[number=4,initialized=false] of device 'MEQ1354719'

but I believe that to be an initialised status on the channel, not on the gateway as a whole - and I believe the check at line 738 is checking initialised status on the gateway.

When I restart the gateway it is clearly in the loadAllDeviceMetadata method, as I see log entries such as Loading metadata for device (line 385) and Loading channel (line 392). Again, there is no trace logging that tells us we reached the end and set the initialised status. It would be nice to add or around line 431:

        }
        initialized = true;
        logger.debug("Gateway initialization completed for gateway '{}'", id);
    }

That’s probably as far as I can go without a dev environment or the ability to run a debugger - but those extra trace statements would potentially give us the smoking gun as to what’s going on (and assist debugging in the future if other people have similar issues).

OK, a bit of a learning curve, but I have a dev environment running and am able to make code changes to debug what’s happening. And after tracing all the way through, I can see that:

  1. The gateway is initialised, and is processing the update
  2. It is calling dp.setValue at line 740-ish in AbstractHomematicGateway.java
  3. It is correctly getting to handleVirtualDatapointEvent, and the conversion (and presumably datapoint update) happens before then
  4. In HomematicBridgeHandler.java it returns a null thing from getThing(). And that’s because the UID it generates is different from the real UID of the thing
  5. In turn that’s because the UID for the thing is “homematic:HG-BC-RT-TRX-CyG-3:ABDD5864-8959-5743-FE7A-8ADC71DCD01D:MEQ1354719”, but the gateway it’s connected to has a UID of “homematic:bridge:F6B89899-2A5B-533A-A2EC-A308C51F07EF”. The generated UID inside onStateUpdated uses this UID - so it generates “homematic:HG-BC-RT-TRX-CyG-3:F6B89899-2A5B-533A-A2EC-A308C51F07EF:MEQ1354719”, which then isn’t found because the real thing doesn’t have that UID.

All the things were created from the inbox, so it’s an interesting muddle that they’re in. I presume it’s just cruft left over from having upgraded this system multiple times over the years (openhab1->2->3 etc), something must have tied itself in knots.

I have deleted the gateway and all the things, and recreated them from the inbox. They have created with the correct UID. It looks like all my data is now updating dynamically as it would be expected to.

So, a lot of messing around to come to the conclusion that the thing id in the configuration didn’t match the real derived thing id. What’s weird is that it seemed happy to update when the thing was restarted, so it must have had enough information to find it on restart, but not enough information to find it when information was pushed over the pub/sub.

If someone were so inclined, this situation could be detected in future by placing an else clause on the null check:

    public void onStateUpdated(HmDatapoint dp) {
        Thing hmThing = getThing().getThing(UidUtils.generateThingUID(dp.getChannel().getDevice(), getThing()));
        if (hmThing != null) {
            final ThingStatus status = hmThing.getStatus();
            if (status == ThingStatus.ONLINE || status == ThingStatus.OFFLINE) {
                HomematicThingHandler thingHandler = (HomematicThingHandler) hmThing.getHandler();
                if (thingHandler != null) {
                    thingHandler.updateDatapointState(dp);
                }
            }
        } else {
            logger.debug("Thing not found for thing uid '{}'", UidUtils.generateThingUID(dp.getChannel().getDevice(), getThing()));
        }
    }

Thanks very much to everyone for the assistance and pointers.

3 Likes

Good to hear that you could solve the problem. When I switched from 2.5 to 3.1deleted my existing configuration and started with a completely fresh installation. Quite a lot of work but but it probably saved me from a few problems :-).

Thanks for your proposal for the code improvement. Sounds like a good idea and I can add it to the code.

1 Like

Had the same problem. Everything seemed to work, but only updated if I restarted the binding thing. Fixed it by removing everything related to my homegear setup, and re-adding them to Openhab from scratch. Now instant status updates. Thanks for the hard work!

Hi there, I’m faceing the same problem and have been getting along with the “Reload All From Gateway” channel from the GATEWAY-EXTRAS. I switch this one to ON by rule every 5 minutes and it reloads all states from the ccu. But this can’t be the solution. Might work for temperatures which don’t change that often, but in terms of doorcontacts this is way to long.
After a long search I’ve found this thread and deleted all Things and the Gateway, restarted openHAB and recreated them through the inbox. But still faceing the problem of not updating states.
Can anyone help? Do I have to remove the Binding to?
Setup is openHAB 3.3 in docker on Synology Diskstation and original CCU3. Config in general is working because state updates from CCU3 to openHab are working with the written workaround and sendCommand from openHAB to CCU3 works as expected.
Thanks in advance

1 Like

For me it was a specific device that wasn’t receiving updates, and it was that device that was improperly configured. I am also using file based configuration, I think you’re less likely to get configuration errors with inbox based configuration.

Do you have any pattern to which states are working and which are not? Do you have any other configuration at all that references/uses the CCU that could be causing the issue? Are you able to cut your configuration down to a single device from the inbox, a single gateway, and not much else? That may give you some hints.

When you turn on debug logging, do you get any messages at all that may be relevant?

I’m useing only Homematic IP Devices on this CCU. Manly eTRV and eTRV2 for radiator control, some WTH and some doorsensors (SWDM and SWDO). When I recreated the Things, I watched the behavior but it startet with the first one while every rule or configuration regarding the things was disabled. Every other Binding/Gateway is working as expected, it’s just the Homematic one that’s giveing me headache.

In the openhab.log file there are two warnings about the two windowsensors SWDM saying:

2022-12-06 08:00:34.806 [WARN ] [ommunicator.parser.GetParamsetParser] - Can’t set value for datapoint ‘00155F29xxxxx:0#UPDATE_PENDING’

So I again deleated these two things and all links to Items, but it didn’t change anything for the other items.
How can I get debug logging? Sorry, I’m just maybe an advanced user but no developer

There’s a few ways to turn on debug logging.

There are instructions in the binding info on turning on logging: Homematic - Bindings | openHAB

Log on to the Karaf console - for me this is:

ssh -p 8101 openhab@localhost

Password is usually habopen (or HabOpen, can’t recall).

Then turn on DEBUG logging or TRACE logging.

log:set DEBUG org.openhab.binding.homematic

You can see logs with

log:tail

Or just look in your log files as normal. I tend to find the log:tail gives me more info for some reason, never bothered to look into it in detail. I sometimes need to restart my openhab to make the log changes take effect - no idea why on that either. Most probably some sort of user error.

It produces a lot of logging, particularly at trace level. Working out what’s relevant can be hard. I’d probably start off with toggling updates on some device and see what’s coming into the log, and whether anything looks suspicious. Then if need be do the full startup trace as suggested in the binding doco - but that does give a lot of info that takes a while to sort through.

If you post here some subsets of info and explanations of what’s happening people will help. And you may be able to compare to my similar logs above, to see if you’re getting something different going on.

I suddenly have the same issue: OH 3.3 does not get change events anymore from my CCU3.
This was working now fine for years and stopped working after I restarted OH today (because of other reasons). Now I do not get change events anymore (besides those for the Bridgte Duty cycle).
Between today’s restart and the one before that, I added an HmIP-PSM-2 to the CCU3 and added some devices/channels to rooms and “Gewerke” that were unassigned before.

Trying to fix this I already rebooted the CCU3 and restarted OH several times (also with cleaning tmp and cache).

The CCU3 spits out errors when OH starts, I don’t remember seeing those before:

Dec 31 16:48:10 ccu cuxd[655]: process_rpc_request(192.168.0.7) - illegal XMLRPC(init) request
Dec 31 16:48:10 ccu rfd: XmlRpc transport error calling system.listMethods({"bb707ce1-8b96-47c1-9e91-458c51a57834"}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:10 ccu rfd: XmlRpc transport error calling listDevices({"bb707ce1-8b96-47c1-9e91-458c51a57834"}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:10 ccu cuxd[655]: INIT 'binary://172.17.0.1:9126' 'f645c189-f8f3-4134-aad1-6611e9aa1471'
Dec 31 16:48:19 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1975027:2","BOOT",false}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:19 ccu rfd: XmlRpc transport error
Dec 31 16:48:20 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1975027:2","ENERGY_COUNTER",228673.900000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1975027:2","POWER",4.230000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1975027:2","CURRENT",76.000000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1975027:2","VOLTAGE",239.900000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1975027:2","FREQUENCY",49.970000}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:20 ccu rfd: XmlRpc transport error
Dec 31 16:48:28 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1977779:1","STATE",true}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:28 ccu rfd: XmlRpc transport error
Dec 31 16:48:28 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1977779:1","WORKING",false}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:28 ccu rfd: XmlRpc transport error
Dec 31 16:48:28 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1977779:2","BOOT",true}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1977779:2","ENERGY_COUNTER",140786.900000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1977779:2","POWER",0.120000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1977779:2","CURRENT",19.000000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1977779:2","VOLTAGE",239.700000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1977779:2","FREQUENCY",49.970000}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:28 ccu rfd: XmlRpc transport error
Dec 31 16:48:31 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1973823:1","STATE",true}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1973823:1","WORKING",false}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:31 ccu rfd: XmlRpc transport error
Dec 31 16:48:31 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1973823:2","BOOT",true}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1973823:2","ENERGY_COUNTER",9904.200000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1973823:2","POWER",4.290000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1973823:2","CURRENT",72.000000}],[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1973823:2","VOLTAGE",239.900000}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:31 ccu rfd: XmlRpc transport error
Dec 31 16:48:31 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1973823:2","FREQUENCY",49.970000}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:31 ccu rfd: XmlRpc transport error
Dec 31 16:48:32 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1975027:1","STATE",true}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:32 ccu rfd: XmlRpc transport error
Dec 31 16:48:32 ccu rfd: XmlRpcClient error calling event({[methodName:"event",params:{"bb707ce1-8b96-47c1-9e91-458c51a57834","OEQ1975027:1","WORKING",false}]}) on http://172.17.0.1:9125/RPC2:
Dec 31 16:48:32 ccu rfd: XmlRpc transport error
Dec 31 16:48:33 ccu cuxd[655]: use CUX2801001:1.CMD_QUERY_RET=1 to activate CUX2801001:1.CMD_RETS command!
Dec 31 16:48:33 ccu cuxd[655]: use CUX2801001:1.CMD_QUERY_RET=1 to activate CUX2801001:1.CMD_RETS command!
Dec 31 16:48:33 ccu cuxd[655]: use CUX2801001:1.CMD_QUERY_RET=1 to activate CUX2801001:1.CMD_RETS command!
Dec 31 16:48:33 ccu cuxd[655]: use CUX2801001:1.CMD_QUERY_RET=1 to activate CUX2801001:1.CMD_RETS command!

I am at a total loss. I can still control Homematic from OH, but don’t receive changes anymore.

I have created an issue: [homematic] Binding does not get change events anymore from CCU3 · Issue #14126 · openhab/openhab-addons · GitHub

I think I solved it. I saw in the CCU3 log that it wants to connect to 172.17.0.1:9125, but OH runs on 192.168.0.7.

Since the last OH restart, I started the docker daemon and that adds the 172.17.x.x network to the server.

Looks like the homematic binding decided to use this network! Now that I configured the right IP address in the bridge settings, I seem to get events again!