iotedge: edgeHub always reported(module twin) fail after module reported a message with null value in array

Expected Behavior

The iotedge module can report information normally when there are null values in the array.

Current Behavior

The edgeHub always reported(module twin) fail after module reported a message with null value in the array.

Report {"a":[{"b":1}]} and then report {"a":[{"b": null}]} makes edgeHub abnormal and the only way to bring edgeHub back to normal is to delete the cache folder and containers.

Steps to Reproduce

Provide a detailed set of steps to reproduce the bug.

Use azure-iot-sdk-c version 1.4.0 to develop a module for reported properties.

It’s normal to report the following property message.

module log

Dec 26 15:37:56 Moxa b66fb16c497e[1725]: [INFO] - [origin:azureiotedge] - [reported], {"a":[{"b":1}]}
Dec 26 15:37:59 Moxa b66fb16c497e[1725]: [INFO] - [origin:azureiotedge] - [reported callback], success

The edgeHub will show many error messages after module send the following property message. The module can receive success message from callback but the properties message sent later cannot be uploaded to the iothub

module log

Dec 26 15:38:46 Moxa b66fb16c497e[1725]: [INFO] - [origin:azureiotedge] - [reported], {"a":[{"b":null}]}
Dec 26 15:38:48 Moxa b66fb16c497e[1725]: [INFO] - [origin:azureiotedge] - [reported callback], success

edgeHub error messages

 <7> 2020-12-29 08:32:54.290 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync failed for Cain8112AME/thingspro-agent
 System.InvalidOperationException: Service response is null
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.RoundTripTwinMessage(AmqpTwinMessageType amqpTwinMessageType, TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass23_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
    at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass25_0.<<SendTwinPatchAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    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.<<InvokeFunc>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 185
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145
 <7> 2020-12-29 08:32:54.659 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Error sending updated reported properties for Cain8112AME/thingspro-agent in cloud proxy 210f6703-27b7-4fef-8545-05d99d3457e5

Context (Environment)

Output of `iotedge check`

Click here


√ config.yaml is well-formed - OK
√ config.yaml has well-formed connection string - OK
√ container engine is installed and functional - OK
√ config.yaml has correct hostname - OK
√ config.yaml has correct URIs for daemon mgmt endpoint - OK
‼ latest security daemon - Warning
    Installed IoT Edge daemon has version 1.0.10.2 but 1.0.10.4 is the latest stable version available.
    Please see https://aka.ms/iotedge-update-runtime for update instructions.
‼ host time is close to real time - Warning
    Time on the device is out of sync with the NTP server. This may cause problems connecting to IoT Hub.
    Please ensure time on device is accurate, for example by installing an NTP daemon.
√ container time is close to host time - OK
√ DNS server - OK
‼ production readiness: certificates - Warning
    The Edge device is using self-signed automatically-generated development certificates.
    They will expire in 84 days (at 2021-03-24 01:17:12 UTC) causing module-to-module and downstream device communication to fail on an active deployment.
    After the certs have expired, restarting the IoT Edge daemon will trigger it to generate new development certs.
    Please consider using production certificates instead. See https://aka.ms/iotedge-prod-checklist-certs for best practices.
√ production readiness: container engine - OK
‼ production readiness: logs policy - Warning
    Container engine is not configured to rotate module logs which may cause it run out of disk space.
    Please see https://aka.ms/iotedge-prod-checklist-logs for best practices.
    You can ignore this warning if you are setting log policy per module in the Edge deployment.
‼ production readiness: Edge Agent's storage directory is persisted on the host filesystem - Warning
    The edgeAgent module is not configured to persist its /tmp/edgeAgent directory on the host filesystem.
    Data might be lost if the module is deleted or updated.
    Please see https://aka.ms/iotedge-storage-host for best practices.
‼ production readiness: Edge Hub's storage directory is persisted on the host filesystem - Warning
    The edgeHub module is not configured to persist its /tmp/edgeHub directory on the host filesystem.
    Data might be lost if the module is deleted or updated.
    Please see https://aka.ms/iotedge-storage-host for best practices.

Connectivity checks
-------------------
√ host can connect to and perform TLS handshake with IoT Hub AMQP port - OK
√ host can connect to and perform TLS handshake with IoT Hub HTTPS / WebSockets port - OK
√ host can connect to and perform TLS handshake with IoT Hub MQTT port - OK
√ container on the default network can connect to IoT Hub AMQP port - OK
√ container on the default network can connect to IoT Hub HTTPS / WebSockets port - OK
√ container on the default network can connect to IoT Hub MQTT port - OK
√ container on the IoT Edge module network can connect to IoT Hub AMQP port - OK
√ container on the IoT Edge module network can connect to IoT Hub HTTPS / WebSockets port - OK
√ container on the IoT Edge module network can connect to IoT Hub MQTT port - OK

17 check(s) succeeded.
6 check(s) raised warnings. Re-run with --verbose for more details.

Device Information

Host OS: debian9
Architecture: arm32
Container OS: Linux containers

Runtime Versions

iotedged: 1.0.10.2
Edge Agent: 1.0.10.3
Edge Hub: 1.0.10.3

Logs

edge-hub logs


         █████╗ ███████╗██╗   ██╗██████╗ ███████╗
        ██╔══██╗╚══███╔╝██║   ██║██╔══██╗██╔════╝
        ███████║  ███╔╝ ██║   ██║██████╔╝█████╗
        ██╔══██║ ███╔╝  ██║   ██║██╔══██╗██╔══╝
        ██║  ██║███████╗╚██████╔╝██║  ██║███████╗
        ╚═╝  ╚═╝╚══════╝ ╚═════╝ ╚═╝  ╚═╝╚══════╝
 
  ██╗ ██████╗ ████████╗    ███████╗██████╗  ██████╗ ███████╗
  ██║██╔═══██╗╚══██╔══╝    ██╔════╝██╔══██╗██╔════╝ ██╔════╝
  ██║██║   ██║   ██║       █████╗  ██║  ██║██║  ███╗█████╗
  ██║██║   ██║   ██║       ██╔══╝  ██║  ██║██║   ██║██╔══╝
  ██║╚██████╔╝   ██║       ███████╗██████╔╝╚██████╔╝███████╗
  ╚═╝ ╚═════╝    ╚═╝       ╚══════╝╚═════╝  ╚═════╝ ╚══════╝
.......
 <7> 2020-12-29 08:32:48.063 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///var/run/iotedge/workload.sock for Encrypt
 <7> 2020-12-29 08:32:48.128 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.DeviceProxy] - Sent twin update to Cain8112AME/thingspro-agent
 <7> 2020-12-29 08:32:48.136 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MessagingServiceClient] - Updating reported properties for device Id Cain8112AME/thingspro-agent
 <7> 2020-12-29 08:32:52.234 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Syncing stored reported properties to cloud in Cain8112AME/thingspro-agent
 <7> 2020-12-29 08:32:52.330 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///var/run/iotedge/workload.sock to Decrypt
 <7> 2020-12-29 08:32:52.356 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
 <7> 2020-12-29 08:32:52.368 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
 <7> 2020-12-29 08:32:52.381 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637000483951873616/decrypt?api-version=2019-01-30
 <7> 2020-12-29 08:32:52.838 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK
 <7> 2020-12-29 08:32:52.858 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///var/run/iotedge/workload.sock for Decrypt
 <7> 2020-12-29 08:32:52.945 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Found stored reported properties for Cain8112AME/thingspro-agent to sync to cloud
 <7> 2020-12-29 08:32:53.020 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///var/run/iotedge/workload.sock to Decrypt
 <7> 2020-12-29 08:32:53.043 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
 <7> 2020-12-29 08:32:53.056 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
 <7> 2020-12-29 08:32:53.071 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637000483951873616/decrypt?api-version=2019-01-30
 <7> 2020-12-29 08:32:53.564 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK
 <7> 2020-12-29 08:32:53.627 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///var/run/iotedge/workload.sock for Decrypt
 <7> 2020-12-29 08:32:53.727 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties for Cain8112AME/thingspro-agent
 <7> 2020-12-29 08:32:53.741 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/thingspro-agent
 <7> 2020-12-29 08:32:54.290 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync failed for Cain8112AME/thingspro-agent
 System.InvalidOperationException: Service response is null
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.RoundTripTwinMessage(AmqpTwinMessageType amqpTwinMessageType, TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass23_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
    at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass25_0.<<SendTwinPatchAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    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.<<InvokeFunc>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 185
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145
 <7> 2020-12-29 08:32:54.659 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Error sending updated reported properties for Cain8112AME/thingspro-agent in cloud proxy 210f6703-27b7-4fef-8545-05d99d3457e5
 System.InvalidOperationException: Service response is null
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.RoundTripTwinMessage(AmqpTwinMessageType amqpTwinMessageType, TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass23_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
    at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass25_0.<<SendTwinPatchAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    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.<<InvokeFunc>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 185
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.UpdateReportedPropertiesAsync(IMessage reportedPropertiesMessage) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 202
 <7> 2020-12-29 08:32:54.815 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy] - Not retrying cloud proxy operation UpdateReportedPropertiesAsync for Cain8112AME/thingspro-agent since the cloud proxy is still active
 System.InvalidOperationException: Service response is null
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.RoundTripTwinMessage(AmqpTwinMessageType amqpTwinMessageType, TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass23_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
    at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass25_0.<<SendTwinPatchAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    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.<<InvokeFunc>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 185
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.UpdateReportedPropertiesAsync(IMessage reportedPropertiesMessage) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 202
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.UpdateReportedPropertiesAsync(IMessage reportedPropertiesMessage) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 211
    at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.<>c__DisplayClass22_0.<<ExecuteOperation>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/cloud/RetryingCloudProxy.cs:line 59
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.ExecuteOperation[T](Func`2 func, String operation) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/cloud/RetryingCloudProxy.cs:line 72
 <7> 2020-12-29 08:32:54.915 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Error updating reported properties for Cain8112AME/thingspro-agent
 System.InvalidOperationException: Service response is null
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.RoundTripTwinMessage(AmqpTwinMessageType amqpTwinMessageType, TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.SendTwinPatchAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass23_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
    at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass25_0.<<SendTwinPatchAsync>b__0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    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.<<InvokeFunc>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 185
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.UpdateReportedPropertiesAsync(IMessage reportedPropertiesMessage) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 202
    at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy.UpdateReportedPropertiesAsync(IMessage reportedPropertiesMessage) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudProxy.cs:line 211
    at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.<>c__DisplayClass22_0.<<ExecuteOperation>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/cloud/RetryingCloudProxy.cs:line 59
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Edge.Hub.Core.Cloud.RetryingCloudProxy.ExecuteOperation[T](Func`2 func, String operation) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/cloud/RetryingCloudProxy.cs:line 72
    at Microsoft.Azure.Devices.Edge.Hub.Core.Twin.CloudSync.<>c__DisplayClass5_0.<<UpdateReportedProperties>b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/twin/CloudSync.cs:line 61
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.Azure.Devices.Edge.Hub.Core.Twin.CloudSync.UpdateReportedProperties(String id, TwinCollection patch) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/twin/CloudSync.cs:line 57
 <4> 2020-12-29 08:32:54.990 +00:00 [WRN] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties failed Cain8112AME/thingspro-agent
 <7> 2020-12-29 08:32:56.223 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:32:56.229 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:33:06.246 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:33:06.258 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:33:16.295 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:33:16.297 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:33:26.309 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:33:26.326 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:33:36.367 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:33:36.369 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:33:44.164 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Calling IotHub to test connectivity
 <7> 2020-12-29 08:33:44.186 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/$edgeHub
 <7> 2020-12-29 08:33:44.495 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
 <7> 2020-12-29 08:33:44.502 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:33:44.507 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:33:46.383 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:33:46.393 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:33:56.411 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:33:56.417 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:34:06.441 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:34:06.445 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:34:16.454 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:34:16.460 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:34:26.478 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:34:26.492 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:34:36.497 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:34:36.503 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:34:44.502 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Calling IotHub to test connectivity
 <7> 2020-12-29 08:34:44.505 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/$edgeHub
 <7> 2020-12-29 08:34:44.931 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
 <7> 2020-12-29 08:34:44.961 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:34:44.974 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:34:46.544 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:34:46.551 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:34:56.551 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:34:56.556 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:35:06.561 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:35:06.566 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:35:16.586 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:35:16.594 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:35:26.628 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:35:26.634 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:35:36.638 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:35:36.646 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:35:44.968 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Calling IotHub to test connectivity
 <7> 2020-12-29 08:35:44.971 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/$edgeHub
 <7> 2020-12-29 08:35:45.453 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
 <7> 2020-12-29 08:35:45.456 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:35:45.464 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:35:46.655 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:35:46.656 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:35:56.673 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:35:56.674 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:36:06.714 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:36:06.720 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:36:16.738 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:36:16.742 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:36:26.749 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:36:26.754 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:36:36.761 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:36:36.766 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:36:45.458 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Calling IotHub to test connectivity
 <7> 2020-12-29 08:36:45.468 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/$edgeHub
 <7> 2020-12-29 08:36:45.802 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
 <7> 2020-12-29 08:36:45.809 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:36:45.815 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:36:46.762 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:36:46.763 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:36:56.772 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:36:56.777 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <6> 2020-12-29 08:37:06.575 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionReauthenticator] - Entering periodic task to reauthenticate connected clients
 <7> 2020-12-29 08:37:06.721 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Getting service identity for Cain8112AME/thingspro-agent
 <7> 2020-12-29 08:37:06.743 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeAuthenticator] - Client Cain8112AME/thingspro-agent in device scope reauthenticated locally.
 <7> 2020-12-29 08:37:06.747 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Authenticator] - Client Cain8112AME/thingspro-agent re-authentication successful
 <7> 2020-12-29 08:37:06.756 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionReauthenticator] - Reauthenticated client Cain8112AME/thingspro-agent successfully
 <7> 2020-12-29 08:37:06.788 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:37:06.790 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:37:16.792 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:37:16.802 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:37:26.808 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:37:26.808 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:37:36.814 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:37:36.814 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:37:45.818 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Calling IotHub to test connectivity
 <7> 2020-12-29 08:37:45.824 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/$edgeHub
 <7> 2020-12-29 08:37:46.154 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
 <7> 2020-12-29 08:37:46.174 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:37:46.175 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:37:46.809 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:37:46.809 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:37:56.811 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:37:56.812 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:38:06.815 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:38:06.820 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:38:16.823 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:38:16.824 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:38:26.829 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:38:26.829 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:38:36.838 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:38:36.838 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:38:46.188 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Calling IotHub to test connectivity
 <7> 2020-12-29 08:38:46.198 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/$edgeHub
 <7> 2020-12-29 08:38:46.531 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
 <7> 2020-12-29 08:38:46.541 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:38:46.547 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:38:46.847 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:38:46.853 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:38:56.852 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:38:56.853 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:39:06.880 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:39:06.881 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:39:16.888 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:39:16.889 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:39:26.901 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:39:26.906 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:39:36.918 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:39:36.925 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:39:46.549 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Calling IotHub to test connectivity
 <7> 2020-12-29 08:39:46.559 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/$edgeHub
 <7> 2020-12-29 08:39:46.919 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:39:46.919 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:39:46.912 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
 <7> 2020-12-29 08:39:46.931 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:39:46.931 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:39:56.919 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:39:56.923 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:40:06.926 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:40:06.930 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:40:16.937 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:40:16.938 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:40:26.940 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:40:26.945 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:40:36.958 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:40:36.959 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:40:46.948 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Calling IotHub to test connectivity
 <7> 2020-12-29 08:40:46.962 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:40:46.963 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:40:46.967 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device Cain8112AME/$edgeHub
 <7> 2020-12-29 08:40:47.317 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded
 <7> 2020-12-29 08:40:47.323 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:40:47.328 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for Cain8112AME/$edgeHub
 <7> 2020-12-29 08:40:56.960 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:40:56.964 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
 <7> 2020-12-29 08:41:06.967 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
 <7> 2020-12-29 08:41:06.972 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 15 (10 by maintainers)

Most upvoted comments

Folks, this finally has been fixed in #4896. There were two issues - with null values in arrays and null properties of objects inside arrays. Both cases should be covered now. EdgeHub will report twin validation error back to the device, instead of blocking further twin patches until the twin store is cleared. Thanks everyone for reporting this!

The fix will be available soon in 1.2 and 1.1.

vadim-kovalyov on May 26, 2021

Closing this issue as it should be fixed by https://github.com/Azure/iotedge/commit/f349908f56686efa3f3d716ea4278845d0504abb

micahl on Feb 11, 2021