Dear all
I hope that it is okay if I post this inquiry here but I am completely out of ideas and looking for any support I can get.
Please find below my configuration:
Hardware: Raspberry Pi 3 with Busware CUL
OS: Raspbian Buster
Java Runtime Environment:
openjdk version “11.0.16” 2022-07-19
OpenJDK Runtime Environment (build 11.0.16+8-post-Raspbian-1deb10u1)
OpenJDK Server VM (build 11.0.16+8-post-Raspbian-1deb10u1, mixed mode)
OpenHAB: 3.4.0.M4 Milestone Build
Homematic Binding: 3.4.0.M4
Homegear Version: Nightly 0.9.22110315-3600
I’ve been running homegear with approx. 60 Homematic Devices for a few years now without any major issues and now I wanted to give Openhab a try because OpenHAB with Homematic Binding and Homegear seemed a well-established combination to me.
In order not to affect my Homegear installation, I installed Openhab on a second Raspi (IP 192.168.178.35). A firewall is not active on either of the two Raspis and the required ports are not occupied by other programs. In the Homematic Binding I left all configurations at the default values and I only set the gateway address to the IP of the Raspi which is running Homegear.
According to my understanding, all Homematic devices should be automatically recognized by the binding and appear in the OpenHAB inbox as new things.
Unfortunately I ran into the following issue:
The Homematic Binding connects to Homegear and is “Online” in Openhab but no Homematic Devices show up as things in the inbox.
In the Openhab log, I looks like the binding at first connects fine to the Homegear BIN-RPC Server but then I receive the error message “Connection refused”
For double-checking, I installed Openhab again on another computer (Windows laptop) and the behavior is the same here.
> 14:47:32.237 [DEBUG] [ternal.handler.HomematicBridgeHandler] - HomematicConfig[gatewayAddress=raspi-hg,callbackHost=192.168.178.35,xmlCallbackPort=9125,binCallbackPort=9126,gatewayType=auto,rfPort=2001,wiredPort=2000,hmIpPort=2010,cuxdPort=8701,groupPort=9292,timeout=15,discoveryTimeToLive=-1,installModeDuration=60,socketMaxAlive=900]
> 14:47:32.359 [INFO ] [nternal.communicator.client.RpcClient] - Interface 'WIRED' on gateway '61ae080193' not available, disabling support
> 14:47:32.369 [INFO ] [nternal.communicator.client.RpcClient] - Interface 'HMIP' on gateway '61ae080193' not available, disabling support
> 14:47:32.378 [INFO ] [nternal.communicator.client.RpcClient] - Interface 'CUXD' on gateway '61ae080193' not available, disabling support
> 14:47:32.388 [INFO ] [nternal.communicator.client.RpcClient] - Interface 'GROUP' on gateway '61ae080193' not available, disabling support
> 14:47:32.398 [DEBUG] [communicator.AbstractHomematicGateway] - Initializing gateway with id '61ae080193'
> 14:47:32.404 [INFO ] [communicator.AbstractHomematicGateway] - HmGatewayInfo[id=HOMEGEAR,type=Homegear,firmware=0.9.22110315-3600,address=VBC8828257,rf=true,wired=false,hmip=false,cuxd=false,group=false]
> 14:47:32.410 [DEBUG] [communicator.AbstractHomematicGateway] - Used Homematic transfer modes: RF:BIN_RPC
> 14:47:32.417 [DEBUG] [rnal.communicator.server.BinRpcServer] - Initializing BIN-RPC server at port 9126
> 14:47:32.423 [DEBUG] [nternal.communicator.client.RpcClient] - Register callback for interface BidCos-RF
> 14:47:32.436 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Stopping Homematic discovery scan
> 14:47:32.450 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Waiting for finishing Homematic device discovery scan
> 14:47:32.460 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Finished Homematic device discovery scan on gateway '61ae080193'
> 14:47:32.468 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Starting Homematic discovery scan
> 14:47:32.474 [DEBUG] [nternal.communicator.client.RpcClient] - Submitting setInstallMode(on=true, time=60, mode=1)
> 14:47:32.489 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Successfully put controller in install mode. Remaining time: 60 seconds
> 14:47:32.494 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Waiting for finishing Homematic device discovery scan
> 14:47:32.695 [DEBUG] [rnal.communicator.client.BinRpcClient] - BinRpcMessage socket failure, sending message again 1/3
> 14:47:32.705 [DEBUG] [rnal.communicator.client.BinRpcClient] - BinRpcMessage socket failure, sending message again 2/3
> 14:47:32.712 [DEBUG] [rnal.communicator.client.BinRpcClient] - BinRpcMessage socket failure, sending message again 3/3
> 14:47:32.719 [ERROR] [overy.HomematicDeviceDiscoveryService] - Verbindungsaufbau abgelehnt (Connection refused)
> java.net.ConnectException: Verbindungsaufbau abgelehnt (Connection refused)
> at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:?]
> at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:412) ~[?:?]
> at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:255) ~[?:?]
> at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:237) ~[?:?]
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:?]
> at java.net.Socket.connect(Socket.java:609) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.client.SocketHandler.getSocket(SocketHandler.java:50) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:80) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:95) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:95) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:95) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:71) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.client.RpcClient.listDevices(RpcClient.java:211) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.getDeviceDescriptions(AbstractHomematicGateway.java:453) ~[?:?]
> at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.loadAllDeviceMetadata(AbstractHomematicGateway.java:377) ~[?:?]
> at org.openhab.binding.homematic.internal.discovery.HomematicDeviceDiscoveryService.lambda$0(HomematicDeviceDiscoveryService.java:209) ~[?:?]
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
> at java.lang.Thread.run(Thread.java:829) [?:?]
> 14:48:32.467 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Stopping Homematic discovery scan
> 14:48:32.483 [DEBUG] [nternal.communicator.client.RpcClient] - Submitting setInstallMode(on=false, time=0, mode=1)
> 14:48:32.501 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Finished Homematic device discovery scan on gateway '61ae080193'
> 14:48:32.504 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Waiting for finishing Homematic device discovery scan
> 14:48:32.512 [DEBUG] [communicator.AbstractHomematicGateway] - Starting connection tracker for gateway with id '61ae080193'
> 14:48:32.523 [DEBUG] [overy.HomematicDeviceDiscoveryService] - Finished Homematic device discovery scan on gateway '61ae080193'
As the extract from the homegear.log file shows, Openhab apparently connects to Homegear’s Bin-RPC server, but then Homegear restarts.
11/07/22 12:47:28.383 RPC Server (Port 2001): Info: Client number 593 is calling RPC method: init (2) Parameters:
(String) binary://192.168.178.35:9126
11/07/22 12:47:28.383 Info: Client with IP ::ffff:192.168.178.35 is calling "init".
11/07/22 12:47:28.383 Info: Removing server "binary://192.168.178.35".
11/07/22 12:47:28.399 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.178.35:38544 accepted. Client number: 638
11/07/22 12:47:28.400 RPC Server (Port 2001): Info: RPC server client id for client number 638 is: 638
11/07/22 12:47:28.403 RPC Server (Port 2001): Info: Client number 638 is calling RPC method: getDeviceDescription (1) Parameters:
(String) BidCoS-RF
11/07/22 12:47:28.438 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.178.35:38546 accepted. Client number: 639
11/07/22 12:47:28.439 RPC Server (Port 2001): Info: RPC server client id for client number 639 is: 639
11/07/22 12:47:28.443 RPC Server (Port 2001): Info: Client number 639 is calling RPC method: listBidcosInterfaces (1) Parameters:
11/07/22 12:47:28.477 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.178.35:38548 accepted. Client number: 640
11/07/22 12:47:28.477 RPC Server (Port 2001): Info: RPC server client id for client number 640 is: 640
11/07/22 12:47:28.479 RPC Server (Port 2001): Info: Client number 640 is calling RPC method: init (1) Parameters:
(String) http://openhab.validation:1000
11/07/22 12:47:28.479 Info: Client with IP ::ffff:192.168.178.35 is calling "init".
11/07/22 12:47:28.567 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.178.35:38558 accepted. Client number: 641
11/07/22 12:47:28.567 RPC Server (Port 2001): Info: RPC server client id for client number 641 is: 641
11/07/22 12:47:28.568 RPC Server (Port 2001): Info: Client number 641 is calling RPC method: init (2) Parameters:
(String) binary://192.168.178.35:9126
(String) 66aa9bc4-f311-46cc-b255-37ae06cadc3d
(Integer) 34
11/07/22 12:47:28.568 Info: Client with IP ::ffff:192.168.178.35 is calling "init".
11/07/22 12:47:28.569 Info: Adding server "binary://192.168.178.35".
11/07/22 12:47:28.569 Info: Calling init methods on server "binary://192.168.178.35".
11/07/22 12:47:28.577 RPC Server (Port 2001): Info: Connection from ::ffff:192.168.178.35:38560 accepted. Client number: 642
11/07/22 12:47:28.577 RPC Server (Port 2001): Info: RPC server client id for client number 642 is: 642
11/07/22 12:47:28.578 RPC Server (Port 2001): Info: Client number 642 is calling RPC method: setInstallMode (2) Parameters:
(Boolean) 1
(Integer) 60
(Integer) 1
11/07/22 12:47:28.578 Module HomeMatic BidCoS: Info: Pairing mode enabled.
11/07/22 12:47:28.581 RPC Server (Port 2001): Info: Client number 642 is calling RPC method: getInstallMode (2) Parameters:
11/07/22 12:47:28.594 RPC Server (Port 2001): Info: Client number 642 is calling RPC method: listDevices (2) Parameters:
11/07/22 12:47:28.745 Module HomeMatic BidCoS: CUL "My-CUL": Info: Ignoring too small packet: A06354FEBBF8ADCE7
11/07/22 12:47:30.252 Starting Homegear...
The Homegear restart also occurs everytime, when I click SAVE in the Homematic Binding in the Openhab GUI.
Does anybody have an idea what might cause this strange behavior?
Please let me know if you need more details, then I will update the post accordingly.
Thanks
Cheers
FiveEights