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.

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

[velux] Stability checks and improvements in slip io #10119

Merged
merged 4 commits into from
Mar 26, 2021
Merged
Show file tree
Hide file tree
Changes from 3 commits
Commits
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
2 changes: 1 addition & 1 deletion bundles/org.openhab.binding.velux/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ In addition there are some optional Configuration Parameters.
|-------------------------|------------------|:--------:|--------------------------------------------------------------|
| ipAddress | | Yes | Hostname or address for accessing the Velux Bridge. |
| password | velux123 | Yes | Password for authentication against the Velux Bridge.(\*\*) |
| timeoutMsecs | 2000 | No | Communication timeout in milliseconds. |
| timeoutMsecs | 3000 | No | Communication timeout in milliseconds. |
| protocol | slip | No | Underlying communication protocol (http/https/slip). |
| tcpPort | 51200 | No | TCP port (80 or 51200) for accessing the Velux Bridge. |
| retries | 5 | No | Number of retries during I/O. |
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,10 @@
import java.util.Queue;
import java.util.concurrent.Callable;
import java.util.concurrent.ConcurrentLinkedQueue;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;

import org.eclipse.jdt.annotation.NonNullByDefault;
import org.eclipse.jdt.annotation.Nullable;
Expand All @@ -49,6 +51,7 @@ class DataInputStreamWithTimeout implements Closeable {

// special character that marks the first and last byte of a slip message
private static final byte SLIP_MARK = (byte) 0xc0;
private static final byte SLIP_PROT = 0;

private final Logger logger = LoggerFactory.getLogger(DataInputStreamWithTimeout.class);

Expand All @@ -63,9 +66,19 @@ class DataInputStreamWithTimeout implements Closeable {
private class Poller implements Callable<Boolean> {

private boolean interrupted = false;
private Future<Boolean> pollerFinished;

public Poller(ExecutorService executor) {
logger.trace("Poller: created");
pollerFinished = executor.submit(this);
}

public void interrupt() {
interrupted = true;
try {
pollerFinished.get();
} catch (InterruptedException | ExecutionException e) {
}
}

/**
Expand All @@ -75,34 +88,47 @@ public void interrupt() {
*/
@Override
public Boolean call() throws Exception {
logger.trace("Poller.call(): started");
Copy link
Member

Choose a reason for hiding this comment

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

I'm a bit in doubt about these log statements in the light of https://www.openhab.org/docs/developer/guidelines.html#f-logging

If there are no other complaints, I would say we should merge 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.

Hi @martinvw I do understand that the developer guideline says one should not use the logger to replace the debugger. But our problem is that the Velux bridge has an undocumented weakness whereby it sometimes (very infrequently) falls into a "zombie state" that requires the bridge to be physically power cycled. Users of the binding have been trying to track down the exact circumstances when such zombie states occur, but it is very infrequent, so I can't expect normal users to be trying to run the binding in a debugger. That is the reason why I added these logger.trace() commands instead. So I do hope you that can allow this please.

byte[] buf = new byte[BUFFER_SIZE];
byte byt;
int byt;
int i = 0;

// clean start, no exception, empty queue
pollException = null;
slipMessageQueue.clear();

// loop forever or until internally or externally interrupted
while ((!interrupted) && (!Thread.interrupted())) {
// loop forever or until externally interrupted
while (!Thread.interrupted()) {
try {
buf[i] = byt = (byte) inputStream.read();
if (byt == SLIP_MARK) {
if (i > 0) {
// the minimal slip message is 7 bytes [MM PP LL CC CC KK MM]
if ((i > 5) && (buf[0] == SLIP_MARK)) {
slipMessageQueue.offer(Arrays.copyOfRange(buf, 0, i + 1));
if (slipMessageQueue.size() > QUEUE_SIZE) {
logger.warn("pollRunner() => slip message queue overflow => PLEASE REPORT !!");
slipMessageQueue.poll();
}
if (interrupted) {
// fully flush the input buffer
inputStream.readAllBytes();
break;
}
byt = inputStream.read();
if (byt < 0) {
// end of stream is OK => keep on polling
continue;
}
buf[i] = (byte) byt;
if ((i > 0) && (buf[i] == SLIP_MARK)) {
// the minimal slip message is 7 bytes [MM PP LL CC CC KK MM]
if ((i > 5) && (buf[0] == SLIP_MARK) && (buf[1] == SLIP_PROT)) {
slipMessageQueue.offer(Arrays.copyOfRange(buf, 0, i + 1));
if (slipMessageQueue.size() > QUEUE_SIZE) {
logger.warn("Poller.call(): slip message queue overflow => PLEASE REPORT !!");
slipMessageQueue.poll();
}
i = 0;
} else {
logger.warn("Poller.call(): non slip messsage discarded => PLEASE REPORT !!");
buf[0] = SLIP_MARK;
continue;
i = 1;
}
continue;
}
if (++i >= BUFFER_SIZE) {
logger.warn("Poller.call(): input buffer overrun => PLEASE REPORT !!");
i = 0;
}
} catch (SocketTimeoutException e) {
Expand All @@ -112,11 +138,12 @@ public Boolean call() throws Exception {
// any other exception => stop polling
String msg = e.getMessage();
pollException = msg != null ? msg : "Generic IOException";
logger.debug("pollRunner() stopping '{}'", pollException);
logger.debug("Poller.call(): stopping '{}'", pollException);
break;
}
}

logger.trace("Poller.call(): ended");
// we only get here if shutdown or an error occurs so free ourself so we can be recreated again
pollRunner = null;
return true;
Expand Down Expand Up @@ -210,11 +237,9 @@ public void flush() {
* Start the polling task
*/
private void startPolling() {
Poller pollRunner = this.pollRunner;
if (pollRunner == null) {
logger.trace("startPolling()");
pollRunner = this.pollRunner = new Poller();
executor.submit(pollRunner);
pollRunner = new Poller(executor);
}
}

Expand All @@ -226,7 +251,6 @@ private void stopPolling() {
if (pollRunner != null) {
logger.trace("stopPolling()");
pollRunner.interrupt();
this.pollRunner = null;
}
executor.shutdown();
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -43,11 +43,11 @@
<!-- Velux Bridge factory default -->
<default>velux123</default>
</parameter>
<parameter name="timeoutMsecs" type="integer" min="500" step="1" max="5000">
<parameter name="timeoutMsecs" type="integer" min="500" step="1" max="10000">
<label>@text/config.velux.bridge.timeoutMsecs.label</label>
<description>@text/config.velux.bridge.timeoutMsecs.description</description>
<required>false</required>
<default>2000</default>
<default>3000</default>
<advanced>true</advanced>
</parameter>
<parameter name="retries" type="integer" min="0" step="1" max="10">
Expand Down