[homematic] Improve (re)connect handling to Homematic gateways (#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 #8808

Fixes #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>

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

bundles/org.openhab.binding.homematic/src/main/java/org/openhab/binding/homematic/internal/HomematicBindingConstants.java

@@ -24,6 +24,7 @@ import org.openhab.core.thing.ThingTypeUID;
 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";
 

bundles/org.openhab.binding.homematic/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 class HomematicConfig {
         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.
      */

bundles/org.openhab.binding.homematic/src/main/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 @@ import org.slf4j.LoggerFactory;
 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 abstract class AbstractHomematicGateway implements RpcEventListener, Home
         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 abstract class AbstractHomematicGateway implements RpcEventListener, Home
         stopWatchdogs();
         sendDelayedExecutor.stop();
         receiveDelayedExecutor.stop();
-        stopServers();
+        stopServers(true);
         stopClients();
         devices.clear();
         echoEvents.clear();
@@ -253,25 +255,29 @@ public abstract class AbstractHomematicGateway implements RpcEventListener, Home
                 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() {
+    private synchronized void stopServers(boolean releaseConnection) {
-        for (HmInterface hmInterface : availableInterfaces.keySet()) {
+        if (releaseConnection) {
-            try {
+            for (HmInterface hmInterface : availableInterfaces.keySet()) {
-                getRpcClient(hmInterface).release(hmInterface);
+                try {
-            } catch (IOException ex) {
+                    getRpcClient(hmInterface).release(hmInterface);
-                // recoverable exception, therefore only debug
+                } catch (IOException ex) {
-                logger.debug("Unable to release the connection to the gateway with id '{}': {}", id, ex.getMessage(),
+                    // recoverable exception, therefore only debug
-                        ex);
+                    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 @@ public abstract class AbstractHomematicGateway implements RpcEventListener, Home
      */
     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 @@ public abstract class AbstractHomematicGateway implements RpcEventListener, Home
             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 @@ public abstract class AbstractHomematicGateway implements RpcEventListener, Home
                 logger.warn("Connection lost on gateway '{}', cause: \"{}\"", id, cause);
                 gatewayAdapter.onConnectionLost();
             }
-            stopServers();
+            stopServers(false);
             stopClients();
-            startClients();
+            reStartPending = true;
-            startServers();
+            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);
         }
     }
 }

bundles/org.openhab.binding.homematic/src/main/java/org/openhab/binding/homematic/internal/communicator/client/BinRpcClient.java

@@ -40,6 +40,7 @@ public class BinRpcClient extends RpcClient<byte[]> {
 
     @Override
     public void dispose() {
+        super.dispose();
         socketHandler.flush();
     }
 
@@ -54,8 +55,8 @@ public class BinRpcClient extends RpcClient<byte[]> {
     }
 
     @Override
-    public void init(HmInterface hmInterface, String clientId) throws IOException {
+    public void init(HmInterface hmInterface) throws IOException {
-        super.init(hmInterface, clientId);
+        super.init(hmInterface);
         socketHandler.removeSocket(config.getRpcPort(hmInterface));
     }
 

bundles/org.openhab.binding.homematic/src/main/java/org/openhab/binding/homematic/internal/communicator/client/RpcClient.java

@@ -19,6 +19,13 @@ import java.util.Collection;
 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.HmGatewayInfo;
 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 abstract class RpcClient<T> {
     /**
      * 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);
     }
 
     /**

bundles/org.openhab.binding.homematic/src/main/java/org/openhab/binding/homematic/internal/communicator/client/XmlRpcClient.java

@@ -49,10 +49,6 @@ public class XmlRpcClient extends RpcClient<String> {
         this.httpClient = httpClient;
     }
 
-    @Override
-    public void dispose() {
-    }
-
     @Override
     public RpcRequest<String> createRpcRequest(String methodName) {
         return new XmlRpcRequest(methodName);
@@ -87,10 +83,13 @@ public class XmlRpcClient extends RpcClient<String> {
                 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;

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>