[SOLVED] Homematic Binding: No pong received

Add-ons Bindings
1

I just noticed that openHAB is not receiving any updates from homematic ccu2 anymore. Enable TRACE on the binding and looking into the logs, I am seeing this:

08:57:50.047 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 2001):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>init</methodName>
<params><param><value>http://10.0.0.3:9125</value></param></params></methodCall>
08:57:50.052 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcResponse (port 2001):
<?xml version="1.0" encoding="iso-8859-1"?>
<methodResponse><params><param>
    <value></value>
</param></params></methodResponse>

08:57:50.053 [DEBUG] [nal.communicator.server.XmlRpcServer] - Stopping XML-RPC server
08:57:50.056 [DEBUG] [nal.communicator.server.XmlRpcServer] - Initializing XML-RPC server at port 9125
Server@6e801301{STARTED}[9.4.20.v20190813] - STARTED
+= QueuedThreadPool[qtp2001399832]@774af018{STARTED,8<=8<=200,i=5,r=4,q=0}[ReservedThreadExecutor@13d109e7{s=0/4,p=0}] - STARTED
|  += ReservedThreadExecutor@13d109e7{s=0/4,p=0} - STARTED
|  +> threads size=8
|     +> 934 qtp2001399832-934 IDLE TIMED_WAITING @ sun.misc.Unsafe.park(Native Method)
|     +> 930 qtp2001399832-930 SELECTING RUNNABLE @ sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
|     +> 932 qtp2001399832-932 SELECTING RUNNABLE @ sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
|     +> 933 qtp2001399832-933 IDLE TIMED_WAITING @ sun.misc.Unsafe.park(Native Method)
|     +> 936 qtp2001399832-936 IDLE TIMED_WAITING @ sun.misc.Unsafe.park(Native Method)
|     +> 931 qtp2001399832-931-acceptor-0@1c3e08aa-ServerConnector@31522bbf{HTTP/1.1,[http/1.1]}{macko:9125} ACCEPTING RUNNABLE @ sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) prio=3
|     +> 935 qtp2001399832-935 IDLE TIMED_WAITING @ sun.misc.Unsafe.park(Native Method)
|     +> 937 qtp2001399832-937 IDLE TIMED_WAITING @ sun.misc.Unsafe.park(Native Method)
+= ServerConnector@31522bbf{HTTP/1.1,[http/1.1]}{macko:9125} - STARTED
|  +~ Server@6e801301{STARTED}[9.4.20.v20190813] - STARTED
|  +~ QueuedThreadPool[qtp2001399832]@774af018{STARTED,8<=8<=200,i=5,r=4,q=0}[ReservedThreadExecutor@13d109e7{s=0/4,p=0}] - STARTED
|  += ScheduledExecutorScheduler@4bc115ed{STARTED} - STARTED
|  +- org.eclipse.jetty.io.ArrayByteBufferPool@1c00127
|  += HttpConnectionFactory@292ede[HTTP/1.1] - STARTED
|  |  +- HttpConfiguration@39eea039{32768/8192,8192/8192,https://:0,[]}
|  |     +> customizers size=0
|  |     +> formEncodedMethods size=2
|  |     |  +> POST
|  |     |  +> PUT
|  |     +> outputBufferSize=32768
|  |     +> outputAggregationSize=8192
|  |     +> requestHeaderSize=8192
|  |     +> responseHeaderSize=8192
|  |     +> headerCacheSize=4096
|  |     +> secureScheme=https
|  |     +> securePort=0
|  |     +> idleTimeout=-1
|  |     +> blockingTimeout=-1
|  |     +> sendDateHeader=true
|  |     +> sendServerVersion=true
|  |     +> sendXPoweredBy=false
|  |     +> delayDispatchUntilContent=true
|  |     +> persistentConnectionsEnabled=true
|  |     +> maxErrorDispatches=10
|  |     +> minRequestDataRate=0
|  |     +> minResponseDataRate=0
|  |     +> cookieCompliance=RFC6265
|  |     +> setRequestCookieCompliance=RFC6265
|  |     +> notifyRemoteAsyncErrors=true
|  += SelectorManager@ServerConnector@31522bbf{HTTP/1.1,[http/1.1]}{macko:9125} - STARTED
|  |  += ManagedSelector@226b08d2{STARTED} id=0 keys=0 selected=0 updates=0 - STARTED
|  |  |  += EatWhatYouKill@61c61f0f/SelectorProducer@608ef329/PRODUCING/p=false/QueuedThreadPool[qtp2001399832]@774af018{STARTED,8<=8<=200,i=5,r=4,q=0}[ReservedThreadExecutor@13d109e7{s=0/4,p=0}][pc=0,pic=0,pec=0,epc=0]@2020-01-08T08:57:50.072+01:00 - STARTED
|  |  |  |  +- SelectorProducer@608ef329
|  |  |  |  +~ QueuedThreadPool[qtp2001399832]@774af018{STARTED,8<=8<=200,i=5,r=4,q=0}[ReservedThreadExecutor@13d109e7{s=0/4,p=0}] - STARTED
|  |  |  +> updates @ 2020-01-08T08:57:50.07+01:00 size=0
|  |  |  +> keys @ 2020-01-08T08:57:50.071+01:00 size=0
|  |  += ManagedSelector@2c2d7869{STARTED} id=1 keys=0 selected=0 updates=0 - STARTED
|  |     += EatWhatYouKill@567ac8a6/SelectorProducer@7959b01/PRODUCING/p=false/QueuedThreadPool[qtp2001399832]@774af018{STARTED,8<=8<=200,i=5,r=4,q=0}[ReservedThreadExecutor@13d109e7{s=0/4,p=0}][pc=0,pic=0,pec=0,epc=0]@2020-01-08T08:57:50.073+01:00 - STARTED
|  |     |  +- SelectorProducer@7959b01
|  |     |  +~ QueuedThreadPool[qtp2001399832]@774af018{STARTED,8<=8<=200,i=5,r=4,q=0}[ReservedThreadExecutor@13d109e7{s=0/4,p=0}] - STARTED
|  |     +> updates @ 2020-01-08T08:57:50.072+01:00 size=0
|  |     +> keys @ 2020-01-08T08:57:50.072+01:00 size=0
|  +- sun.nio.ch.ServerSocketChannelImpl[/172.16.100.1:9125]
|  +- qtp2001399832-931-acceptor-0@1c3e08aa-ServerConnector@31522bbf{HTTP/1.1,[http/1.1]}{macko:9125}
+= ResponseHandler@10952761{STARTED} - STARTED
+= ErrorHandler@573ceb2a{STARTED} - STARTED
+> org.eclipse.osgi.internal.loader.EquinoxClassLoader@400d5d3b[org.eclipse.jetty.server:9.4.20.v20190813(id=90)]
   +> java.net.URLClassLoader@41629346
  +> URLs size=2
  |  +> file:/openhab/runtime/system/org/eclipse/platform/org.eclipse.osgi/3.12.100/org.eclipse.osgi-3.12.100.jar
  |  +> file:/openhab/userdata/cache/org.eclipse.osgi/1/0/bundleFile
  +> sun.misc.Launcher$AppClassLoader@3d4eac69
     +> URLs size=5
     |  +> file:/openhab/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.2.7.jar
     |  +> file:/openhab/runtime/lib/boot/org.apache.karaf.jaas.boot-4.2.7.jar
     |  +> file:/openhab/runtime/lib/boot/org.apache.karaf.main-4.2.7.jar
     |  +> file:/openhab/runtime/lib/boot/org.apache.karaf.specs.activator-4.2.7.jar
     |  +> file:/openhab/runtime/lib/boot/osgi.core-6.0.0.jar
     +> sun.misc.Launcher$ExtClassLoader@506ef1b
        +> URLs size=11
           +> file:/usr/lib/java-8/jre/lib/ext/cldrdata.jar
           +> file:/usr/lib/java-8/jre/lib/ext/dnsns.jar
           +> file:/usr/lib/java-8/jre/lib/ext/jaccess.jar
           +> file:/usr/lib/java-8/jre/lib/ext/localedata.jar
           +> file:/usr/lib/java-8/jre/lib/ext/nashorn.jar
           +> file:/usr/lib/java-8/jre/lib/ext/openjsse.jar
           +> file:/usr/lib/java-8/jre/lib/ext/sunec.jar
           +> file:/usr/lib/java-8/jre/lib/ext/sunjce_provider.jar
           +> file:/usr/lib/java-8/jre/lib/ext/sunpkcs11.jar
           +> file:/usr/lib/java-8/jre/lib/ext/zipfs.jar
           +> file:/openhab/runtime/lib/ext/README
key: +- bean, += managed, +~ unmanaged, +? auto, +: iterable, +] array, +@ map, +> undefined
08:57:50.074 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 2001):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>init</methodName>
<params><param><value>http://10.0.0.3:9125</value></param><param><value>RF-LEQ0245826</value></param></params></methodCall>
08:57:50.081 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcResponse (port 2001):
<?xml version="1.0" encoding="iso-8859-1"?>
<methodResponse><params><param>
    <value></value>
</param></params></methodResponse>

08:57:50.082 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 2001):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>ping</methodName>
<params><param><value>LEQ0245826</value></param></params></methodCall>
08:57:50.095 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcResponse (port 2001):
<?xml version="1.0" encoding="iso-8859-1"?>
<methodResponse><params><param>
    <value><array><data><value><boolean>1</boolean></value></data></array></value>
</param></params></methodResponse>

08:57:50.096 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 2001):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>listBidcosInterfaces</methodName>
<params></params></methodCall>
08:57:50.104 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcResponse (port 2001):
<?xml version="1.0" encoding="iso-8859-1"?>
<methodResponse><params><param>
    <value><array><data><value><struct><member><name>ADDRESS</name><value>LEQ0245826</value></member><member><name>CONNECTED</name><value><boolean>1</boolean></value></member><member><name>DEFAULT</name><value><boolean>1</boolean></value></member><member><name>DESCRIPTION</name><value></value></member><member><name>DUTY_CYCLE</name><value><i4>2</i4></value></member><member><name>FIRMWARE_VERSION</name><value>2.8.6</value></member><member><name>TYPE</name><value>CCU2</value></member></struct></value></data></array></value>
</param></params></methodResponse>

This block of log messages repeats over and over. There are two lines that make me think it constantly restarts the XmlRpcServer:

09:00:20.756 [DEBUG] [nal.communicator.server.XmlRpcServer] - Stopping XML-RPC server
09:00:20.759 [DEBUG] [nal.communicator.server.XmlRpcServer] - Initializing XML-RPC server at port 9125

This is my thing config for the ccu2:

Bridge homematic:bridge:LEQ0245826 [ gatewayAddress="10.0.0.4", callbackHost="10.0.0.3", xmlCallbackPort="9125", binCallbackPort="9126" ]

Any suggestions?

2

Try stopping OH, cleaning the cache then reboot.

1 Like
3

That helped, thanks!

4

Glad to assist. Please click the square box on the post that provided the solution to mark the topic solved.

Thanks