[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 <software@whitebear.ch>
This commit is contained in:
Andrew Fiddian-Green 2023-01-04 06:26:22 +00:00 committed by GitHub
parent de6ef7e8ae
commit 31fd91129e
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
7 changed files with 166 additions and 86 deletions

View 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
*

View 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() {

View 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();
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

View 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;
}

View 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;
}
// 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;
}
}

View 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);
}
}

View 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());