[solved] Homematic no pong / OFFLINE - BRIDGE_OFFLINE after update to 2.5M1

Hey all,
After upgrading my setup from 2.3 to 2.5M1 my homematic connection to my good old CCU2 is bad. This is what my log sais:

2019-04-19 00:01:19.419 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'homematic.things'
2019-04-19 00:01:20.832 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'WIRED' on gateway 'ccu2' not available, disabling support
2019-04-19 00:01:21.000 [INFO ] [ommunicator.AbstractHomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=2.45.6,address=LEQ0246XXX,rf=true,wired=false,hmip=true,cuxd=true,group=true]
2019-04-19 00:01:53.353 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name 'Garagentor schalter aus' contains invalid characters, new Datapoint name 'Garagentor_schalter_aus'
2019-04-19 00:01:53.356 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name 'System - Servicemeldungen Kommunikation prĂĽfen' contains invalid characters, new Datapoint name 'System_-_Servicemeldungen_Kommunikation_pr_fen'
2019-04-19 00:01:53.358 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name 'System Servicemeldungen bestäigen' contains invalid characters, new Datapoint name 'System_Servicemeldungen_best_igen'
2019-04-19 00:01:53.367 [INFO ] [rnal.type.HomematicTypeGeneratorImpl] - Multiple firmware versions for device type 'HM-Sec-SC-2' found (2.2, 2.4). Make sure, all devices of the same type have the same firmware version, otherwise you MAY have channel and/or datapoint errors in the logfile
2019-04-19 00:01:53.369 [INFO ] [rnal.type.HomematicTypeGeneratorImpl] - Multiple firmware versions for device type 'HmIP-SRH' found (1.2.10, 1.0.2). Make sure, all devices of the same type have the same firmware version, otherwise you MAY have channel and/or datapoint errors in the logfile
2019-04-19 00:01:53.492 [WARN ] [matic.handler.HomematicBridgeHandler] - Unable to load RSSI values from bridge 'ccu2'
2019-04-19 00:01:53.493 [ERROR] [matic.handler.HomematicBridgeHandler] - -1 rssiInfo: unknown.method name (sending rssiInfo()
)
java.io.IOException: -1 rssiInfo: unknown.method name (sending rssiInfo()
)
        at org.eclipse.smarthome.binding.homematic.internal.communicator.parser.RpcResponseParser.parse(RpcResponseParser.java:51) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:82) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:94) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:70) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.client.RpcClient.loadRssiInfo(RpcClient.java:448) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.AbstractHomematicGateway.loadRssiValues(AbstractHomematicGateway.java:534) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.handler.HomematicBridgeHandler.initializeInternal(HomematicBridgeHandler.java:118) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-04-19 00:02:38.535 [WARN ] [ommunicator.AbstractHomematicGateway] - Connection lost on gateway 'ccu2', cause: "No Pong received!"

Paper UI sais about my 50 things they are in state OFFLINE - BRIDGE_OFFLINE
As you can see from the log, I’m running the most recent CCU2 firmware. I also checked that firewall config is in place and ports are opened. The only thing I havent found is the Authentication thing. The Security page does not contain any Authentication nor SNMP entries as you can see from the screenshot.

As soon as I change the things file, the CCU comes online with its devices. But a minute later all are gone again and “no pong” is logged. Even though I can send commands to my rollershutters and lights which are executed properly, I cannot receive data from the temparature or lux sensors.
Anyone an idea how to get it working again? Or what to look for in more detail?
Thanks much for your help.
Best Seb

what about these settings:

Thanks for your feedback @lukics,
This is how mine looks right now.

Seems like I cannot set the Mediola-Zugriff. As soon as I set it to “full access” the setting reverts to “limited access” on its own.

I just ramped up my test system (docker) with M1 milestone build with following configuration:

raspberymatic:

openhab:

HomeMatic stable connected for last 15 minutes.

1 Like

Thanks @lukics for your efforts to replicate my issue. Appreciate your help on this.
The only difference I can see is that your raspberrymatic replicates a CCU3 and I have a CCU2.

Then I have login password set. Would you mind checking on CCU3 > Controlpanel > Security and check for an “Authentication” check-box. Is that ticked or not?

And last but not least, I’m not able to set “Mediola access” to “full access”. When I try to set it and save, its automatically reverted to “restricted access”

In one of the facebook groups I’m discussing similar topic and some said, that “Authentication” might only be available on CCU3, but not the good old CCU2. So I’m wondering how to configure CCU2 with most recent firmware.

Since I can control the blinds as well as the the lights, some connection must be ok, even the things pretend to be offline.
Only the devices just sending data (temps, lux, window sensors, etc) cant be polled by OH. in CCU2 they work just fine. So I think its a communication problem between OH2 and CCU2.
Thanks for your help.

Edit:
I removed my manually configured things file for homematic. and gave the auto-detection a shot. After manually adding the bridge thing, all my homematic things were synced from the CCU2 and added to the inbox. I confirmed a handful devices in order to start testing.
After appx. 2 mins they all went offline with this error message:

image

And logfile again confirmed:

2019-04-20 16:50:47.113 [WARN ] [matic.handler.HomematicBridgeHandler] - Unable to load RSSI values from bridge '589fd53c'
2019-04-20 16:50:47.113 [ERROR] [matic.handler.HomematicBridgeHandler] - -1 rssiInfo: unknown.method name (sending rssiInfo()
)
java.io.IOException: -1 rssiInfo: unknown.method name (sending rssiInfo()
)
        at org.eclipse.smarthome.binding.homematic.internal.communicator.parser.RpcResponseParser.parse(RpcResponseParser.java:51) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:82) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:94) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:70) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.client.RpcClient.loadRssiInfo(RpcClient.java:448) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.AbstractHomematicGateway.loadRssiValues(AbstractHomematicGateway.java:534) ~[?:?]
        at org.eclipse.smarthome.binding.homematic.handler.HomematicBridgeHandler.initializeInternal(HomematicBridgeHandler.java:118) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-04-20 16:51:32.162 [WARN ] [ommunicator.AbstractHomematicGateway] - Connection lost on gateway '589fd53c', cause: "No Pong received!"

So I think its definitily a connection issue between OH2 and CCU2. And I guess its the new firewall or authentication feature on the good old CCU2.
Possibly @gerrieg or @MHerbst have an idea or hint on how to troubleshoot further?
Thanks much for your help guys.

I have added Authentication and my HomeMatic Bridge goes offline too, removing it, the bridge comes online
Since my CCU in in the lan with no ports exposed I always run without authentication.

Hi @waitz_sebastian

in the meantime I have also switched from a CCU2 to raspberrymatic. I am also using openHAB 2.4 because this is the current stable version. Can you try to test it with this version?

What about firewall settings on the machine where openHAB is running. Maybe the firewall blocks the “pong”.

Hey @MHerbst,
thanks for commenting. The local firewall where OH2 is running (Debian based NUC) is disabled. I moved to 2.4 release first and tested, but since z-wave got some decent updates since release of 2.4 already I descided to move on to 2.5M1 .
The behavior for Homematic was the same in both setups.

What I did yesterday, was resetting the CCU2 to factory defaults. And I started adding everything from scratch.
After adding the first 3 devices, I added the conection to OH, and still the same behavior as before. SO even on a fresh CCU2 without much tweaks, this issue persists. Here are my most recent CCU2 settings and log from OH2:

image


Still no “authentication” section

2019-04-23 08:01:43.627 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'homematic.things'
2019-04-23 08:01:44.133 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'WIRED' on gateway 'ccu2' not available, disabling support
2019-04-23 08:01:44.192 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'CUXD' on gateway 'ccu2' not available, disabling support
2019-04-23 08:01:44.398 [INFO ] [ommunicator.AbstractHomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=2.45.6,address=LEQ0246XXX,rf=true,wired=false,hmip=true,cuxd=false,group=true]
2019-04-23 08:02:00.057 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'homematic:HmIP-RCV-50:ccu2:000352298D292B' to inbox.
2019-04-23 08:02:00.081 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name '${sysVarAlarmZone1}' contains invalid characters, new Datapoint name '__sysVarAlarmZone1_'
2019-04-23 08:02:00.085 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name '${sysVarPresence}' contains invalid characters, new Datapoint name '__sysVarPresence_'
2019-04-23 08:02:00.295 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'homematic:GATEWAY-EXTRAS-CCU2:ccu2:GWE00000000' to inbox.
2019-04-23 08:02:45.412 [WARN ] [ommunicator.AbstractHomematicGateway] - Connection lost on gateway 'ccu2', cause: "No Pong received!"

Martin, I guess your rasperrymatic is also replicating a CCU3, right? Is authenitcation turned on of off on security tab in control planel?

Lukics was able to confirm, it doesnt work as long as authentication is enabled. Since CCU2 doesnt seem to have the option to disable auth, my setup is skrewed.
Any ideas welcome!
Thanks much

Yes, Raspberrymatic is based on the CCU3 firmware without the Mediola stuff (maybe this causes now the problem).

Here you can see my security settings

In your screenshot I can see that you have added an IP address from a different subnet. Are the CCU and openHAB using different networks? In this case it could be a routing problem.

The additional subnet was a recommendation I found in some HASS documentation. CCU2 and OH2 are on the same subnet.
I ordered RPI-RF-MOD which should arrive today. Will give it a try with rasperrymatic and simulating CCU3.

To analyze the issue on CCU2 deeper would be checking source code, when “no pong” received is logged. I still guess, its an undocumented port or something that needs to be opened.
Or even worse, the CCU2 firmware does not offer “disabling authentication” which is needed by the binding. Alternativly a binding using authentication would be an option as well.

Anyway, I will focus on the rasperrymatic migration for now.

I have replaced my CCU2 by a Raspi with Raspberrymatic some months ago. Since then it is running without any problems. And the performance is much better then on the CCU2.

Now I’m really puzzled. Migrated to recent version of rasperrymatic and added the rollershutters. On Raspi everything is working quite fine.
BUT, OH2 still cannot connect. no matter if configured by things file or auto-detected. First everything is found and added to inbox, but few seconds later I have “no pong received” again.
Since its not CCU2 or rasperrymatic, must be my local system. Only changed was the update of OH2 and some OS packages.
I also confirmed once more that iptables is off.
Its really wired…

Edit:
I moved IP of rasperrymatic to different IP address. Exactly same behavior. Auto-discover finds the new CCU3-thing. once added it finds all the things and adds them to inbox. After about 2 mins I receive “no pong received” and CCU goes offline.
I can properly telnet all ports on rasperrymatic side. And since initial connection is working fine, I dought its a network or firewall issue.

Hmm, still investigating. Found the pong error message in source code: Link, but hat to admit that I’m not so dev centric to get an idea why the error is spit here and whats wrong then.

I also ran a TRACE log which did not reveal any new information. Here it is:

 2019-04-25 14:46:01.519 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'homematic:bridge:3014F711A0001F58A9A71XXX' to inbox.
 2019-04-25 14:46:09.941 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'WIRED' on gateway '3014F711A0001F58A9A71XXX' not available, disabling support
 2019-04-25 14:46:10.003 [INFO ] [ommunicator.AbstractHomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=3.45.5.20190330,address=PEQ1947XXX,rf=true,wired=false,hmip=true,cuxd=true,group=true]
 2019-04-25 14:46:20.539 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'homematic:HM-LC-Bl1PBU-FM:3014F711A0001F58A9A71XXX:LEQ0276XXX' to inbox.

... adding 29 more things to inbox...

 2019-04-25 14:46:22.907 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'homematic:HmIP-SRH:3014F711A0001F58A9A7XXX:0007D8A99FCXXX' to inbox.
 2019-04-25 14:46:22.920 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name '${sysVarAlarmZone1}' contains invalid characters, new Datapoint name '__sysVarAlarmZone1_'
 2019-04-25 14:46:22.921 [INFO ] [ng.homematic.internal.misc.MiscUtils] - Datapoint name '${sysVarPresence}' contains invalid characters, new Datapoint name '__sysVarPresence_'
 2019-04-25 14:46:23.069 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'homematic:GATEWAY-EXTRAS-3014F711A0001F58A9A71XXX:3014F711A0001F58A9A71XXX:GWE00000000' to inbox.
 2019-04-25 14:46:23.110 [WARN ] [matic.handler.HomematicBridgeHandler] - Unable to load RSSI values from bridge '3014F711A0001F58A9A71XXX'
 2019-04-25 14:46:23.110 [ERROR] [matic.handler.HomematicBridgeHandler] - -1 rssiInfo: unknown.method name (sending rssiInfo()
 )
 java.io.IOException: -1 rssiInfo: unknown.method name (sending rssiInfo()
 )
     at org.eclipse.smarthome.binding.homematic.internal.communicator.parser.RpcResponseParser.parse(RpcResponseParser.java:51) ~[?:?]
     at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:82) ~[?:?]
     at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:94) ~[?:?]
     at org.eclipse.smarthome.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:70) ~[?:?]
     at org.eclipse.smarthome.binding.homematic.internal.communicator.client.RpcClient.loadRssiInfo(RpcClient.java:448) ~[?:?]
     at org.eclipse.smarthome.binding.homematic.internal.communicator.AbstractHomematicGateway.loadRssiValues(AbstractHomematicGateway.java:534) ~[?:?]
     at org.eclipse.smarthome.binding.homematic.handler.HomematicBridgeHandler.initializeInternal(HomematicBridgeHandler.java:118) ~[?:?]
     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
     at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
     at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
     at java.lang.Thread.run(Thread.java:748) [?:?]
 2019-04-25 14:47:08.141 [WARN ] [ommunicator.AbstractHomematicGateway] - Connection lost on gateway '3014F711A0001F58A9A71XXX', cause: "No Pong received!"

On the other hand, I can control my blinds perfectly fine through basic UI, even though PaperUI confirms for the rollershutter things to be in state “OFFLINE - BRIDGE_OFFLINE”.
Only the devices that send data like windows sensors or temp sensors just dont send values. Or better said, PH2 does not receive them.

Any troubleshooting idea is appreciated.
Thanks

I also asked Gerhard offline for some help and he pushed me to the right direction. In fact it is important that CCU/RasperryMatic can connect on 2 ports back to OH2 server. By default these are 9125 & 9126 as per docu

So I ssh’ed into CCU and tested connecting back to OH2 server using telnet. I was able to connect on 9126 but NOT on 9125. Thus I checked OH server whats wrong on this port.
Using netstat command:

root@nuc:/var/log# netstat -tulpn |grep 91
tcp6       0      0 127.0.1.1:9125          :::*                    LISTEN      495/java
tcp6       0      0 192.168.23.16:9126      :::*                    LISTEN      495/java
udp6       0      0 :::34917                :::*                                495/java

I saw that port 9125 was only listening to debian called local_hostname and not the real IP. So I checked why.
/etc/hostname gives you the real hostname and in /etc/hosts you can check which IP is mapped to this name.
And indeed, there were 2 lines using the hostname. One mapping to 172.0.1.1 and the other mapping to the real OS IP. I commented out the 127.0.1.1 line and restared Homematic binding. And tada:

root@nuc:/var/log# netstat -tulpn |grep 91
tcp6       0      0 192.168.23.16:9125      :::*                    LISTEN      495/java
tcp6       0      0 192.168.23.16:9126      :::*                    LISTEN      495/java
udp6       0      0 :::34917                :::*                                495/java

OH is now listening on the real IP and immediatly the Homematic binding went online again. And most important: It remains online.
Thanks everyone for supporting me in giving troubleshooting ideas! really appreciate your help.
Thanks