Edge stops sending messages to upstream after comming back from disconnected state.

Expected Behavior

IoT Edge after restoring the connection to Internet should push all cached messages and send them upstream and send all new messages live to upstream.

Current Behavior

Edge after entering disconnected state and then when going back to connected state (after internet connection is restored) keeps caching messages and is not pushing them upstream. After restarting the edgeHub edge pushes all cached messages and operates normally but the restart is required.

Steps to Reproduce

Cut Internet connection for a couple of minutes.
Restore Internet connection.
Edge will stop sending messages even after the connection is restored.
After restarting EdgeHub it starts to operate normally.

Context (Environment)

Device Information

Host OS Ubuntu 22.04
Architecture amd64
Container OS Linux containers

Runtime Versions

aziot-edged 1.4.16
Edge Agent 1.4.18
Edge Hub 1.4.18
Docker/Moby: 20.10.25+azure-2

Logs

edge-agent logs

``` <6> 2023-09-26 06:11:39.251 +00:00 [INF] - Starting compaction of stores <6> 2023-09-26 06:11:39.251 +00:00 [INF] - Starting compaction of store moduleState <6> 2023-09-26 06:11:39.251 +00:00 [INF] - Starting compaction of store default <6> 2023-09-26 06:11:39.251 +00:00 [INF] - Starting compaction of store deploymentConfig <6> 2023-09-26 06:12:30.893 +00:00 [INF] - Starting periodic operation refresh twin config... <6> 2023-09-26 06:12:30.955 +00:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 71 and reported properties version 248. <6> 2023-09-26 06:12:30.957 +00:00 [INF] - Successfully completed periodic operation refresh twin config <6> 2023-09-26 07:12:30.955 +00:00 [INF] - Starting periodic operation refresh twin config... <6> 2023-09-26 07:12:31.006 +00:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 71 and reported properties version 248. <6> 2023-09-26 07:12:31.007 +00:00 [INF] - Successfully completed periodic operation refresh twin config <6> 2023-09-26 07:16:35.065 +00:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 71 and reported properties version 248. <6> 2023-09-26 07:18:13.065 +00:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 71 and reported properties version 248. <6> 2023-09-26 08:11:39.252 +00:00 [INF] - Starting compaction of stores <6> 2023-09-26 08:11:39.252 +00:00 [INF] - Starting compaction of store moduleState <6> 2023-09-26 08:11:39.252 +00:00 [INF] - Starting compaction of store default <6> 2023-09-26 08:11:39.252 +00:00 [INF] - Starting compaction of store deploymentConfig <6> 2023-09-26 08:12:31.006 +00:00 [INF] - Starting periodic operation refresh twin config... <6> 2023-09-26 08:12:31.033 +00:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 71 and reported properties version 248. <6> 2023-09-26 08:12:31.035 +00:00 [INF] - Successfully completed periodic operation refresh twin config ```

edge-hub logs

``` <6> 2023-09-26 07:07:11.285 +00:00 [INF] - Transport closed. CorrelationId 1336c232 <6> 2023-09-26 07:07:11.291 +00:00 [INF] - "Request finished HTTP/1.1 GET https://edge_ip/$iothub/websocket - - - 101 - - 3899813.5647ms" <6> 2023-09-26 07:07:11.298 +00:00 [INF] - Closing device proxy for device Id edge_name/edgeblob <6> 2023-09-26 07:07:11.318 +00:00 [INF] - Closing receiver in cloud proxy 6b099344-32fc-4bfd-a18f-a9aff6c72a24 for edge_name/edgeblob <6> 2023-09-26 07:07:11.319 +00:00 [INF] - Closed cloud proxy 6b099344-32fc-4bfd-a18f-a9aff6c72a24 for edge_name/edgeblob <6> 2023-09-26 07:07:11.319 +00:00 [INF] - Device connection removed for device edge_name/edgeblob <6> 2023-09-26 07:07:11.493 +00:00 [INF] - "Request starting HTTP/1.1 GET https://edge_ip/$iothub/websocket - -" <6> 2023-09-26 07:07:11.493 +00:00 [INF] - Processed MQTT WebSocket request with CorrelationId 7b7d24a8-85fc-47d3-b007-06e84d8a9904 <6> 2023-09-26 07:07:11.639 +00:00 [INF] - Updated reported properties for edge_name/$edgeHub <6> 2023-09-26 07:07:11.754 +00:00 [INF] - Client edge_name/edgeblob in device scope authenticated locally. <6> 2023-09-26 07:07:11.754 +00:00 [INF] - Successfully generated identity for clientId edge_name/edgeblob and username edge_ip/edge_name/edgeblob/?api-version=2018-06-30&DeviceClientType=.NET%2F1.20.3%20%28.NET%20Core%203.1.21%3B%20Linux%205.4.0-128-generic%20%23144-Ubuntu%20SMP%20Tue%20Sep%2020%2011%3A00%3A04%20UTC%202022%3B%20X64%29%20iot-edge-blob-storage%2F1.4.1.0%20%28UploadOff%29 <6> 2023-09-26 07:07:11.754 +00:00 [INF] - "ClientAuthenticated, edge_name/edgeblob, 5057ed06" <6> 2023-09-26 07:07:11.754 +00:00 [INF] - New device connection for device edge_name/edgeblob <6> 2023-09-26 07:07:11.754 +00:00 [INF] - Client edge_name/edgeblob connected to edgeHub, processing existing subscriptions. <6> 2023-09-26 07:07:11.755 +00:00 [INF] - Bind device proxy for device edge_name/edgeblob <6> 2023-09-26 07:07:11.755 +00:00 [INF] - Binding message channel for device Id edge_name/edgeblob <6> 2023-09-26 07:07:11.756 +00:00 [INF] - Attempting to connect to IoT Hub for client edge_name/edgeblob via AMQP... <6> 2023-09-26 07:07:11.758 +00:00 [INF] - Processing pending subscriptions for edge_name/edgeblob <6> 2023-09-26 07:07:11.760 +00:00 [INF] - Processing subscriptions TwinResponse, DesiredPropertyUpdates for client edge_name/edgeblob. <6> 2023-09-26 07:07:11.762 +00:00 [INF] - Set subscriptions from session state for edge_name/edgeblob <6> 2023-09-26 07:07:11.765 +00:00 [INF] - Processing subscriptions TwinResponse, DesiredPropertyUpdates for client edge_name/edgeblob. <6> 2023-09-26 07:07:11.765 +00:00 [INF] - Set subscriptions from session state for edge_name/edgeblob <6> 2023-09-26 07:07:11.829 +00:00 [INF] - Cloud connection for edge_name/edgeblob is True <6> 2023-09-26 07:07:11.829 +00:00 [INF] - Connection status for edge_name/edgeblob changed to ConnectionEstablished <6> 2023-09-26 07:07:11.829 +00:00 [INF] - Client edge_name/edgeblob connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:07:11.829 +00:00 [INF] - Skipping edge_name/edgeblob for subscription processing, as it is currently being processed. <6> 2023-09-26 07:07:11.829 +00:00 [INF] - Created cloud proxy for client edge_name/edgeblob via AMQP, with client operation timeout 20 seconds. <6> 2023-09-26 07:07:11.829 +00:00 [INF] - Initialized cloud proxy 4feae539-8b36-4856-9034-49fe3585dd29 for edge_name/edgeblob <6> 2023-09-26 07:07:11.829 +00:00 [INF] - Created cloud connection for client edge_name/edgeblob <6> 2023-09-26 07:07:11.854 +00:00 [INF] - Processing pending subscriptions for edge_name/edgeblob <6> 2023-09-26 07:07:11.855 +00:00 [INF] - Processing pending subscriptions for edge_name/edgeblob <6> 2023-09-26 07:07:11.855 +00:00 [INF] - Processing pending subscriptions for edge_name/edgeblob <6> 2023-09-26 07:07:16.874 +00:00 [INF] - Updated reported properties for edge_name/$edgeHub <6> 2023-09-26 07:12:11.259 +00:00 [INF] - Entering periodic task to reauthenticate connected clients <6> 2023-09-26 07:14:24.701 +00:00 [INF] - Starting periodic operation Get EdgeHub config... <6> 2023-09-26 07:14:37.370 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint iothub <6> 2023-09-26 07:14:37.403 +00:00 [INF] - Cleaned up 71 messages from queue for endpoint iothub and 71 messages from message store. <6> 2023-09-26 07:14:37.403 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint edge_name/customemodule6/SensorStatus <6> 2023-09-26 07:14:37.405 +00:00 [INF] - Cleaned up 0 messages from queue for endpoint edge_name/customemodule6/SensorStatus and 0 messages from message store. <6> 2023-09-26 07:14:37.405 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint edge_name/customemodule1/SensorMsg <6> 2023-09-26 07:14:37.825 +00:00 [INF] - Cleaned up 3226 messages from queue for endpoint edge_name/customemodule1/SensorMsg and 1 messages from message store. <6> 2023-09-26 07:14:37.825 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint edge_name/edgeSpotterLogger/Spotter <6> 2023-09-26 07:14:38.264 +00:00 [INF] - Cleaned up 3226 messages from queue for endpoint edge_name/edgeSpotterLogger/Spotter and 3225 messages from message store. <6> 2023-09-26 07:14:38.264 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint edge_name/customemodule3/HandlerData <6> 2023-09-26 07:14:38.264 +00:00 [INF] - Cleaned up 0 messages from queue for endpoint edge_name/customemodule3/HandlerData and 0 messages from message store. <6> 2023-09-26 07:14:38.264 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint edge_name/customemodule2/SensorData <6> 2023-09-26 07:14:38.582 +00:00 [INF] - Cleaned up 2837 messages from queue for endpoint edge_name/customemodule2/SensorData and 2 messages from message store. <6> 2023-09-26 07:14:38.582 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint edge_name/customemodule4/stoppage <6> 2023-09-26 07:14:38.584 +00:00 [INF] - Cleaned up 13 messages from queue for endpoint edge_name/customemodule4/stoppage and 13 messages from message store. <6> 2023-09-26 07:14:38.584 +00:00 [INF] - Started task to cleanup processed and stale messages for endpoint edge_name/customemodule3/SensorData <6> 2023-09-26 07:14:38.923 +00:00 [INF] - Cleaned up 2835 messages from queue for endpoint edge_name/customemodule3/SensorData and 2835 messages from message store. <6> 2023-09-26 07:14:44.701 +00:00 [INF] - Exiting connected state <6> 2023-09-26 07:14:44.701 +00:00 [INF] - Entering unreachable state <4> 2023-09-26 07:14:44.703 +00:00 [WRN] - Error getting twin for edge_name/$edgeHub System.TimeoutException: The operation timed out. ---> Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException: Transient network error occurred, please retry. ---> System.TimeoutException: The operation has timed out. at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.RoundTripTwinMessageAsync(AmqpTwinMessageType amqpTwinMessageType, TwinCollection reportedProperties, CancellationToken cancellationToken) at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinGetAsync(CancellationToken cancellationToken) at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation) --- End of inner exception stack trace --- at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation) at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass35_0.<b__0>d.MoveNext() --- End of stack trace from previous location --- at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.SendTwinGetAsync(CancellationToken cancellationToken) at Microsoft.Azure.Devices.Client.InternalClient.GetTwinAsync() --- End of inner exception stack trace --- at Microsoft.Azure.Devices.Client.InternalClient.GetTwinAsync() at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 189 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 189 at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter[T](Task`1 task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 137 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.GetTwinAsync() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 145 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.GetTwinAsync() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 145 at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.ExecuteOperation[T](Func`2 func, String operation) at Microsoft.Azure.Devices.Edge.Hub.Core.Twin.CloudSync.<>c__DisplayClass4_0.<b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/twin/CloudSync.cs:line 40 --- End of stack trace from previous location --- at Microsoft.Azure.Devices.Edge.Hub.Core.Twin.CloudSync.GetTwin(String id) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/twin/CloudSync.cs:line 49 <6> 2023-09-26 07:14:44.776 +00:00 [INF] - Obtained edge hub config from module twin <6> 2023-09-26 07:15:04.704 +00:00 [INF] - Entering disconnected state <6> 2023-09-26 07:15:04.704 +00:00 [INF] - Cloud connection for edge_name/customemodule4 is False <6> 2023-09-26 07:15:04.704 +00:00 [INF] - Connection status for edge_name/customemodule4 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for edge_name/customemodule2 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for edge_name/customemodule2 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for edge_name/customemodule4 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for edge_name/customemodule4 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for edge_name/customemodule3 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for edge_name/customemodule3 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for edge_name/edgeSpotterLogger is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for edge_name/edgeSpotterLogger changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for edge_name/customemodule3 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for edge_name/customemodule3 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for edge_name/customemodule2 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for edge_name/customemodule2 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for some_downstream_device0043 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for some_downstream_device0043 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for some_downstream_device0047 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for some_downstream_device0047 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for some_downstream_device0045 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for some_downstream_device0045 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for some_downstream_device0057 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for some_downstream_device0057 changed to Disconnected <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Cloud connection for some_downstream_device0058 is False <6> 2023-09-26 07:15:04.705 +00:00 [INF] - Connection status for some_downstream_device0058 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0037 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0037 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0041 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0041 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0061 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0061 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0056 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0056 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0054 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0054 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0062 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0062 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0050 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0050 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0063 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0063 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0064 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0064 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0046 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0046 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0055 is False <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Connection status for some_downstream_device0055 changed to Disconnected <6> 2023-09-26 07:15:04.706 +00:00 [INF] - Cloud connection for some_downstream_device0053 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0053 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0065 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0065 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0048 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0048 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0066 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0066 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0040 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0040 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0049 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0049 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0059 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0059 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0042 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0042 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0052 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0052 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for edge_name/$edgeHub is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for edge_name/$edgeHub changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0044 is False <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Connection status for some_downstream_device0044 changed to Disconnected <6> 2023-09-26 07:15:04.707 +00:00 [INF] - Cloud connection for some_downstream_device0060 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for some_downstream_device0060 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/customemodule3 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/customemodule3 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/customemodule2 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/customemodule2 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/customemodule1 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/customemodule1 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/customemodule4 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/customemodule4 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/customemodule2 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/customemodule2 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/edgeSpotterLogger is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/edgeSpotterLogger changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/customemodule3 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/customemodule3 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/customemodule6 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/customemodule6 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/customemodule5 is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/customemodule5 changed to Disconnected <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Cloud connection for edge_name/edgeblob is False <6> 2023-09-26 07:15:04.708 +00:00 [INF] - Connection status for edge_name/edgeblob changed to Disconnected <4> 2023-09-26 07:15:04.819 +00:00 [WRN] - Updating reported properties failed edge_name/$edgeHub <6> 2023-09-26 07:15:07.893 +00:00 [INF] - Closing receiver in cloud proxy 7bf6332c-6e57-47dc-ae17-39edb0944ec6 for some_downstream_device0042 <6> 2023-09-26 07:15:07.893 +00:00 [INF] - Error receiving C2D messages for some_downstream_device0042 in cloud proxy 7bf6332c-6e57-47dc-ae17-39edb0944ec6. Closing receive loop. System.ObjectDisposedException: The CancellationTokenSource has been disposed. at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.ReceiveAsync(TimeoutHelper timeoutHelper) at Microsoft.Azure.Devices.Client.InternalClient.ReceiveAsync(TimeSpan timeout) at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.CloudReceiver.C2DMessagesLoop(IClient deviceClient) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 527 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.CloudReceiver.C2DMessagesLoop(IClient deviceClient) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 541 <6> 2023-09-26 07:15:07.894 +00:00 [INF] - Closing receiver in cloud proxy 7bf6332c-6e57-47dc-ae17-39edb0944ec6 for some_downstream_device0042 <6> 2023-09-26 07:15:07.894 +00:00 [INF] - Closed cloud proxy 7bf6332c-6e57-47dc-ae17-39edb0944ec6 for some_downstream_device0042 <6> 2023-09-26 07:15:07.894 +00:00 [INF] - Closed cloud proxy 7bf6332c-6e57-47dc-ae17-39edb0944ec6 for some_downstream_device0042 <6> 2023-09-26 07:15:27.895 +00:00 [INF] - Closing receiver in cloud proxy 7144a3b2-0d02-4296-bba2-727a8b3c3323 for some_downstream_device0047 <6> 2023-09-26 07:15:27.896 +00:00 [INF] - Cloud message receiver stopped for some_downstream_device0047 in cloud proxy 7144a3b2-0d02-4296-bba2-727a8b3c3323 <6> 2023-09-26 07:15:27.896 +00:00 [INF] - Closed cloud proxy 7144a3b2-0d02-4296-bba2-727a8b3c3323 for some_downstream_device0047 <6> 2023-09-26 07:15:37.883 +00:00 [INF] - Error due to sdk hanging and upstream call timed out, closing cloud proxy for edge_name/customemodule2. Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubCloudSDKException: Operation timed out due to SDK hanging at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.<>c.<.cctor>b__43_0() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 51 at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 160 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.SendMessageAsync(IMessage inputMessage) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 170 <6> 2023-09-26 07:15:37.883 +00:00 [INF] - Closing receiver in cloud proxy 304daa8b-33bb-41b6-a94a-06e1d1e1c34a for edge_name/customemodule2 <6> 2023-09-26 07:15:37.883 +00:00 [INF] - Closed cloud proxy 304daa8b-33bb-41b6-a94a-06e1d1e1c34a for edge_name/customemodule2 <6> 2023-09-26 07:15:37.883 +00:00 [INF] - Retrying cloud proxy operation SendMessageAsync for edge_name/customemodule2. Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubCloudSDKException: Operation timed out due to SDK hanging at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.<>c.<.cctor>b__43_0() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 51 at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 160 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.SendMessageAsync(IMessage inputMessage) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 170 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.SendMessageAsync(IMessage inputMessage) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 170 at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.<>c__DisplayClass24_0.<b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/cloud/RetryingCloudProxy.cs:line 65 --- End of stack trace from previous location --- at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.ExecuteOperation[T](Func`2 func, String operation) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/cloud/RetryingCloudProxy.cs:line 76 <6> 2023-09-26 07:15:47.890 +00:00 [INF] - Closing receiver in cloud proxy 304daa8b-33bb-41b6-a94a-06e1d1e1c34a for edge_name/customemodule2 <6> 2023-09-26 07:15:47.900 +00:00 [INF] - Closed cloud proxy 304daa8b-33bb-41b6-a94a-06e1d1e1c34a for edge_name/customemodule2 <6> 2023-09-26 07:15:47.903 +00:00 [INF] - Closing receiver in cloud proxy 831a806d-765f-4bcb-bfc2-6a23e482fbc9 for some_downstream_device0057 <6> 2023-09-26 07:17:11.257 +00:00 [INF] - Entering periodic task to reauthenticate connected clients <6> 2023-09-26 07:19:24.969 +00:00 [INF] - Exiting disconnected state <6> 2023-09-26 07:19:24.970 +00:00 [INF] - Received device connected callback <6> 2023-09-26 07:19:24.970 +00:00 [INF] - Device connected to cloud, processing subscriptions for connected clients. <6> 2023-09-26 07:19:24.970 +00:00 [INF] - Processing subscriptions for client some_downstream_device0042 on device connected to cloud. <6> 2023-09-26 07:19:24.970 +00:00 [INF] - Processing subscriptions for client some_downstream_device0047 on device connected to cloud. <6> 2023-09-26 07:19:24.970 +00:00 [INF] - Processing subscriptions for client edge_name/customemodule2 on device connected to cloud. <6> 2023-09-26 07:19:24.970 +00:00 [INF] - Processing subscriptions for client some_downstream_device0057 on device connected to cloud. <6> 2023-09-26 07:19:24.971 +00:00 [INF] - Processing subscriptions for client some_downstream_device0043 on device connected to cloud. <6> 2023-09-26 07:19:24.974 +00:00 [INF] - Cloud connection for some_downstream_device0043 is True <6> 2023-09-26 07:19:24.974 +00:00 [INF] - Connection status for some_downstream_device0043 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.974 +00:00 [INF] - Client some_downstream_device0043 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.974 +00:00 [INF] - Skipping some_downstream_device0043 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.974 +00:00 [INF] - Processing subscriptions for client edge_name/customemodule4 on device connected to cloud. <6> 2023-09-26 07:19:24.974 +00:00 [INF] - Processing subscriptions for client some_downstream_device0045 on device connected to cloud. <6> 2023-09-26 07:19:24.974 +00:00 [INF] - Cloud connection for some_downstream_device0045 is True <6> 2023-09-26 07:19:24.974 +00:00 [INF] - Connection status for some_downstream_device0045 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0045 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0045 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0041 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0041 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0041 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0041 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0041 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0058 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0058 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0058 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0058 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0058 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0037 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0037 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0037 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0037 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0037 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0056 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0056 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0056 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0056 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0056 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0061 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0061 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0061 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0061 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0061 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0062 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0062 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0062 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0062 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0062 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client edge_name/edgeblob on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for edge_name/edgeblob is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for edge_name/edgeblob changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client edge_name/edgeblob connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping edge_name/edgeblob for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0065 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0065 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0065 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0065 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0065 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0040 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0040 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0040 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0040 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0040 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0066 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0066 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0066 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0066 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0066 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0050 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0050 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0050 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0050 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0050 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0054 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0054 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0054 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0054 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0054 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0053 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0053 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0053 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0053 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0053 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0064 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0064 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0064 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0064 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0064 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0048 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0048 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0048 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0048 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0048 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0052 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0052 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0052 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0052 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0052 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0060 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0060 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0060 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0060 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0060 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0063 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0063 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0063 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0063 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0063 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client edge_name/customemodule5 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0046 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0046 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0046 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0046 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping some_downstream_device0046 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client edge_name/customemodule3 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for edge_name/customemodule3 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for edge_name/customemodule3 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client edge_name/customemodule3 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Skipping edge_name/customemodule3 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Processing subscriptions for client some_downstream_device0059 on device connected to cloud. <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Cloud connection for some_downstream_device0059 is True <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Connection status for some_downstream_device0059 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.975 +00:00 [INF] - Client some_downstream_device0059 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping some_downstream_device0059 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Processing subscriptions for client some_downstream_device0044 on device connected to cloud. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for some_downstream_device0044 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for some_downstream_device0044 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client some_downstream_device0044 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping some_downstream_device0044 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Processing subscriptions for client edge_name/$edgeHub on device connected to cloud. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/$edgeHub is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/$edgeHub changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/$edgeHub connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/$edgeHub for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Processing subscriptions for client edge_name/edgeSpotterLogger on device connected to cloud. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Processing subscriptions for client edge_name/customemodule6 on device connected to cloud. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Processing subscriptions for client some_downstream_device0049 on device connected to cloud. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for some_downstream_device0049 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for some_downstream_device0049 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client some_downstream_device0049 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping some_downstream_device0049 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Processing subscriptions for client edge_name/customemodule1 on device connected to cloud. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule1 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule1 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule1 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/customemodule1 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Processing subscriptions for client some_downstream_device0055 on device connected to cloud. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for some_downstream_device0055 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for some_downstream_device0055 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client some_downstream_device0055 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping some_downstream_device0055 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule4 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule4 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule4 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/customemodule4 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule2 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule2 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule2 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/customemodule2 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule4 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule4 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule4 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/customemodule4 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule3 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule3 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule3 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/edgeSpotterLogger is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/edgeSpotterLogger changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/edgeSpotterLogger connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule3 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule3 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule3 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule2 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule2 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule2 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/customemodule2 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule3 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule3 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule3 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule2 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule2 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule2 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/customemodule2 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule4 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule4 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule4 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/customemodule4 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/edgeSpotterLogger is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/edgeSpotterLogger changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/edgeSpotterLogger connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule6 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule6 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule6 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Cloud connection for edge_name/customemodule5 is True <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Connection status for edge_name/customemodule5 changed to ConnectionEstablished <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Client edge_name/customemodule5 connected to cloud, processing existing subscriptions. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Skipping edge_name/customemodule5 for subscription processing, as it is currently being processed. <6> 2023-09-26 07:19:24.976 +00:00 [INF] - Entering connected state <6> 2023-09-26 07:19:24.982 +00:00 [INF] - Device scope identities refresh is ready because a refresh was signalled. <6> 2023-09-26 07:19:24.982 +00:00 [INF] - Starting refresh of device scope identities cache <6> 2023-09-26 07:19:24.990 +00:00 [INF] - Done syncing reported properties for some_downstream_device0042 ```

Additional Information

I think this is not happening always. Looks like sometimes Edge is comming bug to normal state after disconnecting. It's a quite dangerous bug because as per the IoT Hub and everything Edge is connected but it is not sending any messages forward to upstream. In the logs disconnection happened at around 07:00.

Hi, I am able to reproduce it on 1.4.24. The issue still is there. The Edge lost connection for 20 minutes, turn back online and after that stopped pushing messages to upstream - restart of edgeHub was needed to get it to work back.

@gordonwang0 Could you please re-open the issue?

edge-hub logs

``` <6> 2023-11-08 15:33:51.825 +00:00 [INF] - Done refreshing device scope identities cache. Waiting for 60 minutes. <6> 2023-11-08 15:35:05.937 +00:00 [INF] - Entering periodic task to reauthenticate connected clients <6> 2023-11-08 15:35:06.050 +00:00 [INF] - Error authenticating token for edge_id/module_1 because the token is expired or could not be parsed <6> 2023-11-08 15:35:06.050 +00:00 [INF] - Credentials for client edge_id/module_1 are not valid. <4> 2023-11-08 15:35:06.050 +00:00 [WRN] - Reauthenticating client edge_id/module_1 failed, removing client connection <6> 2023-11-08 15:35:06.051 +00:00 [INF] - Unable to re-authenticate edge_id/module_1, dropping client connection. <6> 2023-11-08 15:35:06.051 +00:00 [INF] - Removing device connection for device edge_id/module_1 with removeCloudConnection flag 'True'. <4> 2023-11-08 15:35:06.051 +00:00 [WRN] - "Closing connection for device: edge_id/module_1, Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnectionException: Connection closed for device edge_id/module_1., " <6> 2023-11-08 15:35:06.051 +00:00 [INF] - Disposing MessagingServiceClient for device Id edge_id/module_1 because of exception - Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnectionException: Connection closed for device edge_id/module_1. <6> 2023-11-08 15:35:06.055 +00:00 [INF] - Closing device proxy for device Id edge_id/module_1 <6> 2023-11-08 15:35:06.055 +00:00 [INF] - Device connection removed for device edge_id/module_1 <4> 2023-11-08 15:35:07.979 +00:00 [WRN] - Module edge_id/module_1 is not connected <4> 2023-11-08 15:35:08.990 +00:00 [WRN] - Module edge_id/module_1 is not connected <4> 2023-11-08 15:35:10.940 +00:00 [WRN] - Module edge_id/module_1 is not connected <4> 2023-11-08 15:35:15.525 +00:00 [WRN] - Module edge_id/module_1 is not connected <4> 2023-11-08 15:35:22.777 +00:00 [WRN] - Module edge_id/module_1 is not connected <6> 2023-11-08 15:35:26.196 +00:00 [INF] - Exiting connected state <6> 2023-11-08 15:35:26.201 +00:00 [INF] - Entering unreachable state <4> 2023-11-08 15:35:26.202 +00:00 [WRN] - Updating reported properties failed edge_id/$edgeHub <4> 2023-11-08 15:35:38.737 +00:00 [WRN] - Module edge_id/module_1 is not connected <4> 2023-11-08 15:35:48.085 +00:00 [WRN] - Error calling IotHub for connectivity test Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException: Transient network error occurred, please retry. ---> System.Net.Sockets.SocketException (11): Resource temporarily unavailable at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result) at Microsoft.Azure.Amqp.Transport.AmqpTransportInitiator.<>c.b__17_1(IAsyncResult r) at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization) --- End of stack trace from previous location --- at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTTransport.InitializeAsync(TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpIoTConnector.OpenConnectionAsync(TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpConnectionHolder.EnsureConnectionAsync(TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpConnectionHolder.EnsureConnectionAsync(TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpConnectionHolder.OpenSessionAsync(DeviceIdentity deviceIdentity, TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.EnsureSessionIsOpenAsync(TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.EnsureSessionIsOpenAsync(TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.EnableTwinLinksAsync(TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.SendTwinMessageAsync(AmqpTwinMessageType amqpTwinMessageType, String correlationId, TwinCollection reportedProperties, TimeSpan timeout) at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.EnableTwinPatchAsync(CancellationToken cancellationToken) at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken) at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass27_0.<b__0>d.MoveNext() --- End of stack trace from previous location --- at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation) --- End of inner exception stack trace --- at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation) at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass36_0.<b__0>d.MoveNext() --- End of stack trace from previous location --- at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken) at Microsoft.Azure.Devices.Client.InternalClient.UpdateReportedPropertiesAsync(TwinCollection reportedProperties) at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 196 --- End of stack trace from previous location --- at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 189 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 189 at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 160 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.UpdateReportedPropertiesAsync(IMessage reportedPropertiesMessage) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 229 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.UpdateReportedPropertiesAsync(IMessage reportedPropertiesMessage) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 229 at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.<>c__DisplayClass24_0.<b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/cloud/RetryingCloudProxy.cs:line 65 --- End of stack trace from previous location --- at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.ExecuteOperation[T](Func`2 func, String operation) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/cloud/RetryingCloudProxy.cs:line 76 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager.ConnectivityChecker.Check() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/DeviceConnectivityManager.cs:line 218 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager.CheckConnectivity() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/DeviceConnectivityManager.cs:line 181 <6> 2023-11-08 15:35:49.234 +00:00 [INF] - Client edge_id/module_1 in device scope authenticated locally. <6> 2023-11-08 15:35:49.237 +00:00 [INF] - Successfully generated identity for clientId edge_id/module_1 and username 10.11.2.158/edge_id/module_1/?api-version=2020-09-30&DeviceClientType=.NET%2F1.38.0%20%28.NET%20Core%204.6.28008.01%3B%20Linux%205.15.0-86-generic%20%2396-Ubuntu%20SMP%20Wed%20Sep%2020%2008%3A23%3A49%20UTC%202023%3B%20X64%29%20Microsoft.stream-analytics-on-iot-edge <6> 2023-11-08 15:35:49.237 +00:00 [INF] - "ClientAuthenticated, edge_id/module_1, 03202a85" <6> 2023-11-08 15:35:49.239 +00:00 [INF] - New device connection for device edge_id/module_1 <6> 2023-11-08 15:35:49.240 +00:00 [INF] - Client edge_id/module_1 connected to edgeHub, processing existing subscriptions. <6> 2023-11-08 15:35:49.240 +00:00 [INF] - Skipping edge_id/module_1 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:35:49.242 +00:00 [INF] - Bind device proxy for device edge_id/module_1 <6> 2023-11-08 15:35:49.243 +00:00 [INF] - Binding message channel for device Id edge_id/module_1 <6> 2023-11-08 15:35:49.244 +00:00 [INF] - Processing subscriptions TwinResponse, DesiredPropertyUpdates, ModuleMessages for client edge_id/module_1. <6> 2023-11-08 15:35:49.255 +00:00 [INF] - Set subscriptions from session state for edge_id/module_1 <6> 2023-11-08 15:35:49.262 +00:00 [INF] - Processing subscriptions TwinResponse, DesiredPropertyUpdates, ModuleMessages for client edge_id/module_1. <6> 2023-11-08 15:35:49.267 +00:00 [INF] - Set subscriptions from session state for edge_id/module_1 <6> 2023-11-08 15:35:49.269 +00:00 [INF] - Processing subscriptions TwinResponse, DesiredPropertyUpdates, ModuleMessages for client edge_id/module_1. <6> 2023-11-08 15:35:49.270 +00:00 [INF] - Set subscriptions from session state for edge_id/module_1 <6> 2023-11-08 15:36:09.410 +00:00 [INF] - Entering disconnected state <6> 2023-11-08 15:36:09.412 +00:00 [INF] - Cloud connection for edge_id/edgeblob is False <6> 2023-11-08 15:36:09.412 +00:00 [INF] - Connection status for edge_id/edgeblob changed to Disconnected <6> 2023-11-08 15:36:09.413 +00:00 [INF] - Cloud connection for E0:5A:1B:66:6C:78 is False <6> 2023-11-08 15:36:09.413 +00:00 [INF] - Connection status for E0:5A:1B:66:6C:78 changed to Disconnected <6> 2023-11-08 15:36:09.414 +00:00 [INF] - Cloud connection for E0:5A:1B:66:6C:30 is False <6> 2023-11-08 15:36:09.414 +00:00 [INF] - Connection status for E0:5A:1B:66:6C:30 changed to Disconnected <6> 2023-11-08 15:36:09.414 +00:00 [INF] - Cloud connection for 30:C6:F7:F8:B5:FC is False <6> 2023-11-08 15:36:09.415 +00:00 [INF] - Connection status for 30:C6:F7:F8:B5:FC changed to Disconnected <6> 2023-11-08 15:36:09.415 +00:00 [INF] - Cloud connection for E0:5A:1B:64:80:D4 is False <6> 2023-11-08 15:36:09.415 +00:00 [INF] - Connection status for E0:5A:1B:64:80:D4 changed to Disconnected <6> 2023-11-08 15:36:09.416 +00:00 [INF] - Cloud connection for edge_id/$edgeHub is False <6> 2023-11-08 15:36:09.416 +00:00 [INF] - Connection status for edge_id/$edgeHub changed to Disconnected <6> 2023-11-08 15:36:09.417 +00:00 [INF] - Cloud connection for E0:5A:1B:66:6C:24 is False <6> 2023-11-08 15:36:09.417 +00:00 [INF] - Connection status for E0:5A:1B:66:6C:24 changed to Disconnected <6> 2023-11-08 15:36:09.417 +00:00 [INF] - Cloud connection for edge_id/module_4 is False <6> 2023-11-08 15:36:09.418 +00:00 [INF] - Connection status for edge_id/module_4 changed to Disconnected <6> 2023-11-08 15:36:09.418 +00:00 [INF] - Cloud connection for edge_id/module_2 is False <6> 2023-11-08 15:36:09.419 +00:00 [INF] - Connection status for edge_id/module_2 changed to Disconnected <4> 2023-11-08 15:36:09.420 +00:00 [WRN] - Updating reported properties failed edge_id/$edgeHub <6> 2023-11-08 15:40:05.940 +00:00 [INF] - Entering periodic task to reauthenticate connected clients <6> 2023-11-08 15:42:49.962 +00:00 [INF] - Exiting disconnected state <6> 2023-11-08 15:42:49.962 +00:00 [INF] - Device connected to cloud, processing subscriptions for connected clients. <6> 2023-11-08 15:42:49.963 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6D:CC on device connected to cloud. <6> 2023-11-08 15:42:49.963 +00:00 [INF] - Skipping E0:5A:1B:66:6D:CC for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.964 +00:00 [INF] - Processing subscriptions for client 08:B6:1F:3A:1A:80 on device connected to cloud. <6> 2023-11-08 15:42:49.964 +00:00 [INF] - Skipping 08:B6:1F:3A:1A:80 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.964 +00:00 [INF] - Processing subscriptions for client edge_id/module_5 on device connected to cloud. <6> 2023-11-08 15:42:49.965 +00:00 [INF] - Skipping edge_id/module_5 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.965 +00:00 [INF] - Processing subscriptions for client edge_id/module_2 on device connected to cloud. <6> 2023-11-08 15:42:49.966 +00:00 [INF] - Skipping edge_id/module_2 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.966 +00:00 [INF] - Processing subscriptions for client 40:22:D8:15:CB:08 on device connected to cloud. <6> 2023-11-08 15:42:49.966 +00:00 [INF] - Skipping 40:22:D8:15:CB:08 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.967 +00:00 [INF] - Processing subscriptions for client 30:C6:F7:F9:34:40 on device connected to cloud. <6> 2023-11-08 15:42:49.967 +00:00 [INF] - Skipping 30:C6:F7:F9:34:40 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.967 +00:00 [INF] - Processing subscriptions for client edge_id/edgeblob on device connected to cloud. <6> 2023-11-08 15:42:49.968 +00:00 [INF] - Skipping edge_id/edgeblob for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.968 +00:00 [INF] - Processing subscriptions for client 30:C6:F7:F8:E1:D0 on device connected to cloud. <6> 2023-11-08 15:42:49.968 +00:00 [INF] - Skipping 30:C6:F7:F8:E1:D0 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.969 +00:00 [INF] - Processing subscriptions for client 30:C6:F7:F9:40:A4 on device connected to cloud. <6> 2023-11-08 15:42:49.969 +00:00 [INF] - Skipping 30:C6:F7:F9:40:A4 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.969 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6C:78 on device connected to cloud. <6> 2023-11-08 15:42:49.970 +00:00 [INF] - Skipping E0:5A:1B:66:6C:78 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.970 +00:00 [INF] - Processing subscriptions for client edge_id/module_7ger on device connected to cloud. <6> 2023-11-08 15:42:49.971 +00:00 [INF] - Skipping edge_id/module_7ger for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.971 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6A:6C on device connected to cloud. <6> 2023-11-08 15:42:49.971 +00:00 [INF] - Skipping E0:5A:1B:66:6A:6C for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.972 +00:00 [INF] - Processing subscriptions for client edge_id/module_4 on device connected to cloud. <6> 2023-11-08 15:42:49.972 +00:00 [INF] - Skipping edge_id/module_4 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.972 +00:00 [INF] - Processing subscriptions for client edge_id/module_1 on device connected to cloud. <6> 2023-11-08 15:42:49.973 +00:00 [INF] - Skipping edge_id/module_1 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.973 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6C:30 on device connected to cloud. <6> 2023-11-08 15:42:49.974 +00:00 [INF] - Skipping E0:5A:1B:66:6C:30 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.974 +00:00 [INF] - Processing subscriptions for client 30:C6:F7:F8:E3:0C on device connected to cloud. <6> 2023-11-08 15:42:49.974 +00:00 [INF] - Skipping 30:C6:F7:F8:E3:0C for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.975 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6C:DC on device connected to cloud. <6> 2023-11-08 15:42:49.975 +00:00 [INF] - Skipping E0:5A:1B:66:6C:DC for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.976 +00:00 [INF] - Processing subscriptions for client edge_id/module_3 on device connected to cloud. <6> 2023-11-08 15:42:49.976 +00:00 [INF] - Skipping edge_id/module_3 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.976 +00:00 [INF] - Processing subscriptions for client edge_id/module_6sMsgHelper on device connected to cloud. <6> 2023-11-08 15:42:49.977 +00:00 [INF] - Skipping edge_id/module_6sMsgHelper for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.977 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:65:64:18 on device connected to cloud. <6> 2023-11-08 15:42:49.977 +00:00 [INF] - Skipping E0:5A:1B:65:64:18 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.978 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6C:88 on device connected to cloud. <6> 2023-11-08 15:42:49.978 +00:00 [INF] - Skipping E0:5A:1B:66:6C:88 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.979 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6D:00 on device connected to cloud. <6> 2023-11-08 15:42:49.979 +00:00 [INF] - Skipping E0:5A:1B:66:6D:00 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.979 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6C:FC on device connected to cloud. <6> 2023-11-08 15:42:49.980 +00:00 [INF] - Skipping E0:5A:1B:66:6C:FC for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.983 +00:00 [INF] - Processing subscriptions for client 30:C6:F7:F9:3D:8C on device connected to cloud. <6> 2023-11-08 15:42:49.983 +00:00 [INF] - Skipping 30:C6:F7:F9:3D:8C for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.984 +00:00 [INF] - Processing subscriptions for client 30:C6:F7:F8:B5:FC on device connected to cloud. <6> 2023-11-08 15:42:49.984 +00:00 [INF] - Cloud connection for 30:C6:F7:F8:B5:FC is True <6> 2023-11-08 15:42:49.985 +00:00 [INF] - Connection status for 30:C6:F7:F8:B5:FC changed to ConnectionEstablished <6> 2023-11-08 15:42:49.990 +00:00 [INF] - Client 30:C6:F7:F8:B5:FC connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:49.993 +00:00 [INF] - Skipping 30:C6:F7:F8:B5:FC for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.993 +00:00 [INF] - Processing subscriptions for client edge_id/$edgeHub on device connected to cloud. <6> 2023-11-08 15:42:49.994 +00:00 [INF] - Cloud connection for edge_id/$edgeHub is True <6> 2023-11-08 15:42:49.994 +00:00 [INF] - Connection status for edge_id/$edgeHub changed to ConnectionEstablished <6> 2023-11-08 15:42:49.994 +00:00 [INF] - Client edge_id/$edgeHub connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:49.995 +00:00 [INF] - Skipping edge_id/$edgeHub for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:49.995 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:66:6C:24 on device connected to cloud. <6> 2023-11-08 15:42:49.996 +00:00 [INF] - Cloud connection for E0:5A:1B:66:6C:24 is True <6> 2023-11-08 15:42:49.996 +00:00 [INF] - Connection status for E0:5A:1B:66:6C:24 changed to ConnectionEstablished <6> 2023-11-08 15:42:50.000 +00:00 [INF] - Client E0:5A:1B:66:6C:24 connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:50.001 +00:00 [INF] - Skipping E0:5A:1B:66:6C:24 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:50.001 +00:00 [INF] - Processing subscriptions for client E0:5A:1B:64:80:D4 on device connected to cloud. <6> 2023-11-08 15:42:50.002 +00:00 [INF] - Cloud connection for E0:5A:1B:64:80:D4 is True <6> 2023-11-08 15:42:50.002 +00:00 [INF] - Connection status for E0:5A:1B:64:80:D4 changed to ConnectionEstablished <6> 2023-11-08 15:42:50.003 +00:00 [INF] - Client E0:5A:1B:64:80:D4 connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:50.003 +00:00 [INF] - Skipping E0:5A:1B:64:80:D4 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:50.003 +00:00 [INF] - Received device connected callback <6> 2023-11-08 15:42:50.018 +00:00 [INF] - Device scope identities refresh is ready because a refresh was signalled. <6> 2023-11-08 15:42:50.018 +00:00 [INF] - Starting refresh of device scope identities cache <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Cloud connection for edge_id/edgeblob is True <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Connection status for edge_id/edgeblob changed to ConnectionEstablished <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Client edge_id/edgeblob connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Skipping edge_id/edgeblob for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Cloud connection for E0:5A:1B:66:6C:78 is True <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Connection status for E0:5A:1B:66:6C:78 changed to ConnectionEstablished <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Client E0:5A:1B:66:6C:78 connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Skipping E0:5A:1B:66:6C:78 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Cloud connection for E0:5A:1B:66:6C:30 is True <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Connection status for E0:5A:1B:66:6C:30 changed to ConnectionEstablished <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Client E0:5A:1B:66:6C:30 connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Skipping E0:5A:1B:66:6C:30 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Cloud connection for edge_id/module_4 is True <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Connection status for edge_id/module_4 changed to ConnectionEstablished <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Client edge_id/module_4 connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Skipping edge_id/module_4 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Cloud connection for edge_id/module_2 is True <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Connection status for edge_id/module_2 changed to ConnectionEstablished <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Client edge_id/module_2 connected to cloud, processing existing subscriptions. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Skipping edge_id/module_2 for subscription processing, as it is currently being processed. <6> 2023-11-08 15:42:50.050 +00:00 [INF] - Entering connected state <6> 2023-11-08 15:42:50.074 +00:00 [INF] - Done syncing reported properties for E0:5A:1B:66:6D:CC <6> 2023-11-08 15:42:51.117 +00:00 [INF] - Not changed node: 30:C6:F7:F9:1C:14 <6> 2023-11-08 15:42:51.118 +00:00 [INF] - Not changed node: E0:5A:1B:64:80:D4 <6> 2023-11-08 15:42:51.118 +00:00 [INF] - Not changed node: 30:C6:F7:F8:DF:6C <6> 2023-11-08 15:42:51.118 +00:00 [INF] - Not changed node: E0:5A:1B:66:6D:CC <6> 2023-11-08 15:42:51.118 +00:00 [INF] - Not changed node: E0:5A:1B:66:6C:FC <6> 2023-11-08 15:42:51.119 +00:00 [INF] - Not changed node: 30:C6:F7:F8:B5:FC <6> 2023-11-08 15:42:51.119 +00:00 [INF] - Not changed node: E0:5A:1B:66:6A:A4 <6> 2023-11-08 15:42:51.119 +00:00 [INF] - Not changed node: 40:22:D8:15:CB:08 <6> 2023-11-08 15:42:51.119 +00:00 [INF] - Not changed node: 30:C6:F7:F8:E1:D0 <6> 2023-11-08 15:42:51.120 +00:00 [INF] - Not changed node: edge_id <6> 2023-11-08 15:42:51.120 +00:00 [INF] - Not changed node: edge_id/$edgeAgent <6> 2023-11-08 15:42:51.120 +00:00 [INF] - Not changed node: edge_id/$edgeHub <6> 2023-11-08 15:42:51.120 +00:00 [INF] - Not changed node: edge_id/module_3 <6> 2023-11-08 15:42:51.120 +00:00 [INF] - Not changed node: edge_id/module_2 <6> 2023-11-08 15:42:51.121 +00:00 [INF] - Not changed node: edge_id/module_1 <6> 2023-11-08 15:42:51.121 +00:00 [INF] - Not changed node: edge_id/edgeblob <6> 2023-11-08 15:42:51.121 +00:00 [INF] - Not changed node: edge_id/module_4 <6> 2023-11-08 15:42:51.121 +00:00 [INF] - Not changed node: edge_id/module_7ger <6> 2023-11-08 15:42:51.121 +00:00 [INF] - Not changed node: edge_id/module_5 <6> 2023-11-08 15:42:51.122 +00:00 [INF] - Not changed node: edge_id/edgeNTP <6> 2023-11-08 15:42:51.122 +00:00 [INF] - Not changed node: edge_id/module_6sMsgHelper <6> 2023-11-08 15:42:51.888 +00:00 [INF] - Not changed node: 30:C6:F7:F9:2C:18 <6> 2023-11-08 15:42:51.889 +00:00 [INF] - Not changed node: E0:5A:1B:66:6C:E0 <6> 2023-11-08 15:42:51.890 +00:00 [INF] - Not changed node: 08:B6:1F:3A:1A:80 <6> 2023-11-08 15:42:51.890 +00:00 [INF] - Not changed node: E0:5A:1B:66:6A:6C <6> 2023-11-08 15:42:51.891 +00:00 [INF] - Not changed node: E0:5A:1B:66:6C:24 <6> 2023-11-08 15:42:51.891 +00:00 [INF] - Not changed node: E0:5A:1B:65:64:18 <6> 2023-11-08 15:42:51.891 +00:00 [INF] - Not changed node: E0:5A:1B:65:66:98 <6> 2023-11-08 15:42:51.892 +00:00 [INF] - Not changed node: E0:5A:1B:66:6D:00 <6> 2023-11-08 15:42:51.892 +00:00 [INF] - Not changed node: E0:5A:1B:66:6C:88 <6> 2023-11-08 15:42:51.892 +00:00 [INF] - Not changed node: 30:C6:F7:F9:34:40 <6> 2023-11-08 15:42:52.539 +00:00 [INF] - Not changed node: E0:5A:1B:66:6C:78 <6> 2023-11-08 15:42:52.540 +00:00 [INF] - Not changed node: 40:22:D8:15:CB:18 <6> 2023-11-08 15:42:52.540 +00:00 [INF] - Not changed node: E0:5A:1B:66:6D:30 <6> 2023-11-08 15:42:52.541 +00:00 [INF] - Not changed node: 30:C6:F7:F9:40:A4 <6> 2023-11-08 15:42:52.541 +00:00 [INF] - Not changed node: E0:5A:1B:66:6C:30 <6> 2023-11-08 15:42:52.541 +00:00 [INF] - Not changed node: 30:C6:F7:F8:E3:0C <6> 2023-11-08 15:42:52.542 +00:00 [INF] - Not changed node: 08:B6:1F:3A:1A:84 <6> 2023-11-08 15:42:52.542 +00:00 [INF] - Not changed node: E0:5A:1B:66:68:2C <6> 2023-11-08 15:42:52.542 +00:00 [INF] - Not changed node: 30:C6:F7:F9:3D:8C <6> 2023-11-08 15:42:52.543 +00:00 [INF] - Not changed node: E0:5A:1B:66:6C:DC <6> 2023-11-08 15:42:53.112 +00:00 [INF] - Not changed node: E0:5A:1B:66:68:54 ```

Azure / iotedge