[insteon] Fix device request failure handling (#18087)

Signed-off-by: Jeremy Setton <jeremy.setton@gmail.com>

bundles/org.openhab.binding.insteon/src/main/java/org/openhab/binding/insteon/internal/device/BaseDevice.java

@@ -43,6 +43,7 @@ public abstract class BaseDevice<@NonNull T extends DeviceAddress, @NonNull S ex
         implements Device {
     private static final int DIRECT_ACK_TIMEOUT = 6000; // in milliseconds
     private static final int REQUEST_QUEUE_TIMEOUT = 30000; // in milliseconds
+    private static final int FAILED_REQUEST_THRESHOLD = 5;
 
     protected static enum DeviceStatus {
         INITIALIZED,
@@ -63,6 +64,7 @@ public abstract class BaseDevice<@NonNull T extends DeviceAddress, @NonNull S ex
     private Map<Msg, DeviceRequest> requestQueueHash = new HashMap<>();
     private @Nullable DeviceFeature featureQueried;
     private long pollInterval = -1L; // in milliseconds
+    private volatile int failedRequestCount = 0;
     private volatile long lastRequestQueued = 0L;
     private volatile long lastRequestSent = 0L;
 
@@ -145,6 +147,10 @@ public abstract class BaseDevice<@NonNull T extends DeviceAddress, @NonNull S ex
         }
     }
 
+    public boolean isResponding() {
+        return failedRequestCount < FAILED_REQUEST_THRESHOLD;
+    }
+
     public void setModem(@Nullable InsteonModem modem) {
         this.modem = modem;
     }
@@ -403,10 +409,8 @@ public abstract class BaseDevice<@NonNull T extends DeviceAddress, @NonNull S ex
     public void handleMessage(Msg msg) {
         getFeatures().stream().filter(feature -> feature.handleMessage(msg)).findFirst().ifPresent(feature -> {
             logger.trace("handled reply of direct for {}", feature.getName());
-            // mark feature queried as processed and answered
+            // notify feature queried was answered
-            setFeatureQueried(null);
+            featureQueriedAnswered(feature);
-            feature.setQueryMessage(null);
-            feature.setQueryStatus(QueryStatus.QUERY_ANSWERED);
         });
     }
 
@@ -527,9 +531,8 @@ public abstract class BaseDevice<@NonNull T extends DeviceAddress, @NonNull S ex
                         return now + 1000L; // retry in 1000 ms
                     }
                     logger.debug("gave up waiting for {} query to be sent to {}", feature.getName(), address);
-                    // reset feature queried as never queried
+                    // notify feature queried failed
-                    feature.setQueryMessage(null);
+                    featureQueriedFailed(feature);
-                    feature.setQueryStatus(QueryStatus.NEVER_QUERIED);
                     break;
                 case QUERY_SENT:
                 case QUERY_ACKED:
@@ -541,20 +544,61 @@ public abstract class BaseDevice<@NonNull T extends DeviceAddress, @NonNull S ex
                         return now + 500L; // retry in 500 ms
                     }
                     logger.debug("gave up waiting for {} query reply from {}", feature.getName(), address);
-                    // reset feature queried as never queried
+                    // notify feature queried failed
-                    feature.setQueryMessage(null);
+                    featureQueriedFailed(feature);
-                    feature.setQueryStatus(QueryStatus.NEVER_QUERIED);
                     break;
                 default:
                     logger.debug("unexpected feature {} query status {} for {}", feature.getName(), queryStatus,
                             address);
-            }
+                    // reset feature queried
-            // reset feature queried otheriwse
                     setFeatureQueried(null);
             }
+        }
         return 0L;
     }
 
+    /**
+     * Notifies that the feature queried was answered
+     *
+     * @param feature the feature queried
+     */
+    protected void featureQueriedAnswered(DeviceFeature feature) {
+        // store current failed request count
+        int prevCount = failedRequestCount;
+        // reset failed request count
+        failedRequestCount = 0;
+        // mark feature queried as processed and answered
+        setFeatureQueried(null);
+        feature.setQueryMessage(null);
+        feature.setQueryStatus(QueryStatus.QUERY_ANSWERED);
+        // notify status changed if failed request count was above threshold
+        if (prevCount >= FAILED_REQUEST_THRESHOLD) {
+            statusChanged();
+        }
+    }
+
+    /**
+     * Notifies that the feature queried failed
+     *
+     * @param feature the feature queried
+     */
+    protected void featureQueriedFailed(DeviceFeature feature) {
+        // increase failed request count
+        failedRequestCount++;
+        // mark feature queried as processed and never queried
+        setFeatureQueried(null);
+        feature.setQueryMessage(null);
+        feature.setQueryStatus(QueryStatus.NEVER_QUERIED);
+        // poll feature again if device is responding
+        if (isResponding()) {
+            feature.doPoll(0L);
+        }
+        // notify status changed if failed request count at threshold
+        if (failedRequestCount == FAILED_REQUEST_THRESHOLD) {
+            statusChanged();
+        }
+    }
+
     /**
      * Notifies that a message request was replied for this device
      *
@@ -564,10 +608,17 @@ public abstract class BaseDevice<@NonNull T extends DeviceAddress, @NonNull S ex
     public void requestReplied(Msg msg) {
         DeviceFeature feature = getFeatureQueried();
         if (feature != null && feature.isMyReply(msg)) {
-            // mark feature queried as processed and answered
+            if (msg.isReplyNack()) {
-            setFeatureQueried(null);
+                logger.debug("got a reply nack msg: {}", msg);
-            feature.setQueryMessage(null);
+                // notify feature queried failed
-            feature.setQueryStatus(QueryStatus.QUERY_ANSWERED);
+                featureQueriedFailed(feature);
+            } else if (!msg.isInsteon()) {
+                // notify feature queried was answered
+                featureQueriedAnswered(feature);
+            } else {
+                // mark feature queried as acked
+                feature.setQueryStatus(QueryStatus.QUERY_ACKED);
+            }
         }
     }
 
@@ -588,6 +639,18 @@ public abstract class BaseDevice<@NonNull T extends DeviceAddress, @NonNull S ex
         }
     }
 
+    /**
+     * Notifies that the status has changed for this device
+     */
+    public void statusChanged() {
+        logger.trace("status for {} has changed", address);
+        @Nullable
+        S handler = getHandler();
+        if (handler != null) {
+            handler.updateStatus();
+        }
+    }
+
     /**
      * Refreshes this device
      */

bundles/org.openhab.binding.insteon/src/main/java/org/openhab/binding/insteon/internal/device/InsteonDevice.java

@@ -66,7 +66,6 @@ import org.openhab.core.types.UnDefType;
 public class InsteonDevice extends BaseDevice<InsteonAddress, InsteonDeviceHandler> {
     private static final int BCAST_STATE_TIMEOUT = 2000; // in milliseconds
     private static final int DEFAULT_HEARTBEAT_TIMEOUT = 1440; // in minutes
-    private static final int FAILED_MSG_COUNT_THRESHOLD = 5;
 
     private InsteonEngine engine = InsteonEngine.UNKNOWN;
     private LinkDB linkDB;
@@ -76,7 +75,6 @@ public class InsteonDevice extends BaseDevice<InsteonAddress, InsteonDeviceHandl
     private Map<Msg, DeviceRequest> deferredQueueHash = new HashMap<>();
     private Map<Byte, Long> lastBroadcastReceived = new HashMap<>();
     private Map<Integer, GroupMessageStateMachine> groupState = new HashMap<>();
-    private volatile int failedMsgCount = 0;
     private volatile long lastMsgReceived = 0L;
 
     public InsteonDevice() {
@@ -145,10 +143,6 @@ public class InsteonDevice extends BaseDevice<InsteonAddress, InsteonDeviceHandl
         return Optional.ofNullable(getFeature(type, group)).map(DeviceFeature::getState).orElse(null);
     }
 
-    public boolean isResponding() {
-        return failedMsgCount < FAILED_MSG_COUNT_THRESHOLD;
-    }
-
     public boolean isBatteryPowered() {
         return getFlag("batteryPowered", false);
     }
@@ -444,35 +438,21 @@ public class InsteonDevice extends BaseDevice<InsteonAddress, InsteonDeviceHandl
             }
             return;
         }
-        // store current responding state
-        boolean isPrevResponding = isResponding();
         // handle message depending if failure report or not
         if (msg.isFailureReport()) {
             getFeatures().stream().filter(feature -> feature.isMyDirectAckOrNack(msg)).findFirst()
                     .ifPresent(feature -> {
                         logger.debug("got a failure report reply of direct for {}", feature.getName());
-                        // increase failed message counter
+                        // notify feature queried failed
-                        failedMsgCount++;
+                        featureQueriedFailed(feature);
-                        // mark feature queried as processed and never queried
-                        setFeatureQueried(null);
-                        feature.setQueryMessage(null);
-                        feature.setQueryStatus(QueryStatus.NEVER_QUERIED);
-                        // poll feature again if device is responding
-                        if (isResponding()) {
-                            feature.doPoll(0L);
-                        }
                     });
         } else {
             // update non-status features
             getFeatures().stream().filter(feature -> !feature.isStatusFeature() && feature.handleMessage(msg))
                     .findFirst().ifPresent(feature -> {
                         logger.trace("handled reply of direct for {}", feature.getName());
-                        // reset failed message counter
+                        // notify feature queried was answered
-                        failedMsgCount = 0;
+                        featureQueriedAnswered(feature);
-                        // mark feature queried as processed and answered
-                        setFeatureQueried(null);
-                        feature.setQueryMessage(null);
-                        feature.setQueryStatus(QueryStatus.QUERY_ANSWERED);
                     });
             // update all status features (e.g. device last update time)
             getFeatures().stream().filter(DeviceFeature::isStatusFeature)
@@ -485,10 +465,6 @@ public class InsteonDevice extends BaseDevice<InsteonAddress, InsteonDeviceHandl
             long delay = msg.isAllLinkBroadcast() && !msg.isAllLinkSuccessReport() && !msg.isReplayed() ? 1500L : 0L;
             doPoll(delay);
         }
-        // notify if responding state changed
-        if (isPrevResponding != isResponding()) {
-            statusChanged();
-        }
     }
 
     /**
@@ -906,25 +882,6 @@ public class InsteonDevice extends BaseDevice<InsteonAddress, InsteonDeviceHandl
         }
     }
 
-    /**
-     * Notifies that a message request was replied for this device
-     *
-     * @param msg the message received
-     */
-    @Override
-    public void requestReplied(Msg msg) {
-        DeviceFeature feature = getFeatureQueried();
-        if (feature != null && feature.isMyReply(msg)) {
-            if (msg.isReplyAck()) {
-                // mark feature queried as acked
-                feature.setQueryStatus(QueryStatus.QUERY_ACKED);
-            } else {
-                logger.debug("got a reply nack msg: {}", msg);
-                super.requestReplied(msg);
-            }
-        }
-    }
-
     /**
      * Notifies that the link db has been updated for this device
      */
@@ -966,18 +923,6 @@ public class InsteonDevice extends BaseDevice<InsteonAddress, InsteonDeviceHandl
         }
     }
 
-    /**
-     * Notifies that the status has changed for this device
-     */
-    public void statusChanged() {
-        logger.trace("status for {} has changed", address);
-
-        InsteonDeviceHandler handler = getHandler();
-        if (handler != null) {
-            handler.updateStatus();
-        }
-    }
-
     /**
      * Factory method for creating a InsteonDevice from a device address, modem and cache
      *

bundles/org.openhab.binding.insteon/src/main/java/org/openhab/binding/insteon/internal/handler/InsteonBaseThingHandler.java

@@ -330,8 +330,6 @@ public abstract class InsteonBaseThingHandler extends BaseThingHandler implement
         updateStatus();
     }
 
-    public abstract void updateStatus();
-
     public void updateProperties(Device device) {
         Map<String, String> properties = editProperties();
 

bundles/org.openhab.binding.insteon/src/main/java/org/openhab/binding/insteon/internal/handler/InsteonThingHandler.java

@@ -91,4 +91,9 @@ public interface InsteonThingHandler extends ThingHandler {
      * Refreshes the thing
      */
     public void refresh();
+
+    /**
+     * Updates the thing status
+     */
+    public void updateStatus();
 }