I tried to use the homematic binding with my CCU1 (equipped with newest firmware 1.519), but the initialization process fails.
The last warning in openhab.log says "2016-12-30 12:29:34.759 [WARN ] [ome.core.thing.internal.ThingManager] - Initializing handler for thing ‘homematic:bridge:a01c60b6’ takes more than 5000ms."
Afterwards the CCU1 is not working correctly anymore. I am not able anymore to switch the light on with a RF switch using the CCU1’s web interface. The CCU1 works correctly again, when I stop the openhab instance and restart the CCU.
openhab.log:
2016-12-30 12:29:25.628 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
2016-12-30 12:29:27.237 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2016-12-30 12:29:27.736 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
2016-12-30 12:29:28.206 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2016-12-30 12:29:28.254 [DEBUG] [org.openhab.binding.homematic ] - BundleEvent STARTING - org.openhab.binding.homematic
2016-12-30 12:29:28.255 [DEBUG] [org.openhab.binding.homematic ] - BundleEvent STARTED - org.openhab.binding.homematic
2016-12-30 12:29:28.415 [DEBUG] [org.openhab.binding.homematic ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.ConfigDescriptionProvider, org.openhab.binding.homematic.type.HomematicConfigDescriptionProvider}={component.name=org.openhab.binding.homematic.type.HomematicConfigDescriptionProviderImpl, component.id=153, service.id=275, service.bundleid=188, service.scope=bundle} - org.openhab.binding.homematic
2016-12-30 12:29:28.434 [DEBUG] [org.openhab.binding.homematic ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.UpnpDiscoveryParticipant}={component.name=org.eclipse.smarthome.binding.homematic.discovery.bridge, component.id=154, service.id=276, service.bundleid=188, service.scope=bundle} - org.openhab.binding.homematic
2016-12-30 12:29:29.006 [DEBUG] [org.openhab.binding.homematic ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingTypeProvider, org.openhab.binding.homematic.type.HomematicThingTypeProvider}={component.name=org.openhab.binding.homematic.type.HomematicThingTypeProviderImpl, component.id=155, service.id=278, service.bundleid=188, service.scope=bundle} - org.openhab.binding.homematic
2016-12-30 12:29:29.143 [DEBUG] [org.openhab.binding.homematic ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.type.ChannelTypeProvider, org.openhab.binding.homematic.type.HomematicChannelTypeProvider}={component.name=org.openhab.binding.homematic.type.HomematicChannelTypeProviderImpl, component.id=156, service.id=279, service.bundleid=188, service.scope=bundle} - org.openhab.binding.homematic
2016-12-30 12:29:29.592 [DEBUG] [org.openhab.binding.homematic ] - ServiceEvent REGISTERED - {org.openhab.binding.homematic.type.HomematicTypeGenerator}={component.name=org.openhab.binding.homematic.type.HomematicTypeGenerator, component.id=152, service.id=280, service.bundleid=188, service.scope=bundle} - org.openhab.binding.homematic
2016-12-30 12:29:29.624 [DEBUG] [org.openhab.binding.homematic ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.homematic.handler.HomematicThingHandlerFactory, component.id=151, service.id=281, service.bundleid=188, service.scope=bundle} - org.openhab.binding.homematic
2016-12-30 12:29:29.820 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 172.16.62.1
2016-12-30 12:29:29.823 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.178.26
2016-12-30 12:29:30.233 [DEBUG] [matic.handler.HomematicBridgeHandler] - HomematicConfig[gatewayAddress=192.168.178.31,callbackHost=192.168.219.1,xmlCallbackPort=9125,binCallbackPort=9126,gatewayType=ccu,rfPort=2001,wiredPort=2000,hmIpPort=2010,cuxdPort=8701,aliveInterval=300,reconnectInterval=0,timeout=60,socketMaxAlive=900]
2016-12-30 12:29:30.313 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 2001):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>getDeviceDescription</methodName>
<params><param><value>BidCoS-RF</value></param></params></methodCall>
2016-12-30 12:29:31.114 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcResponse (port 2001):
<?xml version="1.0"?>
<methodResponse><params><param>
<value><struct><member><name>ADDRESS</name><value>BidCoS-RF</value></member><member><name>CHILDREN</name><value><array><data><value>BidCoS-RF:0</value><value>BidCoS-RF:1</value><value>BidCoS-RF:2</value><value>BidCoS-RF:3</value><value>BidCoS-RF:4</value><value>BidCoS-RF:5</value><value>BidCoS-RF:6</value><value>BidCoS-RF:7</value><value>BidCoS-RF:8</value><value>BidCoS-RF:9</value><value>BidCoS-RF:10</value><value>BidCoS-RF:11</value><value>BidCoS-RF:12</value><value>BidCoS-RF:13</value><value>BidCoS-RF:14</value><value>BidCoS-RF:15</value><value>BidCoS-RF:16</value><value>BidCoS-RF:17</value><value>BidCoS-RF:18</value><value>BidCoS-RF:19</value><value>BidCoS-RF:20</value><value>BidCoS-RF:21</value><value>BidCoS-RF:22</value><value>BidCoS-RF:23</value><value>BidCoS-RF:24</value><value>BidCoS-RF:25</value><value>BidCoS-RF:26</value><value>BidCoS-RF:27</value><value>BidCoS-RF:28</value><value>BidCoS-RF:29</value><value>BidCoS-RF:30</value><value>BidCoS-RF:31</value><value>BidCoS-RF:32</value><value>BidCoS-RF:33</value><value>BidCoS-RF:34</value><value>BidCoS-RF:35</value><value>BidCoS-RF:36</value><value>BidCoS-RF:37</value><value>BidCoS-RF:38</value><value>BidCoS-RF:39</value><value>BidCoS-RF:40</value><value>BidCoS-RF:41</value><value>BidCoS-RF:42</value><value>BidCoS-RF:43</value><value>BidCoS-RF:44</value><value>BidCoS-RF:45</value><value>BidCoS-RF:46</value><value>BidCoS-RF:47</value><value>BidCoS-RF:48</value><value>BidCoS-RF:49</value><value>BidCoS-RF:50</value></data></array></value></member><member><name>FIRMWARE</name><value>1.519</value></member><member><name>FLAGS</name><value><i4>9</i4></value></member><member><name>INTERFACE</name><value>HEQ0176501</value></member><member><name>PARAMSETS</name><value><array><data><value>MASTER</value></data></array></value></member><member><name>PARENT</name><value></value></member><member><name>RF_ADDRESS</name><value><i4>1289314</i4></value></member><member><name>ROAMING</name><value><i4>0</i4></value></member><member><name>TYPE</name><value>HM-RCV-50</value></member><member><name>VERSION</name><value><i4>6</i4></value></member></struct></value>
</param></params></methodResponse>
2016-12-30 12:29:31.140 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 2001):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>listBidcosInterfaces</methodName>
<params></params></methodCall>
2016-12-30 12:29:31.182 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcResponse (port 2001):
<?xml version="1.0"?>
<methodResponse><params><param>
<value><array><data><value><struct><member><name>ADDRESS</name><value>HEQ0176501</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></struct></value></data></array></value>
</param></params></methodResponse>
2016-12-30 12:29:31.184 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 2000):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>init</methodName>
<params><param><value>http://openhab.validation:1000</value></param></params></methodCall>
2016-12-30 12:29:31.202 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcResponse (port 2000):
<?xml version="1.0"?>
<methodResponse><params><param>
<value></value>
</param></params></methodResponse>
2016-12-30 12:29:31.204 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 2010):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>init</methodName>
<params><param><value>http://openhab.validation:1000</value></param></params></methodCall>
2016-12-30 12:29:31.225 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'HMIP' on gateway 'a01c60b6' not available, disabling support
2016-12-30 12:29:31.225 [TRACE] [nal.communicator.client.XmlRpcClient] - Client XmlRpcRequest (port 8701):
<?xml version="1.0" encoding="ISO-8859-1"?>
<methodCall><methodName>init</methodName>
<params><param><value>http://openhab.validation:1000</value></param></params></methodCall>
2016-12-30 12:29:31.239 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'CUXD' on gateway 'a01c60b6' not available, disabling support
2016-12-30 12:29:31.309 [DEBUG] [ternal.communicator.HomematicGateway] - Initializing gateway with id 'a01c60b6'
2016-12-30 12:29:31.312 [INFO ] [ternal.communicator.HomematicGateway] - HmGatewayInfo[id=CCU,type=CCU,firmware=1.519,address=HEQ0176501,wired=true,hmip=false,cuxd=false]
2016-12-30 12:29:31.313 [INFO ] [ternal.communicator.HomematicGateway] - Used Homematic transfer modes: RF:BIN_RPC, WIRED:BIN_RPC
2016-12-30 12:29:31.497 [DEBUG] [nal.communicator.server.BinRpcServer] - Initializing BIN-RPC server at port 9126
2016-12-30 12:29:31.510 [TRACE] [nal.communicator.client.BinRpcClient] - Client BinRpcRequest:
init()
binary://192.168.219.1:9126
RF-a01c60b6
2016-12-30 12:29:31.511 [TRACE] [al.communicator.client.SocketHandler] - Creating new socket for port 2001
2016-12-30 12:29:34.759 [WARN ] [ome.core.thing.internal.ThingManager] - Initializing handler for thing 'homematic:bridge:a01c60b6' takes more than 5000ms.
events.log
2016-12-30 12:29:22.742 [ThingAddedEvent ] - Thing 'homematic:bridge:a01c60b6' has been added.
2016-12-30 12:29:29.796 [hingStatusInfoChangedEvent] - 'homematic:bridge:a01c60b6' changed from UNINITIALIZED to INITIALIZING
2016-12-30 12:30:31.599 [hingStatusInfoChangedEvent] - 'homematic:bridge:a01c60b6' changed from INITIALIZING to OFFLINE (COMMUNICATION_ERROR): Read timed out
2016-12-30 12:35:51.537 [hingStatusInfoChangedEvent] - 'homematic:bridge:a01c60b6' changed from OFFLINE (COMMUNICATION_ERROR): Read timed out to OFFLINE (COMMUNICATION_ERROR)
2016-12-30 12:36:01.535 [hingStatusInfoChangedEvent] - 'homematic:bridge:a01c60b6' changed from OFFLINE (COMMUNICATION_ERROR) to OFFLINE (COMMUNICATION_ERROR): java.net.ConnectException: Verbindungsaufbau abgelehnt
Is there an incompability of the homematic binding with the CCU1?