]> git.basschouten.com Git - openhab-addons.git/commitdiff
[neohub] Recover faster if NeoHub produces empty responses (#13889)
authorAndrew Fiddian-Green <software@whitebear.ch>
Wed, 4 Jan 2023 06:26:22 +0000 (06:26 +0000)
committerGitHub <noreply@github.com>
Wed, 4 Jan 2023 06:26:22 +0000 (07:26 +0100)
* [neohub] resolve issue #13829
* [neohub] harmonise exceptions and logging
* [neohub] improve field name, and log messages

Signed-off-by: Andrew Fiddian-Green <software@whitebear.ch>
bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubException.java
bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubHandler.java
bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocket.java
bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocketBase.java
bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubWebSocket.java
bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubJsonTests.java
bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubProtocolTests.java

index 55c4bd2a243b0b1f653940f296cd588d7090750f..be0e389e1866c9a458feb14d07a7062c548beff3 100644 (file)
@@ -15,7 +15,9 @@ package org.openhab.binding.neohub.internal;
 import org.eclipse.jdt.annotation.NonNullByDefault;
 
 /**
- * The {@link NeoHubException} is a custom exception for NeoHub
+ * The {@link NeoHubException} is a custom checked exception for NeoHubs. It is thrown when the NeoHub encounters an
+ * error that is NOT I/O related. i.e. if the binding is able to connect to the NeoHub but the NeoHub returns unexpected
+ * results.
  *
  * @author Andrew Fiddian-Green - Initial contribution
  *
index 15bb98ce1a745b8a129e4433694be9077e10e890..55927c883b114e8655da73855985857254afab94 100644 (file)
@@ -59,6 +59,7 @@ import com.google.gson.JsonSyntaxException;
 public class NeoHubHandler extends BaseBridgeHandler {
 
     private static final String SEE_README = "See documentation chapter \"Connection Refused Errors\"";
+    private static final int MAX_FAILED_SEND_ATTEMPTS = 2;
 
     private final Logger logger = LoggerFactory.getLogger(NeoHubHandler.class);
 
@@ -86,6 +87,7 @@ public class NeoHubHandler extends BaseBridgeHandler {
 
     private ApiVersion apiVersion = ApiVersion.LEGACY;
     private boolean isApiOnline = false;
+    private int failedSendAttempts = 0;
 
     public NeoHubHandler(Bridge bridge) {
         super(bridge);
@@ -146,11 +148,11 @@ public class NeoHubHandler extends BaseBridgeHandler {
         NeoHubSocketBase socket;
         try {
             if (config.useWebSocket) {
-                socket = new NeoHubWebSocket(config);
+                socket = new NeoHubWebSocket(config, thing.getUID().getAsString());
             } else {
-                socket = new NeoHubSocket(config);
+                socket = new NeoHubSocket(config, thing.getUID().getAsString());
             }
-        } catch (NeoHubException e) {
+        } catch (IOException e) {
             logger.debug("\"hub '{}' error creating web/tcp socket: '{}'", getThing().getUID(), e.getMessage());
             return;
         }
@@ -230,7 +232,7 @@ public class NeoHubHandler extends BaseBridgeHandler {
         }
     }
 
-    /*
+    /**
      * device handlers call this to initiate a burst of fast polling requests (
      * improves response time to users when openHAB changes a channel value )
      */
@@ -255,7 +257,7 @@ public class NeoHubHandler extends BaseBridgeHandler {
             startFastPollingBurst();
 
             return NeoHubReturnResult.SUCCEEDED;
-        } catch (Exception e) {
+        } catch (IOException | NeoHubException e) {
             updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.COMMUNICATION_ERROR);
             logger.warn(MSG_FMT_SET_VALUE_ERR, getThing().getUID(), commandStr, e.getMessage());
             return NeoHubReturnResult.ERR_COMMUNICATION;
@@ -331,7 +333,7 @@ public class NeoHubHandler extends BaseBridgeHandler {
             }
 
             return deviceData;
-        } catch (Exception e) {
+        } catch (IOException | NeoHubException e) {
             logger.warn(MSG_FMT_DEVICE_POLL_ERR, getThing().getUID(), e.getMessage());
             updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.COMMUNICATION_ERROR);
             return null;
@@ -376,13 +378,13 @@ public class NeoHubHandler extends BaseBridgeHandler {
             }
 
             return systemData;
-        } catch (Exception e) {
+        } catch (IOException | NeoHubException e) {
             logger.warn(MSG_FMT_SYSTEM_POLL_ERR, getThing().getUID(), e.getMessage());
             return null;
         }
     }
 
-    /*
+    /**
      * this is the callback used by the lazy polling scheduler.. fetches the info
      * for all devices from the NeoHub, and passes the results the respective device
      * handlers
@@ -394,7 +396,18 @@ public class NeoHubHandler extends BaseBridgeHandler {
         }
 
         NeoHubAbstractDeviceData deviceData = fromNeoHubGetDeviceData();
-        if (deviceData != null) {
+        if (deviceData == null) {
+            if (fastPollingCallsToGo.get() == 0) {
+                failedSendAttempts++;
+                if (failedSendAttempts < MAX_FAILED_SEND_ATTEMPTS) {
+                    logger.debug("lazyPollingSchedulerExecute() deviceData:null, running again");
+                    scheduler.submit(() -> lazyPollingSchedulerExecute());
+                }
+            }
+            return;
+        } else {
+            failedSendAttempts = 0;
+
             // dispatch deviceData to each of the hub's owned devices ..
             List<Thing> children = getThing().getThings();
             for (Thing child : children) {
@@ -448,7 +461,7 @@ public class NeoHubHandler extends BaseBridgeHandler {
         }
     }
 
-    /*
+    /**
      * this is the callback used by the fast polling scheduler.. checks if a fast
      * polling burst is scheduled, and if so calls lazyPollingSchedulerExecute
      */
@@ -458,7 +471,7 @@ public class NeoHubHandler extends BaseBridgeHandler {
         }
     }
 
-    /*
+    /**
      * select whether to use the old "deprecated" API or the new API
      */
     private void selectApi() {
@@ -516,7 +529,7 @@ public class NeoHubHandler extends BaseBridgeHandler {
         this.isApiOnline = true;
     }
 
-    /*
+    /**
      * get the Engineers data
      */
     public @Nullable NeoHubGetEngineersData fromNeoHubGetEngineersData() {
index 301fefb8e1755241b991933a84907ee1231b3584..29c4f2062964ec0b246ec0ced19a8f3703c11986 100644 (file)
@@ -24,8 +24,10 @@ import org.eclipse.jdt.annotation.NonNullByDefault;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
+import com.google.gson.JsonParser;
+
 /**
- * Handles the ASCII based communication via TCP socket between openHAB and NeoHub
+ * Handles the text based communication via TCP socket between openHAB and NeoHub
  *
  * @author Sebastian Prehn - Initial contribution
  * @author Andrew Fiddian-Green - Refactoring for openHAB v2.x
@@ -36,8 +38,8 @@ public class NeoHubSocket extends NeoHubSocketBase {
 
     private final Logger logger = LoggerFactory.getLogger(NeoHubSocket.class);
 
-    public NeoHubSocket(NeoHubConfiguration config) {
-        super(config);
+    public NeoHubSocket(NeoHubConfiguration config, String hubId) {
+        super(config, hubId);
     }
 
     @Override
@@ -52,19 +54,13 @@ public class NeoHubSocket extends NeoHubSocketBase {
 
             try (InputStreamReader reader = new InputStreamReader(socket.getInputStream(), US_ASCII);
                     OutputStreamWriter writer = new OutputStreamWriter(socket.getOutputStream(), US_ASCII)) {
-                if (logger.isDebugEnabled()) {
-                    logger.debug("sending {} characters..", requestJson.length());
-                    logger.debug(">> {}", requestJson);
-                }
-
+                //
+                logger.debug("hub '{}' sending characters:{}", hubId, requestJson.length());
                 writer.write(requestJson);
                 writer.write(0); // NULL terminate the command string
                 writer.flush();
                 socket.shutdownOutput();
-
-                if (logger.isTraceEnabled()) {
-                    logger.trace("sent {} characters..", requestJson.length());
-                }
+                logger.trace("hub '{}' sent:{}", hubId, requestJson);
 
                 int inChar;
                 boolean done = false;
@@ -81,28 +77,21 @@ public class NeoHubSocket extends NeoHubSocketBase {
             caughtException = e;
         }
 
-        String responseJson = builder.toString();
-
-        if (logger.isTraceEnabled()) {
-            logger.trace("received {} characters..", responseJson.length());
-            logger.trace("<< {}", responseJson);
-        } else
+        String responseJson = builder.toString().strip();
 
-        if (logger.isDebugEnabled()) {
-            logger.debug("received {} characters (set log level to TRACE to see full string)..", responseJson.length());
-            logger.debug("<< {} ...", responseJson.substring(0, Math.min(responseJson.length(), 30)));
-        }
+        logger.debug("hub '{}' received characters:{}", hubId, responseJson.length());
+        logger.trace("hub '{}' received:{}", hubId, responseJson);
 
-        // if any type of Exception was caught above, re-throw it again to the caller
+        // if an IOException was caught above, re-throw it again
         if (caughtException != null) {
             throw caughtException;
         }
 
-        if (responseJson.isEmpty()) {
-            throw new NeoHubException("empty response string");
+        if (JsonParser.parseString(responseJson).isJsonObject()) {
+            return responseJson;
         }
-
-        return responseJson;
+        logger.debug("hub '{}' Response is not a JSON object; response:{}", hubId, responseJson);
+        throw new NeoHubException("Invalid response");
     }
 
     @Override
index 3ee2b9665245e8e783e2ee942cbddc96efc0a959..347557ae87e850457f17c215fac0211f05e1b713 100644 (file)
@@ -18,7 +18,7 @@ import java.io.IOException;
 import org.eclipse.jdt.annotation.NonNullByDefault;
 
 /**
- * Base abstract class for ASCII based communication between openHAB and NeoHub
+ * Base abstract class for text based communication between openHAB and NeoHub
  *
  * @author Andrew Fiddian-Green - Initial contribution
  *
@@ -27,9 +27,11 @@ import org.eclipse.jdt.annotation.NonNullByDefault;
 public abstract class NeoHubSocketBase implements Closeable {
 
     protected final NeoHubConfiguration config;
+    protected final String hubId;
 
-    public NeoHubSocketBase(NeoHubConfiguration config) {
+    public NeoHubSocketBase(NeoHubConfiguration config, String hubId) {
         this.config = config;
+        this.hubId = hubId;
     }
 
     /**
@@ -37,8 +39,8 @@ public abstract class NeoHubSocketBase implements Closeable {
      *
      * @param requestJson the message to be sent to the NeoHub
      * @return responseJson received from NeoHub
-     * @throws NeoHubException, IOException
-     *
+     * @throws IOException if there was a communication error or the socket state would not permit communication
+     * @throws NeoHubException if the communication returned a response but the response was not valid JSON
      */
     public abstract String sendMessage(final String requestJson) throws IOException, NeoHubException;
 }
index f62dc860e5e166c24ff4cd42aa300112360fb825..ebd76f32a0359491463d72c7461e46d108c225ed 100644 (file)
@@ -32,9 +32,11 @@ import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
 import com.google.gson.Gson;
+import com.google.gson.JsonParser;
+import com.google.gson.JsonSyntaxException;
 
 /**
- * Handles the ASCII based communication via web socket between openHAB and NeoHub
+ * Handles the text based communication via web socket between openHAB and NeoHub
  *
  * @author Andrew Fiddian-Green - Initial contribution
  *
@@ -53,7 +55,7 @@ public class NeoHubWebSocket extends NeoHubSocketBase {
 
     private @Nullable Session session = null;
     private String responseOuter = "";
-    private boolean responseWaiting;
+    private boolean responsePending;
 
     /**
      * DTO to receive and parse the response JSON.
@@ -69,8 +71,8 @@ public class NeoHubWebSocket extends NeoHubSocketBase {
         public @Nullable String response;
     }
 
-    public NeoHubWebSocket(NeoHubConfiguration config) throws NeoHubException {
-        super(config);
+    public NeoHubWebSocket(NeoHubConfiguration config, String hubId) throws IOException {
+        super(config, hubId);
 
         // initialise and start ssl context factory, http client, web socket client
         SslContextFactory.Client sslContextFactory = new SslContextFactory.Client();
@@ -79,23 +81,23 @@ public class NeoHubWebSocket extends NeoHubSocketBase {
         try {
             httpClient.start();
         } catch (Exception e) {
-            throw new NeoHubException(String.format("Error starting http client: '%s'", e.getMessage()));
+            throw new IOException("Error starting HTTP client", e);
         }
         webSocketClient = new WebSocketClient(httpClient);
         webSocketClient.setConnectTimeout(config.socketTimeout * 1000);
         try {
             webSocketClient.start();
         } catch (Exception e) {
-            throw new NeoHubException(String.format("Error starting web socket client: '%s'", e.getMessage()));
+            throw new IOException("Error starting Web Socket client", e);
         }
     }
 
     /**
      * Open the web socket session.
      *
-     * @throws NeoHubException
+     * @throws IOException if unable to open the web socket
      */
-    private void startSession() throws NeoHubException {
+    private void startSession() throws IOException {
         Session session = this.session;
         if (session == null || !session.isOpen()) {
             closeSession();
@@ -105,9 +107,9 @@ public class NeoHubWebSocket extends NeoHubSocketBase {
                 webSocketClient.connect(this, uri).get();
             } catch (InterruptedException e) {
                 Thread.currentThread().interrupt();
-                throw new NeoHubException(String.format("Error starting session: '%s'", e.getMessage(), e));
+                throw new IOException("Error starting session", e);
             } catch (ExecutionException | IOException | URISyntaxException e) {
-                throw new NeoHubException(String.format("Error starting session: '%s'", e.getMessage(), e));
+                throw new IOException("Error starting session", e);
             }
         }
     }
@@ -161,7 +163,7 @@ public class NeoHubWebSocket extends NeoHubSocketBase {
         // session start failed
         Session session = this.session;
         if (session == null) {
-            throw new NeoHubException("Session is null.");
+            throw new IOException("Session is null");
         }
 
         // wrap the inner request in an outer request string
@@ -170,35 +172,61 @@ public class NeoHubWebSocket extends NeoHubSocketBase {
 
         // initialise the response
         responseOuter = "";
-        responseWaiting = true;
+        responsePending = true;
 
-        // send the request
-        logger.trace("Sending request: {}", requestOuter);
-        session.getRemote().sendString(requestOuter);
+        IOException caughtException = null;
+        try {
+            // send the request
+            logger.debug("hub '{}' sending characters:{}", hubId, requestOuter.length());
+            session.getRemote().sendString(requestOuter);
+            logger.trace("hub '{}' sent:{}", hubId, requestOuter);
 
-        // sleep and loop until we get a response or the socket is closed
-        int sleepRemainingMilliseconds = config.socketTimeout * 1000;
-        while (responseWaiting && (sleepRemainingMilliseconds > 0)) {
-            try {
-                Thread.sleep(SLEEP_MILLISECONDS);
-                sleepRemainingMilliseconds = sleepRemainingMilliseconds - SLEEP_MILLISECONDS;
-            } catch (InterruptedException e) {
-                throw new NeoHubException(String.format("Read timeout '%s'", e.getMessage()));
+            // sleep and loop until we get a response or the socket is closed
+            int sleepRemainingMilliseconds = config.socketTimeout * 1000;
+            while (responsePending) {
+                try {
+                    Thread.sleep(SLEEP_MILLISECONDS);
+                    sleepRemainingMilliseconds = sleepRemainingMilliseconds - SLEEP_MILLISECONDS;
+                    if (sleepRemainingMilliseconds <= 0) {
+                        throw new IOException("Read timed out");
+                    }
+                } catch (InterruptedException e) {
+                    throw new IOException("Read interrupted", e);
+                }
             }
+        } catch (IOException e) {
+            caughtException = e;
+        }
+
+        logger.debug("hub '{}' received characters:{}", hubId, responseOuter.length());
+        logger.trace("hub '{}' received:{}", hubId, responseOuter);
+
+        // if an IOException was caught above, re-throw it again
+        if (caughtException != null) {
+            throw caughtException;
         }
 
-        // extract the inner response from the outer response string
-        Response responseDto = gson.fromJson(responseOuter, Response.class);
-        if (responseDto != null && NeoHubBindingConstants.HM_SET_COMMAND_RESPONSE.equals(responseDto.message_type)) {
+        try {
+            Response responseDto = gson.fromJson(responseOuter, Response.class);
+            if (responseDto == null) {
+                throw new JsonSyntaxException("Response DTO is invalid");
+            }
+            if (!NeoHubBindingConstants.HM_SET_COMMAND_RESPONSE.equals(responseDto.message_type)) {
+                throw new JsonSyntaxException("DTO 'message_type' field is invalid");
+            }
             String responseJson = responseDto.response;
-            if (responseJson != null) {
-                responseJson = jsonUnEscape(responseJson);
-                logger.trace("Received response: {}", responseJson);
-                return responseJson;
+            if (responseJson == null) {
+                throw new JsonSyntaxException("DTO 'response' field is null");
+            }
+            responseJson = jsonUnEscape(responseJson).strip();
+            if (!JsonParser.parseString(responseJson).isJsonObject()) {
+                throw new JsonSyntaxException("DTO 'response' field is not a JSON object");
             }
+            return responseJson;
+        } catch (JsonSyntaxException e) {
+            logger.debug("hub '{}' {}; response:{}", hubId, e.getMessage(), responseOuter);
+            throw new NeoHubException("Invalid response");
         }
-        logger.debug("Null or invalid response.");
-        return "";
     }
 
     @Override
@@ -212,27 +240,26 @@ public class NeoHubWebSocket extends NeoHubSocketBase {
 
     @OnWebSocketConnect
     public void onConnect(Session session) {
-        logger.trace("onConnect: ok");
+        logger.debug("hub '{}' onConnect() ok", hubId);
         this.session = session;
     }
 
     @OnWebSocketClose
     public void onClose(int statusCode, String reason) {
-        logger.trace("onClose: code:{}, reason:{}", statusCode, reason);
-        responseWaiting = false;
+        logger.debug("hub '{}' onClose() statusCode:{}, reason:{}", hubId, statusCode, reason);
+        responsePending = false;
         this.session = null;
     }
 
     @OnWebSocketError
     public void onError(Throwable cause) {
-        logger.trace("onError: cause:{}", cause.getMessage());
+        logger.debug("hub '{}' onError() cause:{}", hubId, cause.getMessage());
         closeSession();
     }
 
     @OnWebSocketMessage
     public void onMessage(String msg) {
-        logger.trace("onMessage: msg:{}", msg);
-        responseOuter = msg;
-        responseWaiting = false;
+        responseOuter = msg.strip();
+        responsePending = false;
     }
 }
index 0417e15359b3911b016af96818035883f19e8ce0..a9e75e3f8c799d75ce4559ebbb8aea54b14ae731 100644 (file)
@@ -36,6 +36,10 @@ import org.openhab.binding.neohub.internal.NeoHubSocket;
 import org.openhab.core.library.unit.ImperialUnits;
 import org.openhab.core.library.unit.SIUnits;
 
+import com.google.gson.JsonElement;
+import com.google.gson.JsonObject;
+import com.google.gson.JsonParser;
+
 /**
  * JUnit for testing JSON parsing.
  *
@@ -363,7 +367,7 @@ public class NeoHubJsonTests {
         config.hostName = HUB_IP_ADDRESS;
         config.socketTimeout = 5;
         try {
-            NeoHubSocket socket = new NeoHubSocket(config);
+            NeoHubSocket socket = new NeoHubSocket(config, "test");
             String responseJson = socket.sendMessage(requestJson);
             socket.close();
             return responseJson;
@@ -416,4 +420,47 @@ public class NeoHubJsonTests {
         responseJson = testCommunicationInner(String.format(CMD_CODE_TEMP, "20", "Hallway"));
         assertFalse(responseJson.isEmpty());
     }
+
+    @Test
+    public void testJsonValidation() {
+        JsonElement jsonElement;
+
+        jsonElement = JsonParser.parseString("");
+        assertFalse(jsonElement.isJsonObject());
+
+        jsonElement = JsonParser.parseString("xx");
+        assertFalse(jsonElement.isJsonObject());
+
+        jsonElement = JsonParser.parseString("{}");
+        assertTrue(jsonElement.isJsonObject());
+        assertEquals(0, ((JsonObject) jsonElement).keySet().size());
+
+        jsonElement = JsonParser.parseString(load("dcb_celsius"));
+        assertTrue(jsonElement.isJsonObject());
+        assertTrue(((JsonObject) jsonElement).keySet().size() > 0);
+
+        jsonElement = JsonParser.parseString(load("live_data"));
+        assertTrue(jsonElement.isJsonObject());
+        assertTrue(((JsonObject) jsonElement).keySet().size() > 0);
+
+        jsonElement = JsonParser.parseString(load("engineers"));
+        assertTrue(jsonElement.isJsonObject());
+        assertTrue(((JsonObject) jsonElement).keySet().size() > 0);
+
+        jsonElement = JsonParser.parseString(load("info_new"));
+        assertTrue(jsonElement.isJsonObject());
+        assertTrue(((JsonObject) jsonElement).keySet().size() > 0);
+
+        jsonElement = JsonParser.parseString(load("info_old"));
+        assertTrue(jsonElement.isJsonObject());
+        assertTrue(((JsonObject) jsonElement).keySet().size() > 0);
+
+        jsonElement = JsonParser.parseString(load("system"));
+        assertTrue(jsonElement.isJsonObject());
+        assertTrue(((JsonObject) jsonElement).keySet().size() > 0);
+
+        jsonElement = JsonParser.parseString(load("info_sensors_closed"));
+        assertTrue(jsonElement.isJsonObject());
+        assertTrue(((JsonObject) jsonElement).keySet().size() > 0);
+    }
 }
index 86cc7ae79b1df22e90ddabec34842d536b81e6b6..09e107aedc425f6e0ef591d281ab7d83f33c76ba 100644 (file)
@@ -70,7 +70,7 @@ public class NeoHubProtocolTests {
             config.socketTimeout = SOCKET_TIMEOUT;
             config.apiToken = HUB_API_TOKEN;
 
-            NeoHubWebSocket socket = new NeoHubWebSocket(config);
+            NeoHubWebSocket socket = new NeoHubWebSocket(config, "test");
             String requestJson = NeoHubBindingConstants.CMD_CODE_FIRMWARE;
             String responseJson = socket.sendMessage(requestJson);
             assertNotEquals(0, responseJson.length());
@@ -96,7 +96,7 @@ public class NeoHubProtocolTests {
             config.socketTimeout = SOCKET_TIMEOUT;
             config.apiToken = HUB_API_TOKEN;
 
-            NeoHubSocket socket = new NeoHubSocket(config);
+            NeoHubSocket socket = new NeoHubSocket(config, "test");
             String requestJson = NeoHubBindingConstants.CMD_CODE_FIRMWARE;
             String responseJson = socket.sendMessage(requestJson);
             assertNotEquals(0, responseJson.length());