feat(iot-dev): Allow users to opt-out of treating routine disconnects…

… as errors (#1740)

SAS authorized MQTT connections have routine disconnects that some users don't want treated as errors or warnings in logs. This adds a flag they can set in client options to opt out of the current default.

Also defer creating a multiplexing retry policy until a multiplexing client is created to avoid unnecessary logs

Like #1739 but requiring opting in to logging these routine disconnects opt-in

iothub/device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/ClientConfiguration.java

@@ -91,6 +91,8 @@ public final class ClientConfiguration
 
     private boolean useIdentifiableThreadNames = true;
 
+    private boolean logRoutineDisconnectsAsErrors = true;
+
     private IotHubAuthenticationProvider authenticationProvider;
 
     /**
@@ -223,6 +225,7 @@ private void setClientOptionValues(ClientOptions clientOptions)
         this.threadNamePrefix = clientOptions != null ? clientOptions.getThreadNamePrefix() : null;
         this.threadNameSuffix = clientOptions != null ? clientOptions.getThreadNameSuffix() : null;
         this.useIdentifiableThreadNames = clientOptions == null || clientOptions.isUsingIdentifiableThreadNames();
+        this.logRoutineDisconnectsAsErrors = clientOptions == null || clientOptions.isLoggingRoutineDisconnectsAsErrors();
 
         if (proxySettings != null)
         {
@@ -646,6 +649,12 @@ public boolean isUsingIdentifiableThreadNames()
         return this.useIdentifiableThreadNames;
     }
 
+    public boolean isLoggingRoutineDisconnectsAsErrors()
+    {
+        // Using a manually written method here to override the name that Lombok would have given it
+        return this.logRoutineDisconnectsAsErrors;
+    }
+
     /**
      * Sets the device operation timeout
      * @param timeout the amount of time, in milliseconds, that a given device operation can last before expiring

iothub/device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/ClientOptions.java

@@ -167,10 +167,29 @@ public final class ClientOptions
     @Builder.Default
     private final boolean useIdentifiableThreadNames = true;
 
+    /**
+     * This option allows for routine disconnect events (such as expired SAS token disconnects
+     * when connecting over MQTT or MQTT_WS) to be logged at debug levels as opposed to error or
+     * warn levels. By default, these routine disconnects are logged at error or warn levels.
+     *
+     * Note that there is a degree of speculation involved when this client labels a disconnect
+     * as a routine disconnect. Generally, if the client is disconnected when the previous SAS
+     * token was expired, it will assume it was a routine disconnect. However, there may be
+     * legitimate disconnects due to network errors that could be mislabeled and not logged
+     * at a warning or error level if they occur around the time that a routine error is expected.
+     */
+    @Builder.Default
+    private final boolean logRoutineDisconnectsAsErrors = true;
 
     public boolean isUsingIdentifiableThreadNames()
     {
         // Using a manually written method here to override the name that Lombok would have given it
         return this.useIdentifiableThreadNames;
     }
+
+    public boolean isLoggingRoutineDisconnectsAsErrors()
+    {
+        // Using a manually written method here to override the name that Lombok would have given it
+        return this.logRoutineDisconnectsAsErrors;
+    }
 }

iothub/device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/transport/IotHubTransport.java

@@ -72,7 +72,7 @@ public class IotHubTransport implements IotHubListener
     private IotHubConnectionStatusChangeCallback multiplexingStateCallback;
     private Object multiplexingStateCallbackContext;
 
-    private RetryPolicy multiplexingRetryPolicy = new ExponentialBackoffWithJitter();
+    private RetryPolicy multiplexingRetryPolicy;
 
     // Callback for notifying the DeviceIO layer of connection status change events. The deviceIO layer
     // should stop spawning send/receive threads when this layer is disconnected or disconnected retrying
@@ -179,6 +179,7 @@ public IotHubTransport(
         this.connectionStatus = IotHubConnectionStatus.DISCONNECTED;
         this.deviceIOConnectionStatusChangeCallback = deviceIOConnectionStatusChangeCallback;
         this.isMultiplexing = true;
+        this.multiplexingRetryPolicy = new ExponentialBackoffWithJitter();
         this.keepAliveInterval = keepAliveInterval;
         this.sendInterval = sendInterval;
         this.useIdentifiableThreadNames = useIdentifiableThreadNames;
@@ -1643,7 +1644,18 @@ private void updateStatus(IotHubConnectionStatus newConnectionStatus, IotHubConn
         {
             if (throwable == null)
             {
-                log.debug("Updating transport status to new status {} with reason {}", newConnectionStatus, reason);
+                log.info("Updating transport status to new status {} with reason {}", newConnectionStatus, reason);
+            }
+            else if (this.getDefaultConfig() != null
+                    && !this.getDefaultConfig().isLoggingRoutineDisconnectsAsErrors()
+                    && newConnectionStatus == IotHubConnectionStatus.DISCONNECTED_RETRYING
+                    && reason == IotHubConnectionStatusChangeReason.EXPIRED_SAS_TOKEN
+                    && (protocol == IotHubClientProtocol.MQTT || protocol == IotHubClientProtocol.MQTT_WS))
+            {
+                // This is a special case where the user has opted out of treating the routine
+                // MQTT/MQTT_WS SAS token disconnects as an error for logging purposes. As such,
+                // log at the debug level instead of warn or error level.
+                log.info("Updating transport status to new status {} with reason {}", newConnectionStatus, reason);
             }
             else
             {

iothub/device/iot-device-client/src/main/java/com/microsoft/azure/sdk/iot/device/transport/mqtt/Mqtt.java

@@ -327,25 +327,24 @@ public IotHubTransportMessage receive()
     @Override
     public void connectionLost(Throwable throwable)
     {
-        log.warn("Mqtt connection lost", throwable);
-
         this.disconnect();
 
-        if (this.listener != null)
+        TransportException transportException;
+        if (throwable instanceof MqttException)
         {
-            TransportException transportException;
-            if (throwable instanceof MqttException)
-            {
-                transportException = PahoExceptionTranslator.convertToMqttException((MqttException) throwable, "Mqtt connection lost");
-                log.trace("Mqtt connection loss interpreted into transport exception", throwable);
-            }
-            else
-            {
-                transportException = new TransportException(throwable);
-            }
-
-            this.listener.onConnectionLost(transportException, this.connectionId);
+            transportException = PahoExceptionTranslator.convertToMqttException((MqttException) throwable, "Mqtt connection lost");
+            log.trace("Mqtt connection loss interpreted into transport exception", throwable);
+        }
+        else
+        {
+            transportException = new TransportException(throwable);
         }
+
+        // Logging this at a debug level instead of warning or error because the IoThubTransport
+        // level will log it to warning or error if applicable.
+        log.debug("Mqtt connection lost", transportException);
+
+        this.listener.onConnectionLost(transportException, this.connectionId);
     }
 
     /**