Closed surlemur closed 4 years ago
ancaantochi
commented
4 years ago Hi @surlemur
When you use "Set modules" can you please check in the Review + Create state if the module status is set to running.
Are you able to reproduce this issue consistently?
I see that the temperature sensor simulator module is removed when it receives deployment 50, was it started from deployment 49? Can you please upload the full log for edgeAgent?
veyalla
commented
4 years ago @surlemur This happens if the device where you are setting the modules using "Set Modules" is also targeted by an at-scale deployment. Basically, the at-scale deployment overrides the set-modules config in a few minutes.
For a given device, use either set-module or target it with an at-scale deployment, not both.
surlemur
commented
4 years ago Hi @veyalla
Thanks for the hint, this may well be the problem. In fact, I first created an at-scale deployment to provide docker registry credentials, and later deployed using "Set Modules".
It would be helpful though to indicate the incompatibility of the two mechanisms somewhere, as their interference is not very obvious.
Btw: how are multiple at-scale deployments related? Do they overwrite each other, too? Do you need to specifiy "Layered deployments" if you want to combine multiple deployments?
veyalla
commented
4 years ago Deployment priority determines which one is applied if there is overlap in the devices each targets. Similar behavior for layered deployments.
I've added an item to our docs backlog to clarify the perils the using both deployments and set-modules for the given device. Thanks!
Expected Behavior
After deploying an IoT Edge module using the Azure portal IoT Hub -> IoT Edge -> (my device) -> Set Modules it should run until it completes or is manually undeployed.
Current Behavior
For my own module as well as the MS "Simulated Temperature Sensor", the module is stopped by the infrastructure after a couple of minutes. See logs below.
Weird: This seems to happen only if the module is deployed by "Set Modules". When using "Create Deployment", everything looks fine.
Steps to Reproduce
Provide a detailed set of steps to reproduce the bug.
Context (Environment)
Output of
iotedge checkNot available due to https://github.com/Azure/iotedge/issues/2747
Click here
```Device Information
Runtime Versions
iotedge version]: 1.0.9docker version]: 18.09.0, go1.11.1, git commit, 489b8eda6674523df8b82a210399b7d2954427d0Logs
iotedged logs
``` Mar 30 13:23:03 edge iotedged[905]: 2020-03-30T13:23:03Z [DBUG] - [edgelet_http] accepted new connection (unknown) Mar 30 13:23:03 edge iotedged[905]: 2020-03-30T13:23:03Z [DBUG] - [edgelet_http_mgmt::server::module::list] List modules Mar 30 13:23:03 edge iotedged[905]: 2020-03-30T13:23:03Z [DBUG] - [edgelet_docker::runtime] Listing modules... Mar 30 13:23:03 edge iotedged[905]: 2020-03-30T13:23:03Z [DBUG] - [edgelet_http] accepted new connection (unknown) Mar 30 13:23:03 edge iotedged[905]: 2020-03-30T13:23:03Z [DBUG] - [edgelet_docker::runtime] Listing modules... Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_docker::runtime] Successfully listed modules Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_docker::runtime] Successfully listed modules Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [INFO] - [mgmt] - - - [2020-03-30 13:23:04.021630193 UTC] "GET /modules?api-version=2019-11-05 HTTP/1.1" 200 OK 2070 "-" "-" auth_id(-) Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [INFO] - [work] - - - [2020-03-30 13:23:04.097085137 UTC] "POST /modules/%24edgeAgent/genid/637200529561405818/encrypt?api-version=2019-11-05 HTTP/1.1" 200 OK 2089 "-" "-" auth_idMar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_docker::runtime] Listing modules...(-) Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_http] accepted new connection (unknown) Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_docker::runtime] Listing modules... Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_docker::runtime] Successfully listed modules Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_http::client] Success generating token for request GET /devices/aufderdo-som/modules Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [INFO] - [mgmt] - - - [2020-03-30 13:23:04.441756582 UTC] "GET /identities/?api-version=2019-11-05 HTTP/1.1" 200 OK 428 "-" "-" auth_id(-) Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_http] accepted new connection (unknown) Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_docker::runtime] Listing modules... Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_docker::runtime] Successfully listed modules Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_http::client] Success generating token for request DELETE /devices/aufderdo-som/modules/SimulatedTemperatureSensor Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [INFO] - [mgmt] - - - [2020-03-30 13:23:04.773105074 UTC] "DELETE /identities/SimulatedTemperatureSensor?api-version=2019-11-05 HTTP/1.1" 204 No Content - "-" "-" auth_id(-) Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [DBUG] - [edgelet_http] accepted new connection (unknown) Mar 30 13:23:04 edge iotedged[905]: 2020-03-30T13:23:04Z [INFO] - Stopping module SimulatedTemperatureSensor... ```edge-agent logs
``` <7> 2020-03-30 13:22:58.860 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Starting reconcile operation <7> 2020-03-30 13:22:58.860 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to List modules <7> 2020-03-30 13:22:58.861 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:22:58.862 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:22:58.862 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/modules?api-version=2019-11-05 <7> 2020-03-30 13:22:58.863 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Getting edge agent config... <7> 2020-03-30 13:22:58.869 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Obtained edge agent config <7> 2020-03-30 13:22:58.912 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2020-03-30 13:22:58.915 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for List modules <7> 2020-03-30 13:22:58.937 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of desired modules is - {"EdgeGateway":{"status":"running","restartPolicy":"always","version":"1.0","imagePullPolicy<7> 2020-03-30 13:22:58.941 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of current modules is - {"EdgeGateway":{"exitCode":0,"statusDescription":"running","lastStartTimeUtc":"2020-03-30T09<7> 2020-03-30 13:22:58.949 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - HealthRestartPlanner created Plan, with 0 command(s). <7> 2020-03-30 13:22:58.966 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.Reporters.IoTHubReporter] - Not updating reported properties as patch was found to be empty <7> 2020-03-30 13:22:58.967 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Finished reconcile operation <7> 2020-03-30 13:22:59.710 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.EdgeAgentConnection] - Edge agent desired properties updated callback invoked. <7> 2020-03-30 13:22:59.775 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.EdgeAgentConnection] - Edge agent updated deployment config from desired properties. <7> 2020-03-30 13:22:59.776 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.EdgeAgentConnection] - Edge agent desired properties patch applied successfully. <7> 2020-03-30 13:23:03.965 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Starting reconcile operation <7> 2020-03-30 13:23:03.966 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to List modules <7> 2020-03-30 13:23:03.967 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:03.968 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:03.968 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/modules?api-version=2019-11-05 <7> 2020-03-30 13:23:03.969 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Getting edge agent config... <7> 2020-03-30 13:23:03.975 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///var/run/iotedge/workload.sock to Encrypt <7> 2020-03-30 13:23:03.977 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock <7> 2020-03-30 13:23:03.978 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock <7> 2020-03-30 13:23:03.980 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeAgent/genid/637200529561405818/encrypt?api-version=2019-11-05 <7> 2020-03-30 13:23:04.028 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2020-03-30 13:23:04.032 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for List modules <7> 2020-03-30 13:23:04.099 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2020-03-30 13:23:04.100 +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-03-30 13:23:04.117 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Obtained edge agent config <7> 2020-03-30 13:23:04.122 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to List identities <7> 2020-03-30 13:23:04.123 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:04.123 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:04.124 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/identities/?api-version=2019-11-05 <7> 2020-03-30 13:23:04.444 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2020-03-30 13:23:04.445 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for List identities <7> 2020-03-30 13:23:04.479 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to Delete identity for SimulatedTemperatureSensor <7> 2020-03-30 13:23:04.549 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:04.551 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:04.552 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/identities/SimulatedTemperatureSensor?api-version=2019-11-05 <7> 2020-03-30 13:23:04.774 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received NoContent <7> 2020-03-30 13:23:04.789 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for Delete identity for SimulatedTemperatureSensor <7> 2020-03-30 13:23:04.804 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of desired modules is - {"EdgeGateway":{"status":"running","restartPolicy":"always","version":"1.0","imagePullPolicy<7> 2020-03-30 13:23:04.808 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of current modules is - {"EdgeGateway":{"exitCode":0,"statusDescription":"running","lastStartTimeUtc":"2020-03-30T09<7> 2020-03-30 13:23:04.865 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - HealthRestartPlanner created Plan, with 3 command(s). <6> 2020-03-30 13:23:04.866 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner] - Plan execution started for deployment 50 <7> 2020-03-30 13:23:04.866 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner] - Received new deployment 50 <6> 2020-03-30 13:23:04.866 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory] - Executing command: "Stop module SimulatedTemperatureSensor" <7> 2020-03-30 13:23:04.867 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to stop module SimulatedTemperatureSensor <7> 2020-03-30 13:23:04.867 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:04.868 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:04.870 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/modules/SimulatedTemperatureSensor/stop?api-version=2019-11-05 <7> 2020-03-30 13:23:06.210 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received NoContent <7> 2020-03-30 13:23:06.211 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for stop module SimulatedTemperatureSensor <7> 2020-03-30 13:23:06.212 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory] - Executing command for operation ["stop"] succeeded. <6> 2020-03-30 13:23:06.216 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory] - Executing command: "Remove module SimulatedTemperatureSensor" <7> 2020-03-30 13:23:06.239 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to Delete module SimulatedTemperatureSensor <7> 2020-03-30 13:23:06.307 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:06.316 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock <7> 2020-03-30 13:23:06.318 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/modules/SimulatedTemperatureSensor?api-version=2019-11-05 <7> 2020-03-30 13:23:06.511 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received NoContent <7> 2020-03-30 13:23:06.526 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for Delete module SimulatedTemperatureSensor <7> 2020-03-30 13:23:06.543 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory] - Executing command for operation ["remove"] succeeded. <6> 2020-03-30 13:23:06.544 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory] - Executing command: "Saving SimulatedTemperatureSensor to store" <7> 2020-03-30 13:23:06.546 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory] - Executing command for operation ["Microsoft.Azure.Devices.Edge.Agent.Core.Commands.RemoveFromStoreCommand`1[Microsoft.Azure.Devic<6> 2020-03-30 13:23:06.547 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner] - Plan execution ended for deployment 50 <7> 2020-03-30 13:23:06.551 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///var/run/iotedge/workload.sock to Encrypt <7> 2020-03-30 13:23:06.552 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock <7> 2020-03-30 13:23:06.553 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock <7> 2020-03-30 13:23:06.554 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeAgent/genid/637200529561405818/encrypt?api-version=2019-11-05 <7> 2020-03-30 13:23:06.721 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2020-03-30 13:23:06.723 +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-03-30 13:23:06.738 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.EdgeAgentConnection] - Updating reported properties in IoT Hub <7> 2020-03-30 13:23:06.889 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.EdgeAgentConnection] - Updated reported properties in IoT Hub <7> 2020-03-30 13:23:06.890 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.Reporters.IoTHubReporter] - Updating reported properties cache <6> 2020-03-30 13:23:06.890 +00:00 [INF] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.Reporters.IoTHubReporter] - Updated reported properties <7> 2020-03-30 13:23:06.890 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Finished reconcile operation ```edge-hub logs
``` <7> 2020-03-30 13:23:00.197 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Amqp.ClientConnectionHandler] - Sending twin update to aufderdo-som/SimulatedTemperatureSensor <7> 2020-03-30 13:23:00.199 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Amqp.LinkHandlers.TwinReceivingLinkHandler] - Processed Twin reported properties update for aufderdo-som/SimulatedTemperatureSensor <7> 2020-03-30 13:23:03.609 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Routing.RoutingEdgeHub] - Received 1 message(s) from aufderdo-som/SimulatedTemperatureSensor <7> 2020-03-30 13:23:03.622 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Amqp.LinkHandlers.EventsLinkHandler] - EventsLinkHandler processed 1 messages for aufderdo-som/SimulatedTemperatureSensor <7> 2020-03-30 13:23:04.919 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Syncing stored reported properties to cloud in aufderdo-som/SimulatedTemperatureSensor <7> 2020-03-30 13:23:04.921 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Found stored reported properties for aufderdo-som/SimulatedTemperatureSensor to sync to cloud <7> 2020-03-30 13:23:04.922 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties for aufderdo-som/SimulatedTemperatureSensor <7> 2020-03-30 13:23:04.923 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device aufderdo-som/SimulatedTemperatureSensor <7> 2020-03-30 13:23:05.081 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync failed for aufderdo-som/SimulatedTemperatureSensor 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.<"Temperature Sensor" module logs
``` [2020-03-30 13:18:33 +00:00]: Starting Module SimulatedTemperatureSensor Main() started. Initializing simulated temperature sensor to send 500 messages, at an interval of 5 seconds. To change this, set the environment variable MessageCount to the number of messages that should be sent (set it to -1 to send unlimited messages). Information: Trying to initialize module client using transport type [Amqp_Tcp_Only]. Information: Successfully initialized module client of transport type [Amqp_Tcp_Only]. 03/30/2020 13:18:50> Sending message: 1, Body: [{"machine":{"temperature":21.852548294049942,"pressure":1.0971257550183477},"ambient":{"temperature":20.847223276434104,"humidity":25},"timeCreated":"2020-03-30T13:18:50.0078175Z"}] 03/30/2020 13:18:56> Sending message: 2, Body: [{"machine":{"temperature":22.981913186601322,"pressure":1.2257875782204037},"ambient":{"temperature":20.819714852291959,"humidity":25},"timeCreated":"2020-03-30T13:18:56.6233001Z"}] ... 03/30/2020 13:22:58> Sending message: 50, Body: [{"machine":{"temperature":46.873605863830811,"pressure":3.9476259844870545},"ambient":{"temperature":21.243863026957897,"humidity":24},"timeCreated":"2020-03-30T13:22:58.5613271Z"}] 03/30/2020 13:23:03> Sending message: 51, Body: [{"machine":{"temperature":47.3408867691601,"pressure":4.000860518005581},"ambient":{"temperature":21.428821924109396,"humidity":26},"timeCreated":"2020-03-30T13:23:03.6040707Z"}] Unhandled Exception: System.AggregateException: One or more errors occurred. (A task was canceled.) ---> System.Threading.Tasks.TaskCanceledException: A task was canceled. --- End of inner exception stack trace --- at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification) at System.Threading.Tasks.Task`1.get_Result() at SimulatedTemperatureSensor.Program.Main() in /home/vsts/work/1/s/edge-modules/SimulatedTemperatureSensor/src/Program.cs:line 37 ```IoT Hub diagnostics
``` f2477bc2-b6b8-447d-a347-4a4e51cf66be Azure 2020-03-30T13:23:06Z null /SUBSCRIPTIONS/F5272630-079F-4696-AAA9-0BBF5643BBD3/RESOURCEGROUPS/RG_EOS_DEV/PROVIDERS/MICROSOFT.DEVICES/IOTHUBS/GPIEOS-DEV-IOTHUB moduleDisconnect Connections Information {"deviceId":"aufderdo-som","moduleId":"SimulatedTemperatureSensor","protocol":"Amqp","authType":null,"maskedIpAddress":"85.7.99.XXX","statusCode":null} westeurope f5272630-079f-4696-aaa9-0bbf5643bbd3 RG_EOS_DEV MICROSOFT.DEVICES GPIEOS-DEV-IOTHUB IOTHUBS AzureDiagnostics /subscriptions/f5272630-079f-4696-aaa9-0bbf5643bbd3/resourcegroups/rg_eos_dev/providers/microsoft.devices/iothubs/gpieos-dev-iothub f2477bc2-b6b8-447d-a347-4a4e51cf66be Azure 2020-03-30T13:23:06Z null /SUBSCRIPTIONS/F5272630-079F-4696-AAA9-0BBF5643BBD3/RESOURCEGROUPS/RG_EOS_DEV/PROVIDERS/MICROSOFT.DEVICES/IOTHUBS/GPIEOS-DEV-IOTHUB deviceConnect Connections Error {"deviceId":"aufderdo-som","moduleId":"SimulatedTemperatureSensor","protocol":"Amqp","authType":"{\"scope\":\"module\",\"type\":\"sas\",\"issuer\":\"iothub\",\"acceptingIpFilterRule\":null}","maskedIpAddress":"85.7.99.XXX","statusCode":"404"} westeurope f5272630-079f-4696-aaa9-0bbf5643bbd3 RG_EOS_DEV MICROSOFT.DEVICES GPIEOS-DEV-IOTHUB IOTHUBS 404010 ModuleNotFound AzureDiagnostics /subscriptions/f5272630-079f-4696-aaa9-0bbf5643bbd3/resourcegroups/rg_eos_dev/providers/microsoft.devices/iothubs/gpieos-dev-iothub ```Additional Information
As mentioned above: when deploying using "Create Deployment", everything seems to be ok. What is the difference to "Set Modules"?