[homematic] Improve (re)connect handling to Homematic gateways (openh…

…ab#11429) * Use globally unique id for registration of callback to allow ... the connection of multiple OH installations with one CCU. The bridge id is not sufficient for this purpose because it is same in all OH installations. Signed-off-by: Martin Herbst <develop@mherbst.de> * Retry callback re-registration after connection is resumed Some services on the CCU need longer to start and are not available immediately after the connection to the CCU has been resumed. Improves the solution for openhab#8808 Fixes openhab#10439 Signed-off-by: Martin Herbst <develop@mherbst.de> * Description was missing. Signed-off-by: Martin Herbst <develop@mherbst.de> * Changed setting name and description to avoid confusion Signed-off-by: Martin Herbst <develop@mherbst.de> * Added a troubleshooting tip to solve a communication problem Signed-off-by: Martin Herbst <develop@mherbst.de> * Shortened the label name to follow the guide lines Signed-off-by: Martin Herbst <develop@mherbst.de> * Print more information about the reason for the failure Signed-off-by: Martin Herbst <develop@mherbst.de> * Using scheduler thread pool and simplified configuration Instead of configuring separate values for retry delays and number of retries only the maximum time for retries can be configured. The init method uses fixed delays. Signed-off-by: Martin Herbst <develop@mherbst.de> * Don't retry to send if gateway does not answer at all Signed-off-by: Martin Herbst <develop@mherbst.de> * Improved reconnect handling - unregister callback not necessary if connection is lost - wait 30s until clients and servers are restarted to give the gateway some time to recover Signed-off-by: Martin Herbst <develop@mherbst.de> * Spotless Signed-off-by: Martin Herbst <develop@mherbst.de> * Cancel an active future if the binding is stopped Signed-off-by: Martin Herbst <develop@mherbst.de> Signed-off-by: Nick Waterton <n.waterton@outlook.com>
NickWaterton · Dec 30, 2021 · 2a8e3e0 · 2a8e3e0
1 parent b2a28a7
commit 2a8e3e0
Show file tree

Hide file tree

Showing 8 changed files with 134 additions and 31 deletions.
diff --git a/bundles/org.openhab.binding.homematic/README.md b/bundles/org.openhab.binding.homematic/README.md
@@ -157,6 +157,13 @@ The port number of the HMIP server (default = 2010)
 - **cuxdPort**
 The port number of the CUxD daemon (default = 8701)
 
+- **groupPort**
+The port number of the Group daemon (default = 9292)
+
+- **callbackRegTimeout**
+Maximum time in seconds for callback registration in the Homematic gateway (default = 120s).
+For a CCU2, the value may need to be increased to 180s.
+
 - **installModeDuration**
 Time in seconds that the controller will be in install mode when a device discovery is initiated (default = 60)
 
@@ -676,6 +683,13 @@ Examples: HmIP-BROLL, HmIP-FROLL, HmIP-BBL, HmIP-FBL and HmIP-DRBLI4
 | openHAB | 0%   | 100%   |
 | CCU     | 100% | 0%     |
 
+** The binding does not receive any status changes from the Homematic gateway**
+
+First of all, make sure that none of the ports needed to receive status changes from the gateway are blocked by firewall settings.
+
+If the computer running openHAB has more than one IP address, a wrong one may have been set as receiver for status changes.
+In this case change the setting for `callbackHost` to the correct address.
+
 ### Debugging and Tracing
 
 If you want to see what's going on in the binding, switch the log level to DEBUG in the Karaf console

diff --git a/...matic/src/main/java/org/openhab/binding/homematic/internal/HomematicBindingConstants.java b/...matic/src/main/java/org/openhab/binding/homematic/internal/HomematicBindingConstants.java
@@ -24,6 +24,7 @@
 public class HomematicBindingConstants {
 
     public static final String BINDING_ID = "homematic";
+    public static final String GATEWAY_POOL_NAME = "homematicGateway";
     public static final ThingTypeUID THING_TYPE_BRIDGE = new ThingTypeUID(BINDING_ID, "bridge");
     public static final String CONFIG_DESCRIPTION_URI_CHANNEL = "channel-type:homematic:config";
 

diff --git a/...omematic/src/main/java/org/openhab/binding/homematic/internal/common/HomematicConfig.java b/...omematic/src/main/java/org/openhab/binding/homematic/internal/common/HomematicConfig.java
@@ -58,6 +58,8 @@ public class HomematicConfig {
     private int bufferSize = 2048;
 
     private HmGatewayInfo gatewayInfo;
+    private int callbackRegistrationRetries;
+    private int callbackRegTimeout;
 
     /**
      * Returns the Homematic gateway address.
@@ -115,6 +117,20 @@ public void setBinCallbackPort(int binCallbackPort) {
         this.binCallbackPort = binCallbackPort;
     }
 
+    /**
+     * Sets timeout for callback registration.
+     */
+    public void setCallbackRegTimeout(int timeout) {
+        this.callbackRegTimeout = timeout;
+    }
+
+    /**
+     * Returns timeout for callback registrations.
+     */
+    public int getCallbackRegTimeout() {
+        return callbackRegTimeout;
+    }
+
     /**
      * Returns the HmGatewayInfo.
      */

diff --git a/...in/java/org/openhab/binding/homematic/internal/communicator/AbstractHomematicGateway.java b/...in/java/org/openhab/binding/homematic/internal/communicator/AbstractHomematicGateway.java
@@ -12,6 +12,7 @@
  */
 package org.openhab.binding.homematic.internal.communicator;
 
+import static org.openhab.binding.homematic.internal.HomematicBindingConstants.*;
 import static org.openhab.binding.homematic.internal.misc.HomematicConstants.*;
 
 import java.io.IOException;
@@ -87,8 +88,8 @@
 public abstract class AbstractHomematicGateway implements RpcEventListener, HomematicGateway, VirtualGateway {
     private final Logger logger = LoggerFactory.getLogger(AbstractHomematicGateway.class);
     public static final double DEFAULT_DISABLE_DELAY = 2.0;
+    private static final long RESTART_DELAY = 30;
     private static final long CONNECTION_TRACKER_INTERVAL_SECONDS = 15;
-    private static final String GATEWAY_POOL_NAME = "homematicGateway";
 
     private final Map<TransferMode, RpcClient<?>> rpcClients = new HashMap<>();
     private final Map<TransferMode, RpcServer> rpcServers = new HashMap<>();
@@ -189,6 +190,7 @@ public void initialize() throws IOException {
         logger.debug("Used Homematic transfer modes: {}", sb.toString());
         startClients();
         startServers();
+        registerCallbacks();
 
         if (!config.getGatewayInfo().isHomegear()) {
             // delay the newDevice event handling at startup, reduces some API calls
@@ -211,7 +213,7 @@ public void dispose() {
         stopWatchdogs();
         sendDelayedExecutor.stop();
         receiveDelayedExecutor.stop();
-        stopServers();
+        stopServers(true);
         stopClients();
         devices.clear();
         echoEvents.clear();
@@ -253,25 +255,29 @@ private synchronized void startServers() throws IOException {
                 rpcServer.start();
             }
         }
+    }
+
+    private void registerCallbacks() throws IOException {
         for (HmInterface hmInterface : availableInterfaces.keySet()) {
-            getRpcClient(hmInterface).init(hmInterface, hmInterface.toString() + "-" + id);
+            getRpcClient(hmInterface).init(hmInterface);
         }
     }
 
     /**
      * Stops the Homematic RPC server.
      */
-    private synchronized void stopServers() {
-        for (HmInterface hmInterface : availableInterfaces.keySet()) {
-            try {
-                getRpcClient(hmInterface).release(hmInterface);
-            } catch (IOException ex) {
-                // recoverable exception, therefore only debug
-                logger.debug("Unable to release the connection to the gateway with id '{}': {}", id, ex.getMessage(),
-                        ex);
+    private synchronized void stopServers(boolean releaseConnection) {
+        if (releaseConnection) {
+            for (HmInterface hmInterface : availableInterfaces.keySet()) {
+                try {
+                    getRpcClient(hmInterface).release(hmInterface);
+                } catch (IOException ex) {
+                    // recoverable exception, therefore only debug
+                    logger.debug("Unable to release the connection to the gateway with id '{}': {}", id,
+                            ex.getMessage(), ex);
+                }
             }
         }
-
         for (TransferMode mode : rpcServers.keySet()) {
             rpcServers.get(mode).shutdown();
         }
@@ -896,10 +902,14 @@ private int translateFlags(boolean reset, boolean force, boolean defer) {
      */
     private class ConnectionTrackerThread implements Runnable {
         private boolean connectionLost;
+        private boolean reStartPending = false;
 
         @Override
         public void run() {
             try {
+                if (reStartPending) {
+                    return;
+                }
                 ListBidcosInterfacesParser parser = getRpcClient(getDefaultInterface())
                         .listBidcosInterfaces(getDefaultInterface());
                 Integer dutyCycleRatio = parser.getDutyCycleRatio();
@@ -920,6 +930,11 @@ private void connectionConfirmed() {
             if (connectionLost) {
                 connectionLost = false;
                 logger.info("Connection resumed on gateway '{}'", id);
+                try {
+                    registerCallbacks();
+                } catch (IOException e) {
+                    logger.warn("Connection only partially restored. It is recommended to restart the binding");
+                }
                 gatewayAdapter.onConnectionResumed();
             }
         }
@@ -930,10 +945,19 @@ private void handleInvalidConnection(String cause) throws IOException {
                 logger.warn("Connection lost on gateway '{}', cause: \"{}\"", id, cause);
                 gatewayAdapter.onConnectionLost();
             }
-            stopServers();
+            stopServers(false);
             stopClients();
-            startClients();
-            startServers();
+            reStartPending = true;
+            logger.debug("Waiting {}s until restart attempt", RESTART_DELAY);
+            scheduler.schedule(() -> {
+                try {
+                    startClients();
+                    startServers();
+                } catch (IOException e) {
+                    logger.debug("Restart failed: {}", e.getMessage());
+                }
+                reStartPending = false;
+            }, RESTART_DELAY, TimeUnit.SECONDS);
         }
     }
 }
diff --git a/...rc/main/java/org/openhab/binding/homematic/internal/communicator/client/BinRpcClient.java b/...rc/main/java/org/openhab/binding/homematic/internal/communicator/client/BinRpcClient.java
@@ -40,6 +40,7 @@ public BinRpcClient(HomematicConfig config) {
 
     @Override
     public void dispose() {
+        super.dispose();
         socketHandler.flush();
     }
 
@@ -54,8 +55,8 @@ protected String getRpcCallbackUrl() {
     }
 
     @Override
-    public void init(HmInterface hmInterface, String clientId) throws IOException {
-        super.init(hmInterface, clientId);
+    public void init(HmInterface hmInterface) throws IOException {
+        super.init(hmInterface);
         socketHandler.removeSocket(config.getRpcPort(hmInterface));
     }
 

diff --git a/...c/src/main/java/org/openhab/binding/homematic/internal/communicator/client/RpcClient.java b/...c/src/main/java/org/openhab/binding/homematic/internal/communicator/client/RpcClient.java
@@ -19,6 +19,13 @@
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
+import java.util.UUID;
+import java.util.concurrent.CancellationException;
+import java.util.concurrent.ExecutionException;
+import java.util.concurrent.ScheduledExecutorService;
+import java.util.concurrent.ScheduledFuture;
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.TimeoutException;
 
 import org.openhab.binding.homematic.internal.HomematicBindingConstants;
 import org.openhab.binding.homematic.internal.common.HomematicConfig;
@@ -41,6 +48,7 @@
 import org.openhab.binding.homematic.internal.model.HmInterface;
 import org.openhab.binding.homematic.internal.model.HmParamsetType;
 import org.openhab.binding.homematic.internal.model.HmRssiInfo;
+import org.openhab.core.common.ThreadPoolManager;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
@@ -53,18 +61,18 @@ public abstract class RpcClient<T> {
     private final Logger logger = LoggerFactory.getLogger(RpcClient.class);
     protected static final int MAX_RPC_RETRY = 3;
     protected static final int RESP_BUFFER_SIZE = 8192;
+    private static final int INITIAL_CALLBACK_REG_DELAY = 20; // 20 s before first attempt
+    private static final int CALLBACK_REG_DELAY = 10; // 10 s between two attempts
 
     protected HomematicConfig config;
+    private String thisUID = UUID.randomUUID().toString();
+    private ScheduledFuture<?> future = null;
+    private int attempt;
 
     public RpcClient(HomematicConfig config) {
         this.config = config;
     }
 
-    /**
-     * Disposes the client.
-     */
-    public abstract void dispose();
-
     /**
      * Returns a RpcRequest for this client.
      */
@@ -83,14 +91,48 @@ public RpcClient(HomematicConfig config) {
     /**
      * Register a callback for the specified interface where the Homematic gateway can send its events.
      */
-    public void init(HmInterface hmInterface, String clientId) throws IOException {
+    public void init(HmInterface hmInterface) throws IOException {
+        ScheduledExecutorService scheduler = ThreadPoolManager.getScheduledPool(GATEWAY_POOL_NAME);
         RpcRequest<T> request = createRpcRequest("init");
         request.addArg(getRpcCallbackUrl());
-        request.addArg(clientId);
+        request.addArg(thisUID);
         if (config.getGatewayInfo().isHomegear()) {
             request.addArg(Integer.valueOf(0x22));
         }
-        sendMessage(config.getRpcPort(hmInterface), request);
+        logger.debug("Register callback for interface {}", hmInterface.getName());
+        try {
+            attempt = 1;
+            sendMessage(config.getRpcPort(hmInterface), request); // first attempt without delay
+        } catch (IOException e) {
+            future = scheduler.scheduleWithFixedDelay(() -> {
+                logger.debug("Register callback for interface {}, attempt {}", hmInterface.getName(), ++attempt);
+                try {
+                    sendMessage(config.getRpcPort(hmInterface), request);
+                    future.cancel(true);
+                } catch (IOException ex) {
+                    // Ignore, retry
+                }
+            }, INITIAL_CALLBACK_REG_DELAY, CALLBACK_REG_DELAY, TimeUnit.SECONDS);
+            try {
+                future.get(config.getCallbackRegTimeout(), TimeUnit.SECONDS);
+            } catch (CancellationException e1) {
+                logger.debug("Callback for interface {} successfully registered", hmInterface.getName());
+            } catch (InterruptedException | ExecutionException e1) {
+                throw new IOException("Callback reg. thread interrupted", e1);
+            } catch (TimeoutException e1) {
+                logger.error("Callback registration for interface {} timed out", hmInterface.getName());
+                throw new IOException("Unable to reconnect in time");
+            }
+            future = null;
+        }
+    }
+
+    /**
+     * Disposes the client.
+     */
+    public void dispose() {
+        if (future != null)
+            future.cancel(true);
     }
 
     /**

diff --git a/...rc/main/java/org/openhab/binding/homematic/internal/communicator/client/XmlRpcClient.java b/...rc/main/java/org/openhab/binding/homematic/internal/communicator/client/XmlRpcClient.java
@@ -49,10 +49,6 @@ public XmlRpcClient(HomematicConfig config, HttpClient httpClient) throws IOExce
         this.httpClient = httpClient;
     }
 
-    @Override
-    public void dispose() {
-    }
-
     @Override
     public RpcRequest<String> createRpcRequest(String methodName) {
         return new XmlRpcRequest(methodName);
@@ -87,10 +83,13 @@ protected synchronized Object[] sendMessage(int port, RpcRequest<String> request
                 throw new IOException(ex);
             } catch (IOException ex) {
                 reason = ex;
-                if ("init".equals(request.getMethodName())) { // no retries for "init" request
+                // no retries for "init" request or if connection is refused
+                if ("init".equals(request.getMethodName())
+                        || ex.getCause() != null && ex.getCause() instanceof ExecutionException) {
                     break;
                 }
-                logger.debug("XmlRpcMessage failed, sending message again {}/{}", rpcRetryCounter, MAX_RPC_RETRY);
+                logger.debug("XmlRpcMessage failed({}), sending message again {}/{}", ex.getMessage(), rpcRetryCounter,
+                        MAX_RPC_RETRY);
             }
         }
         throw reason;

diff --git a/bundles/org.openhab.binding.homematic/src/main/resources/OH-INF/thing/bridge.xml b/bundles/org.openhab.binding.homematic/src/main/resources/OH-INF/thing/bridge.xml
@@ -95,6 +95,12 @@
 				<advanced>true</advanced>
 				<default>9292</default>
 			</parameter>
+			<parameter name="callbackRegTimeout" type="integer" min="30">
+				<label>Callback Reg. Timeout</label>
+				<description>Maximum time in seconds for callback registration in the Homematic gateway.</description>
+				<advanced>true</advanced>
+				<default>120</default>
+			</parameter>
 			<parameter name="installModeDuration" type="integer" min="10" max="300" unit="s">
 				<label>Install Mode Duration</label>
 				<description>Time in seconds that the controller will be in install mode when a device discovery is initiated</description>