From 31fd91129eb4382f2c44f1b06b1559123ece1110 Mon Sep 17 00:00:00 2001 From: Andrew Fiddian-Green Date: Wed, 4 Jan 2023 06:26:22 +0000 Subject: [PATCH] [neohub] Recover faster if NeoHub produces empty responses (#13889) * [neohub] resolve issue #13829 * [neohub] harmonise exceptions and logging * [neohub] improve field name, and log messages Signed-off-by: Andrew Fiddian-Green --- .../neohub/internal/NeoHubException.java | 4 +- .../neohub/internal/NeoHubHandler.java | 37 ++++-- .../binding/neohub/internal/NeoHubSocket.java | 43 +++---- .../neohub/internal/NeoHubSocketBase.java | 10 +- .../neohub/internal/NeoHubWebSocket.java | 105 +++++++++++------- .../binding/neohub/test/NeoHubJsonTests.java | 49 +++++++- .../neohub/test/NeoHubProtocolTests.java | 4 +- 7 files changed, 166 insertions(+), 86 deletions(-) diff --git a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubException.java b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubException.java index 55c4bd2a2..be0e389e1 100644 --- a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubException.java +++ b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubException.java @@ -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 * diff --git a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubHandler.java b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubHandler.java index 15bb98ce1..55927c883 100644 --- a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubHandler.java +++ b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubHandler.java @@ -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 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() { diff --git a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocket.java b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocket.java index 301fefb8e..29c4f2062 100644 --- a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocket.java +++ b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocket.java @@ -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(); + String responseJson = builder.toString().strip(); - if (logger.isTraceEnabled()) { - logger.trace("received {} characters..", responseJson.length()); - logger.trace("<< {}", responseJson); - } else + logger.debug("hub '{}' received characters:{}", hubId, responseJson.length()); + logger.trace("hub '{}' received:{}", hubId, responseJson); - 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))); - } - - // 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 diff --git a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocketBase.java b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocketBase.java index 3ee2b9665..347557ae8 100644 --- a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocketBase.java +++ b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubSocketBase.java @@ -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; } diff --git a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubWebSocket.java b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubWebSocket.java index f62dc860e..ebd76f32a 100644 --- a/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubWebSocket.java +++ b/bundles/org.openhab.binding.neohub/src/main/java/org/openhab/binding/neohub/internal/NeoHubWebSocket.java @@ -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; } - // 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)) { + 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; + } + + 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; } } diff --git a/bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubJsonTests.java b/bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubJsonTests.java index 0417e1535..a9e75e3f8 100644 --- a/bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubJsonTests.java +++ b/bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubJsonTests.java @@ -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); + } } diff --git a/bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubProtocolTests.java b/bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubProtocolTests.java index 86cc7ae79..09e107aed 100644 --- a/bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubProtocolTests.java +++ b/bundles/org.openhab.binding.neohub/src/test/java/org/openhab/binding/neohub/test/NeoHubProtocolTests.java @@ -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());