Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[keba] Robustness improvements on communication error #10399

Merged
merged 4 commits into from
Apr 17, 2021
Merged

[keba] Robustness improvements on communication error #10399

Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
70da552
Merge pull request #1 from openhab/main
MikeTheTux Mar 27, 2021
4703aad
do not send binding offline on (temporary) communication errors
MikeTheTux Mar 27, 2021
618efc4
Robustness improvements on communication error
MikeTheTux Apr 7, 2021
f7c251a
Robustness improvements on communication error
MikeTheTux Apr 10, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
64 changes: 37 additions & 27 deletions ...inding.keba/src/main/java/org/openhab/binding/keba/internal/handler/KeContactHandler.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -181,51 +181,61 @@ private void pollingRunnable() {
long stamp = System.currentTimeMillis();
if (!isKebaReachable()) {
logger.debug("isKebaReachable() timed out after '{}' milliseconds", System.currentTimeMillis() - stamp);
transceiver.unRegisterHandler(getHandler());
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I actually believe that this is the issue. The handler is unregistered here, but never registered again afterwards.
Have you tried adding

transceiver.registerHandler(getHandler());

at the top of the else branch?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, I did. In this case the runnable seems to be executed to early. It throws the following exception during startup:

2021-03-30 20:25:55.371 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NoSuchMethodError: 'com.google.gson.JsonElement com.google.gson.JsonParser.parseString(java.lang.String)'
	at org.openhab.binding.keba.internal.handler.KeContactHandler.onData(KeContactHandler.java:239) ~[?:?]
	at org.openhab.binding.keba.internal.handler.KeContactHandler.pollingRunnable(KeContactHandler.java:190) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:834) [?:?]

In the solution provided by this PR, the Handler is never unregistered. Thereby it is also not required to register it again, once the connection is re-established.
Only drawback of the current solution: Thing status is not set to offline on communication errors.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Only drawback of the current solution: Thing status is not set to offline on communication errors.

As already mentioned: This is not really acceptable and we need to find a solution for it.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've updated the PR with a proper solution.
It changes the state to OFFLINE and back to ONLINE, when the communication is re-established.
My comment #10399 (comment) was crap. The error was caused by the JsonParser update openhab/openhab-core#2244 done on TRUNK while I tested the solution using OH3.0.1

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I updated the solution again :-|
The used UDP communication is not 100% reliable. Even in a switched network, some of the report polling requests do not receive a response. In order to avoid the sporadic OFFLINE/ONLINE events, I introduced isKebaReachable() in the polling runnable again. This function checks the presence of the TCP port (reliable). Only if the TCP port cannot be reached, the Binding goes OFFLINE. It tries to go ONLINE again in the next polling round. In order to change back to ONLINE isKebaReachable() must be successful AND data via UDP must be received.
On UDP timeouts, only a debug message is logged.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sounds sensible to me.

updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.COMMUNICATION_ERROR,
"An timeout occurred while polling the charging station");
} else {
if (getThing().getStatus() == ThingStatus.ONLINE) {
ByteBuffer response = cache.get(CACHE_REPORT_1);
if (response != null) {
onData(response);
}
ByteBuffer response = cache.get(CACHE_REPORT_1);
if (response == null) {
logger.debug("Missing response from Keba station for 'report 1'");
} else {
onData(response);
}

Thread.sleep(REPORT_INTERVAL);
Thread.sleep(REPORT_INTERVAL);

response = cache.get(CACHE_REPORT_2);
if (response != null) {
onData(response);
}
response = cache.get(CACHE_REPORT_2);
if (response == null) {
logger.debug("Missing response from Keba station for 'report 2'");
} else {
onData(response);
}

Thread.sleep(REPORT_INTERVAL);
Thread.sleep(REPORT_INTERVAL);

response = cache.get(CACHE_REPORT_3);
if (response != null) {
onData(response);
}
response = cache.get(CACHE_REPORT_3);
if (response == null) {
logger.debug("Missing response from Keba station for 'report 3'");
} else {
onData(response);
}

if (isReport100needed) {
Thread.sleep(REPORT_INTERVAL);
if (isReport100needed) {
Thread.sleep(REPORT_INTERVAL);

response = cache.get(CACHE_REPORT_100);
if (response != null) {
onData(response);
}
isReport100needed = false;
response = cache.get(CACHE_REPORT_100);
if (response == null) {
logger.debug("Missing response from Keba station for 'report 100'");
} else {
onData(response);
}
isReport100needed = false;
}
}
} catch (NumberFormatException | IOException e) {
logger.debug("An exception occurred while polling the KEBA KeContact '{}': {}", getThing().getUID(),
} catch (IOException e) {
logger.debug("An error occurred while polling the KEBA KeContact '{}': {}", getThing().getUID(),
e.getMessage(), e);
Thread.currentThread().interrupt();
updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.COMMUNICATION_ERROR,
"An exception occurred while while polling the charging station");
"An error occurred while polling the charging station");
} catch (InterruptedException e) {
logger.debug("Polling job has been interrupted for handler of thing '{}'.", getThing().getUID());
}
}

protected void onData(ByteBuffer byteBuffer) {
if (getThing().getStatus() != ThingStatus.ONLINE) {
updateStatus(ThingStatus.ONLINE);
}

String response = new String(byteBuffer.array(), 0, byteBuffer.limit());
response = StringUtils.chomp(response);

Expand Down