[mqtt.homie] handle exceptions parsing attributes (#12254)

fixes #10711

technically this code is in mqtt.generic, but it's only used by Homie.

in particular, if an incoming string doesn't match an enum, this will now
just ignore the value instead of raising an exception to be caught somewhere inside
of Hive MQTT, and eventually timing out and logging that mandatory topics weren't
received, instead of logging a pointer to the actual problem. this makes it so that
if there's a homie $datatype openhab doesn't understand (like duration), it will be
able to get to the point of just choosing a string channel

also did some minor debug logging cleanup for mqtt:
 * fixed a typo
 * when logging homie device name from the thing handler, use the config deviceid,
   since we likely don't have the attributes from MQTT yet

Signed-off-by: Cody Cutrer <cody@cutrer.us>

bundles/org.openhab.binding.mqtt.generic/src/main/java/org/openhab/binding/mqtt/generic/ChannelState.java

@@ -267,7 +267,7 @@ public class ChannelState implements MqttMessageSubscriber {
     }
 
     private void internalStop() {
-        logger.debug("Unsubscribed channel {} form topic: {}", this.channelUID, config.stateTopic);
+        logger.debug("Unsubscribed channel {} from topic: {}", this.channelUID, config.stateTopic);
         this.connection = null;
         this.channelStateUpdateListener = null;
         hasSubscribed = false;

bundles/org.openhab.binding.mqtt.generic/src/main/java/org/openhab/binding/mqtt/generic/mapping/SubscribeFieldToMQTTtopic.java

@@ -140,8 +140,10 @@ public class SubscribeFieldToMQTTtopic implements MqttMessageSubscriber {
         }
 
         String valueStr = new String(payload, StandardCharsets.UTF_8);
+        String originalValueStr = valueStr;
 
         // Check if there is a manipulation annotation attached to the field
+        try {
             final MQTTvalueTransform transform = field.getAnnotation(MQTTvalueTransform.class);
             Object value;
             if (transform != null) {
@@ -159,6 +161,14 @@ public class SubscribeFieldToMQTTtopic implements MqttMessageSubscriber {
             receivedValue = true;
             changeConsumer.fieldChanged(field, value);
             future.complete(null);
+        } catch (IllegalArgumentException e) {
+            if (mandatory) {
+                future.completeExceptionally(e);
+            } else {
+                logger.warn("Unable to interpret {} from topic {}", originalValueStr, topic);
+                future.complete(null);
+            }
+        }
     }
 
     void timeoutReached() {

bundles/org.openhab.binding.mqtt.generic/src/test/java/org/openhab/binding/mqtt/generic/mapping/MqttTopicClassMapperTests.java

@@ -211,4 +211,25 @@ public class MqttTopicClassMapperTests {
 
         assertThat(future.isDone(), is(true));
     }
+
+    @Test
+    public void ignoresInvalidEnum() throws IllegalArgumentException, IllegalAccessException {
+        final Attributes attributes = spy(new Attributes());
+
+        doAnswer(this::createSubscriberAnswer).when(attributes).createSubscriber(any(), any(), anyString(),
+                anyBoolean());
+
+        verify(connection, times(0)).subscribe(anyString(), any());
+
+        // Subscribe now to all fields
+        CompletableFuture<Void> future = attributes.subscribeAndReceive(connection, executor, "homie/device123",
+                fieldChangedObserver, 10);
+        assertThat(future.isDone(), is(true));
+
+        SubscribeFieldToMQTTtopic field = attributes.subscriptions.stream().filter(f -> f.field.getName() == "state")
+                .findFirst().get();
+        field.processMessage(field.topic, "garbage".getBytes());
+        verify(fieldChangedObserver, times(0)).attributeChanged(any(), any(), any(), any(), anyBoolean());
+        assertThat(attributes.state.toString(), is("unknown"));
+    }
 }

bundles/org.openhab.binding.mqtt.homie/src/main/java/org/openhab/binding/mqtt/homie/internal/handler/HomieThingHandler.java

@@ -98,8 +98,8 @@ public class HomieThingHandler extends AbstractMQTTThingHandler implements Devic
 
     @Override
     public void initialize() {
-        logger.debug("About to initialize Homie device {}", device.attributes.name);
         config = getConfigAs(HandlerConfiguration.class);
+        logger.debug("About to initialize Homie device {}", config.deviceid);
         if (config.deviceid.isEmpty()) {
             updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.CONFIGURATION_ERROR, "Object ID unknown");
             return;
@@ -119,7 +119,7 @@ public class HomieThingHandler extends AbstractMQTTThingHandler implements Devic
 
     @Override
     protected CompletableFuture<@Nullable Void> start(MqttBrokerConnection connection) {
-        logger.debug("About to start Homie device {}", device.attributes.name);
+        logger.debug("About to start Homie device {}", config.deviceid);
         if (connection.getQos() != 1) {
             // QoS 1 is required.
             logger.warn(
@@ -129,13 +129,13 @@ public class HomieThingHandler extends AbstractMQTTThingHandler implements Devic
         return device.subscribe(connection, scheduler, attributeReceiveTimeout).thenCompose((Void v) -> {
             return device.startChannels(connection, scheduler, attributeReceiveTimeout, this);
         }).thenRun(() -> {
-            logger.debug("Homie device {} fully attached (start)", device.attributes.name);
+            logger.debug("Homie device {} fully attached (start)", config.deviceid);
         });
     }
 
     @Override
     protected void stop() {
-        logger.debug("About to stop Homie device {}", device.attributes.name);
+        logger.debug("About to stop Homie device {}", config.deviceid);
         final ScheduledFuture<?> heartBeatTimer = this.heartBeatTimer;
         if (heartBeatTimer != null) {
             heartBeatTimer.cancel(false);
@@ -227,7 +227,7 @@ public class HomieThingHandler extends AbstractMQTTThingHandler implements Devic
         final MqttBrokerConnection connection = this.connection;
         if (connection != null) {
             device.startChannels(connection, scheduler, attributeReceiveTimeout, this).thenRun(() -> {
-                logger.debug("Homie device {} fully attached (accept)", device.attributes.name);
+                logger.debug("Homie device {} fully attached (accept)", config.deviceid);
             });
         }
     }