ModuleClient not able to send/receive messages over MQTT after EdgeHub restart with v1.19.0

[varunpuranik]

Description of the issue:

I have a setup on IoT Edge with 2 modules, both connecting to EdgeHub over MQTT. The routes have been set up so that one module generates messages and the other module receives messages. The communication goes on successfully, but if EdgeHub restarts (or is restarted), then both modules stop communicating (sending or receiving messages).

Points to note -

• This issue does not repro if the modules are connecting to the EdgeHub over AMQP
• This does not repro with the previous version of the Client SDK - Microsoft.Azure.Devices.Client v1.18.1. So it seems like a regression from the latest changes.

Here are the console logs from the client with the repro. Looks like the MqttTransportHandler is not properly closed before the retry operation.

_k-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 1001 at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.d48.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 167 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.Devices.Client.Transport.ProtocolRoutingDelegatingHandler.d5.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ProtocolRoutingDelegatingHandler.cs:line 69 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>cDisplayClass22_0.<b0>d.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ErrorDelegatingHandler.cs:line 152 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.d231.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ErrorDelegatingHandler.cs:line 163 --- End of inner exception stack trace --- at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<ExecuteWithErrorHandlingAsync>d__231.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ErrorDelegatingHandler.cs:line 184 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass36_0.<b0>d.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\RetryDelegatingHandler.cs:line 557)). 2019-01-08T15:58:49.1895572 [Microsoft-Azure-Devices-Device-Client-Exit] (RetryStrategyAdapter#15336788, ShouldRetry, RetryStrategyAdapter.ShouldRetry). 2019-01-08T15:58:59.1945264 [Microsoft-Azure-Devices-Device-Client-Info] (RetryDelegatingHandler#63162610, HandleDisconnect, Attempting to recover subscriptions.). 2019-01-08T15:58:59.1972568 [Microsoft-Azure-Devices-Device-Client-Enter] (ErrorDelegatingHandler#50942646, ExecuteWithErrorHandlingAsync, ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync). 2019-01-08T15:58:59.1998433 [Microsoft-Azure-Devices-Device-Client-Enter] (ProtocolRoutingDelegatingHandler#37578102, ProtocolRoutingDelegatingHandler.OpenAsync, (CancellationToken#33711845)). 2019-01-08T15:58:59.2027436 [Microsoft-Azure-Devices-Device-Client-Enter] (MqttTransportHandler#4032828, OpenAsync, (CancellationToken#33711845)). 2019-01-08T15:58:59.2365970 [Microsoft-Azure-Devices-Device-Client-Exit] (MqttTransportHandler#4032828, OpenAsync, CancellationToken#33711845). 2019-01-08T15:58:59.2684229 [Microsoft-Azure-Devices-Device-Client-Exit] (ProtocolRoutingDelegatingHandler#37578102, ProtocolRoutingDelegatingHandler.OpenAsync, CancellationToken#33711845). 2019-01-08T15:58:59.3450431 [Microsoft-Azure-Devices-Device-Client-ErrorMessage] (ErrorDelegatingHandler#50942646, ExecuteWithErrorHandlingAsync, Exception caught: DotNetty.Transport.Channels.ConnectException: LogError connecting to 127.0.0.1:8883 ---> System.Net.Sockets.SocketException: No connection could be made because the target machine actively refused it at DotNetty.Transport.Channels.Sockets.SocketChannelAsyncOperation.Validate() at DotNetty.Transport.Channels.Sockets.TcpSocketChannel.DoFinishConnect(SocketChannelAsyncOperation operation) at DotNetty.Transport.Channels.Sockets.AbstractSocketChannel.AbstractSocketUnsafe.FinishConnect(SocketChannelAsyncOperation operation) --- End of inner exception stack trace --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at DotNetty.Transport.Bootstrapping.Bootstrap.d15.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.<>cDisplayClass79_0.<b0>d.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 869 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.d65.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 535 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.EnsureValidState() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 1001 at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.d48.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 167 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.Devices.Client.Transport.ProtocolRoutingDelegatingHandler.d5.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ProtocolRoutingDelegatingHandler.cs:line 69 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>cDisplayClass22_0.<b0>d.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ErrorDelegatingHandler.cs:line 152 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.d231.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ErrorDelegatingHandler.cs:line 163). 2019-01-08T15:58:59.4669892 [Microsoft-Azure-Devices-Device-Client-Exit] (ErrorDelegatingHandler#50942646, ExecuteWithErrorHandlingAsync, ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync). 2019-01-08T15:58:59.5211814 [Microsoft-Azure-Devices-Device-Client-Enter] (RetryStrategyAdapter#15336788, RetryStrategyAdapter.ShouldRetry, (10, Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException: Transient network error occurred, please retry. ---> DotNetty.Transport.Channels.ConnectException: LogError connecting to 127.0.0.1:8883 ---> System.Net.Sockets.SocketException: No connection could be made because the target machine actively refused it at DotNetty.Transport.Channels.Sockets.SocketChannelAsyncOperation.Validate() at DotNetty.Transport.Channels.Sockets.TcpSocketChannel.DoFinishConnect(SocketChannelAsyncOperation operation) at DotNetty.Transport.Channels.Sockets.AbstractSocketChannel.AbstractSocketUnsafe.FinishConnect(SocketChannelAsyncOperation operation) --- End of inner exception stack trace --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at DotNetty.Transport.Bootstrapping.Bootstrap.<DoResolveAndConnectAsync>d__15.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.<>c__DisplayClass79_0.<b0>d.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 869 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.<OpenAsyncInternal>d__65.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 535 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.EnsureValidState() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 1001 at Microsoft.Azure.Devices.Client.Transport.Mqtt.MqttTransportHandler.<OpenAsync>d__48.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\Mqtt\MqttTransportHandler.cs:line 167 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.Devices.Client.Transport.ProtocolRoutingDelegatingHandler.<OpenAsync>d__5.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ProtocolRoutingDelegatingHandler.cs:line 69 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass22_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ErrorDelegatingHandler.cs:line 152 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.d23`1.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ErrorDelegatingHandler.cs:line 163 --- End of inner exception stack trace --- at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.d23`1.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\ErrorDelegatingHandler.cs:line 184 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass36_0.<b_0>d.MoveNext() in E:\workspace\azure-iot-sdk-csharp\iothub\device\src\Transport\RetryDelegatingHandler.cs:line 557)). 2019-01-08T15:58:59.6197618 [Microsoft-Azure-Devices-Device-Client-Exit] (RetryStrategyAdapter#15336788, ShouldRetry, RetryStrategyAdapter.ShouldRetry).

[jenoola]

Fixed in new release 1.20.0

[az-iot-builder-01]

@jenoola, thank you for your contribution to our open-sourced project! Please help us improve by filling out this 2-minute customer satisfaction survey