Image URI got reverted for a custom module

[mbialecka]

Expected Behavior

Image URI should never change on its own in IoT Hub, or any part of deployment manifest.

Current Behavior

After restarting IoT service on edge device, the image URI in the deployment manifest is incorrect. This is the 2nd time something like this happened to me but I don't have exact 100% repro. The first time the module was completely removed from deployment manifest.

Steps to Reproduce

1. I upgraded security daemon and deployment manifest around the same time - I changed URIs for edge, hub, and my module
2. I verified all modules used the images I set in (1).
3. Setting desired properties for my module didn't work so I restarted the IoT service (it looked like hub was restarted after my module and the new instance didn't know about my module).
4. Edge agent tries to pull incorrect image for my module and the deployment manifest I see in Azure Portal has the old value.
5. No one else has access to this setup so any 3rd party interference can be excluded.

Context (Environment)

Output of iotedge check --output json

Click here

```json {"os_info":{"id":"windows","version_id":"10.0.17763 ","bitness":64},"checks":{"certificates-expiry":{"result":"ok"},"certificates-quickstart":{"result":"warning","details":["Device is using self-signed, automatically generated certs.\nPlease see https://aka.ms/iotedge-prod-checklist-certs for best practices."]},"config-yaml-well-formed":{"result":"ok"},"connect-management-uri":{"result":"ok"},"connection-string":{"result":"ok"},"container-default-connect-iothub-amqp":{"result":"ignored"},"container-default-connect-iothub-https":{"result":"ignored"},"container-default-connect-iothub-mqtt":{"result":"ignored"},"container-engine-dns":{"result":"ok"},"container-engine-is-moby":{"result":"ok"},"container-engine-logrotate":{"result":"warning","details":["Container engine is not configured to rotate module logs which may cause it run out of disk space.\nPlease see https://aka.ms/iotedge-prod-checklist-logs for best practices.\nYou can ignore this warning if you are setting log policy per module in the Edge deployment."]},"container-engine-uri":{"result":"ok"},"container-local-time":{"result":"ok"},"container-module-connect-iothub-amqp":{"result":"ok"},"container-module-connect-iothub-https":{"result":"ok"},"container-module-connect-iothub-mqtt":{"result":"ok"},"edgehub-host-ports":{"result":"ok"},"host-connect-iothub-amqp":{"result":"ok"},"host-connect-iothub-https":{"result":"ok"},"host-connect-iothub-mqtt":{"result":"ok"},"host-local-time":{"result":"ok"},"hostname":{"result":"ok"},"iotedged-version":{"result":"warning","details":["Installed IoT Edge daemon has version 1.0.8~rc1 but version 1.0.7.1 is available.\nPlease see https://aka.ms/iotedge-update-runtime for update instructions."]}}} ```

Device (Host) Operating System

Architecture

amd64

Container Operating System

Windows Server 2019 Datacenter (VM)

Runtime Versions

iotedged

iotedge 1.0.8~rc1 (95c6254573c85635f3cf42fb90fa6ef7a92bb7da)

Edge Agent

1.0.8-rc1

Edge Hub

1.0.8-rc1

Docker

Client:
 Version:           3.0.5
 API version:       1.40
 Go version:        go1.12.1
 Git commit:        ba9934d4
 Built:             Thu Apr 18 22:01:41 2019
 OS/Arch:           windows/amd64
 Experimental:      false

Server:
 Engine:
  Version:          3.0.5
  API version:      1.40 (minimum version 1.24)
  Go version:       go1.12.1
  Git commit:       dbe4a30
  Built:            Thu Apr 18 22:07:58 2019
  OS/Arch:          windows/amd64
  Experimental:     false

Logs

iotedged logs

``` TimeCreated Message ----------- ------- 6/11/2019 10:22:02 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:02.096979800 UTC] "GET /modules/?api-version=2018-06-28 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:04 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:04.321876300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:04 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:04.367953600 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:04 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:04.430887400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:04 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:04.469142100 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:09 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:09.506359800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:09 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:09.555247800 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:09 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:09.615912700 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:09 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:09.648572700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:14 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:14.670718600 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:14 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:14.698979600 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:14 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:14.773782100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:14 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:14.834506200 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:19 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:19.861754 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:20 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:20.172355900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:20 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:20.628187100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:20 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:20.669828600 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:21 AM info: edgelet_core::watchdog -- Checking edge runtime status 6/11/2019 10:22:21 AM info: edgelet_core::watchdog -- Edge runtime is running. 6/11/2019 10:22:25 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:25.717721200 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:25 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:25.748647100 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:25 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:25.821991400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:25 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:25.855117 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:30 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:30.875500900 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:30 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:30.944601900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:31 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:31.148599400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:31 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:31.176225200 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:36 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:36.216401 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:36 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:36.295404100 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:36 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:36.369718 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:36 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:36.395130400 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:41 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:41.414491900 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:41 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:41.444700800 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:41 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:41.501693500 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:41 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:41.533001700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:46 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:46.565492600 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:46 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:46.693323800 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:46 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:46.801890300 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:46 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:46.844898300 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:51 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:51.862656 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:51 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:51.894957 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:51 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:51.963072800 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:51 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:51.997935300 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:22:57 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:57.024606400 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:22:57 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:57.054055400 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:22:57 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:22:57.110773300 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:22:57 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:22:57.150141700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:02 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:02.181216800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:02 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:02.222206900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:02 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:02.267195600 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:02 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:02.300137800 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:07 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:07.332018800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:07 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:07.375098300 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:07 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:07.421673100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:07 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:07.450888500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:12 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:12.472709300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:12 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:12.501800400 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:12 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:12.575982300 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:12 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:12.596848 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:17 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:17.633006300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:17 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:17.663236100 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:17 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:17.737623400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:17 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:17.759067700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:21 AM info: edgelet_core::watchdog -- Checking edge runtime status 6/11/2019 10:23:21 AM info: edgelet_core::watchdog -- Edge runtime is running. 6/11/2019 10:23:22 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:22.783799900 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:22 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:22.813701100 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:22 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:22.873605200 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:22 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:22.904562700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:27 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:27.951626900 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:28 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:28.017478200 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:28 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:28.116784300 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:28 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:28.138876400 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:33 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:33.164104200 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:33 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:33.194219400 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:33 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:33.250448 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:33 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:33.283786800 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:38 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:38.309612200 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:38 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:38.348496500 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:38 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:38.406749700 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:38 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:38.440813900 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:43 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:43.462000300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:43 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:43.522112600 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:43 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:43.597664400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:43 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:43.632550400 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:48 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:48.659544800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:48 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:48.719873700 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:48 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:48.785239900 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:48 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:48.812470200 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:53 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:53.829345100 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:53 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:53.859161900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:53 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:53.931848600 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:53 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:53.963165500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:23:58 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:58.979730500 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:23:59 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:59.008924700 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:23:59 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:23:59.081078900 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:23:59 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:23:59.105884 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:04 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:04.124021800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:04 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:04.153117100 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:04 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:04.225557600 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:04 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:04.252730900 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:09 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:09.273384 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:09 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:09.303583600 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:09 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:09.391803100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:09 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:09.417138200 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:14 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:14.438952800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:14 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:14.479626500 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:14 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:14.523181300 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:14 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:14.562068500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:19 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:19.591592200 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:19 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:19.643623100 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:19 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:19.782667700 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:19 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:19.800836200 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:21 AM info: edgelet_core::watchdog -- Checking edge runtime status 6/11/2019 10:24:21 AM info: edgelet_core::watchdog -- Edge runtime is running. 6/11/2019 10:24:24 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:24.814679200 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:24 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:24.844657700 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:24 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:24.901736200 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:24 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:24.933830900 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:29 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:29.957064800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:30 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:30.028739800 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:30 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:30.091701900 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:30 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:30.111543500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:35 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:35.152389700 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:35 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:35.202655400 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:35 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:35.250732500 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:35 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:35.282860500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:40 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:40.304741300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:40 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:40.349185400 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:40 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:40.404923600 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:40 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:40.434307600 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:45 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:45.474116900 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:45 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:45.518715300 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:45 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:45.571031200 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:45 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:45.603273100 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:50 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:50.622073800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:50 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:50.653089300 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:50 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:50.723705700 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:50 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:50.745864600 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:24:55 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:55.764872 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:24:55 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:55.843160200 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:24:55 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:24:55.962243100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:24:55 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:24:55.995885300 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:01 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:01.016781400 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:01 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:01.049205800 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:01 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:01.184797400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:01 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:01.221025700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:06 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:06.248384400 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:06 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:06.280649600 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:06 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:06.337953500 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:06 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:06.370825100 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:11 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:11.393900 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:11 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:11.424355400 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:11 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:11.480625400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:11 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:11.513084900 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:16 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:16.538240600 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:16 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:16.584215600 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:16 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:16.636937400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:16 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:16.663992200 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:21 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:21.686007600 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:21 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:21.716404300 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:21 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:21.785241900 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:21 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:21.813299800 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:21 AM info: edgelet_core::watchdog -- Checking edge runtime status 6/11/2019 10:25:21 AM info: edgelet_core::watchdog -- Edge runtime is running. 6/11/2019 10:25:26 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:26.845404100 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:26 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:26.891272200 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:26 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:26.934267100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:26 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:26.972656800 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:31 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:31.999123100 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:32 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:32.042613200 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:32 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:32.085842400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:32 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:32.121306600 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:37 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:37.149685100 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:37 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:37.178622500 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:37 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:37.237727300 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:37 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:37.268663300 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:42 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:42.304073700 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:42 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:42.334134900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:42 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:42.406434500 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:42 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:42.428369100 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:47 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:47.450647300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:47 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:47.479891700 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:47 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:47.536973300 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:47 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:47.573230500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:52 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:52.602302700 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:52 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:52.761286 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:52 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:52.810439700 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:52 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:52.844505200 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:25:57 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:57.878096700 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:25:58 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:58.078296400 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:25:58 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:25:58.176286700 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:25:58 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:25:58.207099800 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:03 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:03.232557400 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:03 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:03.404334400 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:03 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:03.455052600 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:03 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:03.489703500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:08 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:08.510980800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:08 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:08.540184300 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:08 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:08.614543400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:08 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:08.634395200 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:13 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:13.662950 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:13 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:13.694026900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:13 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:13.773309200 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:13 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:13.794321700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:18 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:18.819951400 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:18 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:18.865544200 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:18 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:18.911181800 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:18 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:18.945521100 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:21 AM info: edgelet_core::watchdog -- Checking edge runtime status 6/11/2019 10:26:21 AM info: edgelet_core::watchdog -- Edge runtime is running. 6/11/2019 10:26:23 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:23.971703300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:24 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:24.015373300 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:24 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:24.076098200 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:24 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:24.103851 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:29 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:29.124248800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:29 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:29.168972600 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:29 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:29.230653400 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:29 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:29.265305500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:34 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:34.282525800 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:34 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:34.319434 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:34 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:34.390211900 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:34 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:34.421441300 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:39 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:39.462302300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:39 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:39.509001700 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:39 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:39.564798100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:39 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:39.603149 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:44 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:44.636555900 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:44 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:44.681444500 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:44 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:44.792721100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:44 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:44.814724500 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:49 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:49.829493500 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:50 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:50.203363900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:50 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:50.279415900 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:50 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:50.303078700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:26:55 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:55.332645200 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:26:55 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:55.362744900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:26:55 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:26:55.421838100 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:26:55 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:26:55.456664800 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) 6/11/2019 10:27:00 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:27:00.482587300 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1616 "-" "-" auth_id(-) 6/11/2019 10:27:00 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:27:00.531569900 UTC] "GET /identities/?api-version=2019-01-30 HTTP/1.1" 200 OK 316 "-" "-" auth_id(-) 6/11/2019 10:27:00 AM info: edgelet_http::logging -- [mgmt] - - - [2019-06-11 17:27:00.591579600 UTC] "PUT /identities/AzureBlobStorage?api-version=2019-01-30 HTTP/1.1" 200 OK 106 "-" "-" auth_id(-) 6/11/2019 10:27:00 AM info: edgelet_http::logging -- [work] - - - [2019-06-11 17:27:00.613494700 UTC] "POST /modules/%24edgeAgent/genid/636941583382838107/encrypt?api-version=2019-01-30 HTTP/1.1" 200 OK 2073 "-" "-" auth_id(-) ```

edge-agent logs

``` 2019-06-11 16:38:42.539 +00:00 Edge Agent Main() <6> 2019-06-11 09:38:44.145 -07:00 [INF] - Initializing Edge Agent. <6> 2019-06-11 09:38:45.182 -07:00 [INF] - Version - 1.0.8-rc1.22563438 (95c6254573c85635f3cf42fb90fa6ef7a92bb7da) <6> 2019-06-11 09:38:45.183 -07:00 [INF] - ?????????????????? ????????????????????????????????? ?????????????????????????????? ???????????????????????? ????????????????????????????????????????????????????????? ????????????????????????????????????????????????????????? ???????????????????????? ??????????????? ????????? ??????????????????????????????????????????????????? ???????????????????????? ??????????????? ????????? ??????????????????????????????????????????????????? ????????? ????????????????????????????????????????????????????????????????????? ????????????????????????????????? ????????? ????????????????????????????????? ????????????????????? ????????? ????????????????????????????????? ????????? ????????????????????? ??????????????????????????? ????????????????????????????????????????????? ????????????????????? ???????????????????????? ??????????????????????????????????????????????????????????????? ???????????????????????????????????????????????????????????????????????? ???????????????????????? ?????????????????? ????????? ????????? ?????????????????? ????????? ?????????????????? ?????????????????????????????? ?????????????????? ????????? ????????? ?????????????????? ????????? ?????????????????? ??????????????????????????? ???????????????????????????????????? ????????? ??????????????????????????????????????????????????????????????????????????????????????????????????? ????????? ????????????????????? ????????? ????????????????????????????????????????????? ????????????????????? ???????????????????????? <6> 2019-06-11 09:38:46.631 -07:00 [INF] - Started operation refresh twin config <6> 2019-06-11 09:38:46.722 -07:00 [INF] - Edge agent attempting to connect to IoT Hub via Amqp_Tcp_Only... <6> 2019-06-11 09:38:48.662 -07:00 [INF] - Created persistent store at C:\Windows\TEMP\edgeAgent <6> 2019-06-11 09:38:49.661 -07:00 [INF] - Edge agent connected to IoT Hub via Amqp_Tcp_Only. <6> 2019-06-11 09:38:49.864 -07:00 [INF] - Initialized new module client with subscriptions enabled <6> 2019-06-11 09:38:50.078 -07:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 4 and reported properties version 110. <6> 2019-06-11 09:38:51.307 -07:00 [INF] - Plan execution started for deployment 4 <6> 2019-06-11 09:38:51.320 -07:00 [INF] - Executing command: "Saving edgeHub to store" <6> 2019-06-11 09:38:51.346 -07:00 [INF] - Executing command: "Saving AzureBlobStorage to store" <6> 2019-06-11 09:38:51.408 -07:00 [INF] - Executing command: "Command Group: (\n [Command Group: (\n [Prepare update module edgeHub]\n [Stop module edgeHub]\n [Update module edgeHub]\n)]\n [Start module edgeHub]\n)" <6> 2019-06-11 09:38:51.412 -07:00 [INF] - Executing command: "Command Group: (\n [Prepare update module edgeHub]\n [Stop module edgeHub]\n [Update module edgeHub]\n)" <6> 2019-06-11 09:39:01.349 -07:00 [INF] - Executing command: "Start module edgeHub" <6> 2019-06-11 09:39:06.347 -07:00 [INF] - Executing command: "Command Group: (\n [Command Group: (\n [Prepare update module AzureBlobStorage]\n [Stop module AzureBlobStorage]\n [Update module AzureBlobStorage]\n)]\n [Start module AzureBlobStorage]\n)" <6> 2019-06-11 09:39:06.347 -07:00 [INF] - Executing command: "Command Group: (\n [Prepare update module AzureBlobStorage]\n [Stop module AzureBlobStorage]\n [Update module AzureBlobStorage]\n)" <3> 2019-06-11 09:39:07.031 -07:00 [ERR] - Executing command for operation ["update"] failed. Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException- Message:Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown, StatusCode:404, at: at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 194 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\versioning\ModuleManagementHttpClientVersioned.cs:line 124 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 185 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 <3> 2019-06-11 09:39:08.532 -07:00 [ERR] - Executing command for operation ["Command Group: (\n [Command Group: (\n [Prepare update module AzureBlobStorage]\n [Stop module AzureBlobStorage]\n [Update module AzureBlobStorage]\n)]\n [Start module AzureBlobStorage]\n)"] failed. Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException- Message:Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown, StatusCode:404, at: at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 194 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\versioning\ModuleManagementHttpClientVersioned.cs:line 124 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 185 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 <3> 2019-06-11 09:39:08.539 -07:00 [ERR] - Step failed in deployment 4, continuing execution. Failure when running command Command Group: ( [Command Group: ( [Prepare update module AzureBlobStorage] [Stop module AzureBlobStorage] [Update module AzureBlobStorage] )] [Start module AzureBlobStorage] ). Will retry in 00s. <6> 2019-06-11 09:39:08.543 -07:00 [INF] - Plan execution ended for deployment 4 <3> 2019-06-11 09:39:08.545 -07:00 [ERR] - Edge agent plan execution failed. System.AggregateException: One or more errors occurred. (Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown) ---> Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException: Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 194 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\versioning\ModuleManagementHttpClientVersioned.cs:line 124 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 185 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\planrunners\OrdererdRetryPlanRunner.cs:line 87 --- End of inner exception stack trace --- at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner.<>c.b__7_0(List`1 f) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\planrunners\OrdererdRetryPlanRunner.cs:line 115 at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\planrunners\OrdererdRetryPlanRunner.cs:line 116 at Microsoft.Azure.Devices.Edge.Agent.Core.Agent.ReconcileAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\Agent.cs:line 134 ---> (Inner Exception #0) Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException- Message:Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown, StatusCode:404, at: at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 194 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\versioning\ModuleManagementHttpClientVersioned.cs:line 124 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 185 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\planrunners\OrdererdRetryPlanRunner.cs:line 87<--- <4> 2019-06-11 09:39:08.667 -07:00 [WRN] - Reconcile failed because of the an exception System.AggregateException: One or more errors occurred. (Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown) ---> Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException: Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 194 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\versioning\ModuleManagementHttpClientVersioned.cs:line 124 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 185 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\planrunners\OrdererdRetryPlanRunner.cs:line 87 --- End of inner exception stack trace --- at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner.<>c.b__7_0(List`1 f) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\planrunners\OrdererdRetryPlanRunner.cs:line 115 at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\planrunners\OrdererdRetryPlanRunner.cs:line 116 at Microsoft.Azure.Devices.Edge.Agent.Core.Agent.ReconcileAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\Agent.cs:line 134 at Microsoft.Azure.Devices.Edge.Agent.Core.Agent.ReconcileAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\Agent.cs:line 145 ---> (Inner Exception #0) Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException- Message:Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown, StatusCode:404, at: at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 194 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\versioning\ModuleManagementHttpClientVersioned.cs:line 124 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 185 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunners.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\planrunners\OrdererdRetryPlanRunner.cs:line 87<--- <6> 2019-06-11 09:39:09.488 -07:00 [INF] - Updated reported properties <6> 2019-06-11 09:39:14.694 -07:00 [INF] - Plan execution started for deployment 4 <6> 2019-06-11 09:39:14.696 -07:00 [INF] - Executing command: "Saving AzureBlobStorage to store" <6> 2019-06-11 09:39:14.700 -07:00 [INF] - Plan execution ended for deployment 4 <6> 2019-06-11 09:39:14.866 -07:00 [INF] - Updated reported properties <6> 2019-06-11 09:39:19.990 -07:00 [INF] - Plan execution started for deployment 4 <6> 2019-06-11 09:39:19.990 -07:00 [INF] - Executing command: "Saving AzureBlobStorage to store" <6> 2019-06-11 09:39:19.991 -07:00 [INF] - Plan execution ended for deployment 4 <6> 2019-06-11 09:39:25.218 -07:00 [INF] - Plan execution started for deployment 4 <6> 2019-06-11 09:39:25.219 -07:00 [INF] - Executing command: "Saving AzureBlobStorage to store" <6> 2019-06-11 09:39:25.219 -07:00 [INF] - Plan execution ended for deployment 4 <6> 2019-06-11 09:39:30.364 -07:00 [INF] - Plan execution started for deployment 4 <6> 2019-06-11 09:39:30.365 -07:00 [INF] - Executing command: "Saving AzureBlobStorage to store" <6> 2019-06-11 09:39:30.365 -07:00 [INF] - Executing command: "Command Group: (\n [Command Group: (\n [Prepare update module AzureBlobStorage]\n [Stop module AzureBlobStorage]\n [Update module AzureBlobStorage]\n)]\n [Start module AzureBlobStorage]\n)" <6> 2019-06-11 09:39:30.365 -07:00 [INF] - Executing command: "Command Group: (\n [Prepare update module AzureBlobStorage]\n [Stop module AzureBlobStorage]\n [Update module AzureBlobStorage]\n)" <3> 2019-06-11 09:39:30.754 -07:00 [ERR] - Executing command for operation ["update"] failed. Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException- Message:Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown, StatusCode:404, at: at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 194 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\versioning\ModuleManagementHttpClientVersioned.cs:line 124 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 185 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 <3> 2019-06-11 09:39:30.756 -07:00 [ERR] - Executing command for operation ["Command Group: (\n [Command Group: (\n [Prepare update module AzureBlobStorage]\n [Stop module AzureBlobStorage]\n [Update module AzureBlobStorage]\n)]\n [Start module AzureBlobStorage]\n)"] failed. Microsoft.Azure.Devices.Edge.Agent.Edgelet.EdgeletCommunicationException- Message:Error calling prepare update for module module AzureBlobStorage: Could not prepare update for module "AzureBlobStorage" caused by: Could not pull image mazurecr.azurecr.io/azure-blob-storage:1-win caused by: manifest for mazurecr.azurecr.io/azure-blob-storage:1-win not found: manifest unknown: manifest unknown, StatusCode:404, at: at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 194 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\versioning\ModuleManagementHttpClientVersioned.cs:line 124 at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2019_01_30.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Edgelet\version_2019_01_30\ModuleManagementHttpClient.cs:line 185 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\commands\GroupCommand.cs:line 35 at Microsoft.Azure.Devices.Edge.Agent.Core.LoggingCommandFactory.LoggingCommand.ExecuteAsync(CancellationToken token) in C:\agent\_work\4\s\edge-agent\src\Microsoft.Azure.Devices.Edge.Agent.Core\LoggingCommandFactory.cs:line 60 <3> 2019-06-11 09:39:30.757 -07:00 [ERR] - Step failed in deployment 4, continuing execution. Failure when running command Command Group: ( [Command Group: ( [Prepare update module AzureBlobStorage] [Stop module AzureBlobStorage] [Update module AzureBlobStorage] )] [Start module AzureBlobStorage] ). Will retry in -01s. <6> 2019-06-11 09:39:30.758 -07:00 [INF] - Plan execution ended for deployment 4 ```

edge-hub logs

``` 2019-06-11 16:39:10.134 +00:00 Edge Hub Main() <7> 2019-06-11 09:39:11.903 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to CreateServerCertificateAsync <7> 2019-06-11 09:39:13.516 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:13.582 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:13.621 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/certificate/server?api-version=2019-01-30 <7> 2019-06-11 09:39:14.627 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received Created <7> 2019-06-11 09:39:14.795 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for CreateServerCertificateAsync [06/11/2019 04:39:16.006 PM] Found intermediate certificates: [CN=iotedged workload ca:8/20/2019 2:45:58 PM],[CN=Test Edge Device CA:8/20/2019 2:45:58 PM],[CN=Test Edge Owner CA:8/20/2019 2:45:58 PM] <7> 2019-06-11 09:39:16.017 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to TrustBundleAsync <7> 2019-06-11 09:39:16.038 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:16.040 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:16.040 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/trust-bundle?api-version=2019-01-30 <7> 2019-06-11 09:39:16.056 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:16.064 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for TrustBundleAsync <6> 2019-06-11 09:39:19.607 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule] - Created persistent store at C:\Windows\TEMP\edgeHub <6> 2019-06-11 09:39:19.724 -07:00 [INF] [EdgeHub] - Initializing Edge Hub <6> 2019-06-11 09:39:19.725 -07:00 [INF] [EdgeHub] - ?????????????????? ????????????????????????????????? ?????????????????????????????? ???????????????????????? ????????????????????????????????????????????????????????? ????????????????????????????????????????????????????????? ???????????????????????? ??????????????? ????????? ??????????????????????????????????????????????????? ???????????????????????? ??????????????? ????????? ??????????????????????????????????????????????????? ????????? ????????????????????????????????????????????????????????????????????? ????????????????????????????????? ????????? ????????????????????????????????? ????????????????????? ????????? ????????????????????????????????? ????????? ????????????????????? ??????????????????????????? ????????????????????????????????????????????? ????????????????????? ???????????????????????? ??????????????????????????????????????????????????????????????? ???????????????????????????????????????????????????????????????????????? ???????????????????????? ?????????????????? ????????? ????????? ?????????????????? ????????? ?????????????????? ?????????????????????????????? ?????????????????? ????????? ????????? ?????????????????? ????????? ?????????????????? ??????????????????????????? ???????????????????????????????????? ????????? ??????????????????????????????????????????????????????????????????????????????????????????????????? ????????? ????????????????????? ????????? ????????????????????????????????????????????? ????????????????????? ???????????????????????? <6> 2019-06-11 09:39:19.728 -07:00 [INF] [EdgeHub] - Version - 1.0.8-rc1.22563438 (95c6254573c85635f3cf42fb90fa6ef7a92bb7da) <6> 2019-06-11 09:39:19.728 -07:00 [INF] [EdgeHub] - OptimizeForPerformance=True <6> 2019-06-11 09:39:19.736 -07:00 [INF] [EdgeHub] - Loaded server certificate with expiration date of "2019-08-20T14:45:58.0000000-07:00" <6> 2019-06-11 09:39:19.996 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Created device scope identities cache <7> 2019-06-11 09:39:19.999 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Initializing device scope identities cache refresh task to run every 60 minutes. <6> 2019-06-11 09:39:20.004 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Created new message store <6> 2019-06-11 09:39:20.014 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Starting refresh of device scope identities cache <7> 2019-06-11 09:39:20.017 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ServiceProxy] - Created iterator to iterate all service identities in the scope of this IoT Edge device <6> 2019-06-11 09:39:20.017 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Started task to cleanup processed and stale messages <7> 2019-06-11 09:39:20.159 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to SignAsync <7> 2019-06-11 09:39:20.206 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:20.207 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:20.208 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/sign?api-version=2019-01-30 <7> 2019-06-11 09:39:20.299 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:20.313 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for SignAsync <7> 2019-06-11 09:39:20.331 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00 <6> 2019-06-11 09:39:20.678 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Initialized storing twin manager <7> 2019-06-11 09:39:20.737 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - ConnectionManager provided <6> 2019-06-11 09:39:20.747 -07:00 [INF] [EdgeHub] - Initializing configuration <6> 2019-06-11 09:39:20.817 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - New device connection for device edge-02/$edgeHub <7> 2019-06-11 09:39:20.823 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.SubscriptionProcessor] - Adding subscription DesiredPropertyUpdates for client edge-02/$edgeHub. <7> 2019-06-11 09:39:20.841 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.SubscriptionProcessor] - Adding subscription Methods for client edge-02/$edgeHub. <7> 2019-06-11 09:39:20.933 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:20.963 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Getting service identity for edge-02/$edgeHub <7> 2019-06-11 09:39:20.982 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:21.001 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Creating cloud connection for client edge-02/$edgeHub. Client identity is not in device scope, attempting to use client credentials. <7> 2019-06-11 09:39:21.015 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Creating cloud connection for client edge-02/$edgeHub using client credentials <7> 2019-06-11 09:39:21.104 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Storing reported properties in store for edge-02/$edgeHub with version 0 <6> 2019-06-11 09:39:21.110 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Attempting to connect to IoT Hub for client edge-02/$edgeHub via AMQP... <7> 2019-06-11 09:39:21.123 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties in store with version 0 for edge-02/$edgeHub <7> 2019-06-11 09:39:21.136 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnection] - Initialized connection for edge-02/$edgeHub <6> 2019-06-11 09:39:21.150 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Starting periodic operation Get EdgeHub config... <7> 2019-06-11 09:39:21.174 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Getting twin for edge-02/$edgeHub <6> 2019-06-11 09:39:21.186 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Started operation Get EdgeHub config <6> 2019-06-11 09:39:21.186 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Initialized edge hub configuration <6> 2019-06-11 09:39:21.206 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionReauthenticator] - Starting timer to authenticate connections with a period of 300 seconds <7> 2019-06-11 09:39:21.221 -07:00 [DBG] [EdgeHub] - Waiting on shutdown handler to trigger <7> 2019-06-11 09:39:21.297 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.numHeapArenas: 4 <7> 2019-06-11 09:39:21.298 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.numDirectArenas: 4 <7> 2019-06-11 09:39:21.298 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.pageSize: 8192 <7> 2019-06-11 09:39:21.298 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.maxOrder: 11 <7> 2019-06-11 09:39:21.307 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.chunkSize: 16777216 <7> 2019-06-11 09:39:21.307 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.tinyCacheSize: 512 <7> 2019-06-11 09:39:21.307 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.smallCacheSize: 256 <7> 2019-06-11 09:39:21.307 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.normalCacheSize: 64 <7> 2019-06-11 09:39:21.307 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.maxCachedBufferCapacity: 32768 <7> 2019-06-11 09:39:21.307 -07:00 [DBG] [DotNetty.Buffers.PooledByteBufferAllocator] - -Dio.netty.allocator.cacheTrimInterval: 8192 <7> 2019-06-11 09:39:21.310 -07:00 [DBG] [DotNetty.Common.Internal.PlatformDependent] - -Dio.netty.noPreferDirect: True <7> 2019-06-11 09:39:21.527 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiClient] - Got valid device scope result <7> 2019-06-11 09:39:21.531 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ServiceProxy] - Received scope result with 1 devices, 3 modules and null continuation link <6> 2019-06-11 09:39:21.569 -07:00 [INF] [EdgeHub] - Scheduling server certificate renewal for "2019-08-20T14:43:28.0000973Z". <7> 2019-06-11 09:39:21.569 -07:00 [DBG] [EdgeHub] - Scheduling server certificate renewal timer for "2019-07-06T13:10:45.2166765Z" (clamped to Int32.MaxValue). <6> 2019-06-11 09:39:21.571 -07:00 [INF] [EdgeHub] - Starting protocol heads - (MQTT, AMQP, HTTP) <7> 2019-06-11 09:39:21.579 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to Encrypt <6> 2019-06-11 09:39:21.583 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MqttProtocolHead] - Starting MQTT head <7> 2019-06-11 09:39:21.592 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:21.593 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:21.593 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/encrypt?api-version=2019-01-30 <7> 2019-06-11 09:39:21.610 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:21.614 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for Encrypt <7> 2019-06-11 09:39:21.629 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - edge-02 is in device scope, adding to cache. <7> 2019-06-11 09:39:21.630 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to Encrypt <7> 2019-06-11 09:39:21.630 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:21.631 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:21.631 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/encrypt?api-version=2019-01-30 <7> 2019-06-11 09:39:21.639 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:21.639 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for Encrypt <7> 2019-06-11 09:39:21.639 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - edge-02/$edgeAgent is in device scope, adding to cache. <7> 2019-06-11 09:39:21.639 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to Encrypt <7> 2019-06-11 09:39:21.639 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:21.640 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:21.641 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/encrypt?api-version=2019-01-30 <7> 2019-06-11 09:39:21.648 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:21.648 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for Encrypt <7> 2019-06-11 09:39:21.649 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - edge-02/$edgeHub is in device scope, adding to cache. <7> 2019-06-11 09:39:21.649 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to Encrypt <7> 2019-06-11 09:39:21.649 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:21.650 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:21.650 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/encrypt?api-version=2019-01-30 <7> 2019-06-11 09:39:21.658 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:21.658 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for Encrypt <7> 2019-06-11 09:39:21.658 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - edge-02/AzureBlobStorage is in device scope, adding to cache. <7> 2019-06-11 09:39:21.660 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Done refreshing device scope identities cache. Waiting for 60 minutes. <6> 2019-06-11 09:39:21.733 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MqttProtocolHead] - Initializing TLS endpoint on port 8883 for MQTT head. <7> 2019-06-11 09:39:21.746 -07:00 [DBG] [DotNetty.Transport.Channels.DefaultChannelId] - -Dio.netty.processId: 2371511 (auto-detected) <7> 2019-06-11 09:39:21.780 -07:00 [DBG] [DotNetty.Transport.Channels.DefaultChannelId] - -Dio.netty.machineId: 00:15:5D:FF:FE:B1:A5:B8 (auto-detected) <7> 2019-06-11 09:39:21.784 -07:00 [DBG] [DotNetty.Buffers.ByteBufferUtil] - -Dio.netty.allocator.type: pooled <7> 2019-06-11 09:39:21.788 -07:00 [DBG] [DotNetty.Common.ResourceLeakDetector] - -Dio.netty.leakDetection.level: simple <7> 2019-06-11 09:39:21.788 -07:00 [DBG] [DotNetty.Common.ResourceLeakDetector] - -Dio.netty.leakDetection.targetRecords: 4 <6> 2019-06-11 09:39:21.822 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Amqp.AmqpProtocolHead] - Starting AMQP head <7> 2019-06-11 09:39:21.856 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Amqp.AmqpProtocolHead] - WebSockets listener registered. <6> 2019-06-11 09:39:21.944 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Mqtt.MqttProtocolHead] - Started MQTT head <6> 2019-06-11 09:39:22.005 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Amqp.AmqpProtocolHead] - Started AMQP head <6> 2019-06-11 09:39:22.007 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Http.HttpProtocolHead] - Starting HTTP head <7> 2019-06-11 09:39:22.030 -07:00 [DBG] [Microsoft.AspNetCore.Hosting.Internal.WebHost] - Hosting starting <6> 2019-06-11 09:39:22.350 -07:00 [INF] [Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager] - User profile is available. Using '"C:\\Users\\ContainerUser\\AppData\\Local\\ASP.NET\\DataProtection-Keys"' as key repository and Windows DPAPI to encrypt keys at rest. <7> 2019-06-11 09:39:22.358 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to SignAsync <7> 2019-06-11 09:39:22.359 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:22.360 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:22.360 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/sign?api-version=2019-01-30 <7> 2019-06-11 09:39:22.401 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:22.401 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for SignAsync <7> 2019-06-11 09:39:22.430 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.KeyManagement.DefaultKeyResolver] - Repository contains no viable default key. Caller should generate a key with immediate activation. <7> 2019-06-11 09:39:22.431 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider] - Policy resolution states that a new key should be added to the key ring. <6> 2019-06-11 09:39:22.450 -07:00 [INF] [Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager] - Creating key {60f64cf8-f051-4855-8509-e5cc5c90627c} with creation date 2019-06-11 16:39:22Z, activation date 2019-06-11 16:39:22Z, and expiration date 2019-09-09 16:39:22Z. <7> 2019-06-11 09:39:22.486 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager] - Descriptor deserializer type for key {60f64cf8-f051-4855-8509-e5cc5c90627c} is '"Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Version=2.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60"'. <7> 2019-06-11 09:39:22.509 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager] - No key escrow sink found. Not writing key {60f64cf8-f051-4855-8509-e5cc5c90627c} to escrow. <7> 2019-06-11 09:39:22.532 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.XmlEncryption.DpapiXmlEncryptor] - Encrypting to Windows DPAPI for current user account ("User Manager\\ContainerUser"). <6> 2019-06-11 09:39:22.598 -07:00 [INF] [Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository] - Writing data to file '"C:\\Users\\ContainerUser\\AppData\\Local\\ASP.NET\\DataProtection-Keys\\key-60f64cf8-f051-4855-8509-e5cc5c90627c.xml"'. <7> 2019-06-11 09:39:22.604 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager] - Key cache expiration token triggered by '"CreateNewKey"' operation. <7> 2019-06-11 09:39:22.615 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository] - Reading data from file '"C:\\Users\\ContainerUser\\AppData\\Local\\ASP.NET\\DataProtection-Keys\\key-60f64cf8-f051-4855-8509-e5cc5c90627c.xml"'. <7> 2019-06-11 09:39:22.621 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager] - Found key {60f64cf8-f051-4855-8509-e5cc5c90627c}. <7> 2019-06-11 09:39:22.649 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.KeyManagement.DefaultKeyResolver] - Considering key {60f64cf8-f051-4855-8509-e5cc5c90627c} with expiration date 2019-09-09 16:39:22Z as default key. <7> 2019-06-11 09:39:22.670 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.TypeForwardingActivator] - Forwarded activator type request from "Microsoft.AspNetCore.DataProtection.XmlEncryption.DpapiXmlDecryptor, Microsoft.AspNetCore.DataProtection, Version=2.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60" to "Microsoft.AspNetCore.DataProtection.XmlEncryption.DpapiXmlDecryptor, Microsoft.AspNetCore.DataProtection, Culture=neutral, PublicKeyToken=adb9793829ddae60" <7> 2019-06-11 09:39:22.674 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.XmlEncryption.DpapiXmlDecryptor] - Decrypting secret element using Windows DPAPI. <7> 2019-06-11 09:39:22.677 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.TypeForwardingActivator] - Forwarded activator type request from "Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Version=2.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60" to "Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.ConfigurationModel.AuthenticatedEncryptorDescriptorDeserializer, Microsoft.AspNetCore.DataProtection, Culture=neutral, PublicKeyToken=adb9793829ddae60" <7> 2019-06-11 09:39:22.691 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.CngCbcAuthenticatedEncryptorFactory] - Opening CNG algorithm '"AES"' from provider 'null' with chaining mode CBC. <7> 2019-06-11 09:39:22.701 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.AuthenticatedEncryption.CngCbcAuthenticatedEncryptorFactory] - Opening CNG algorithm '"SHA256"' from provider 'null' with HMAC. <7> 2019-06-11 09:39:22.725 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider] - Using key {60f64cf8-f051-4855-8509-e5cc5c90627c} as the default key. <7> 2019-06-11 09:39:22.728 -07:00 [DBG] [Microsoft.AspNetCore.DataProtection.Internal.DataProtectionStartupFilter] - Key ring with default key {60f64cf8-f051-4855-8509-e5cc5c90627c} was loaded during application startup. <7> 2019-06-11 09:39:22.843 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.MvcJsonOptions] - Compatibility switch "AllowInputFormatterExceptionMessages" in type "MvcJsonOptions" is using default value False <7> 2019-06-11 09:39:22.920 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Received connection status changed callback with connection status Connected and reason Connection_Ok for edge-02/$edgeHub <7> 2019-06-11 09:39:22.969 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded <7> 2019-06-11 09:39:22.978 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.MvcOptions] - Compatibility switch "AllowCombiningAuthorizeFilters" in type "MvcOptions" is using default value False <7> 2019-06-11 09:39:22.978 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.MvcOptions] - Compatibility switch "AllowBindingHeaderValuesToNonStringModelTypes" in type "MvcOptions" is using default value False <7> 2019-06-11 09:39:22.978 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.MvcOptions] - Compatibility switch "AllowValidatingTopLevelNodes" in type "MvcOptions" is using default value False <7> 2019-06-11 09:39:22.979 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.MvcOptions] - Compatibility switch "InputFormatterExceptionPolicy" in type "MvcOptions" is using default value AllExceptions <7> 2019-06-11 09:39:22.979 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.MvcOptions] - Compatibility switch "SuppressBindingUndefinedValueToEnumType" in type "MvcOptions" is using default value False <6> 2019-06-11 09:39:23.013 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Exiting disconnected state <6> 2019-06-11 09:39:23.020 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Received device connected callback <7> 2019-06-11 09:39:23.032 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Syncing stored reported properties to cloud in edge-02/$edgeHub <6> 2019-06-11 09:39:23.042 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.SubscriptionProcessor] - Device connected to cloud, processing subscriptions for connected clients. <6> 2019-06-11 09:39:23.044 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.SubscriptionProcessor] - Processing subscriptions for client edge-02/$edgeHub. <7> 2019-06-11 09:39:23.049 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.RazorPages.RazorPagesOptions] - Compatibility switch "AllowAreas" in type "RazorPagesOptions" is using default value False <7> 2019-06-11 09:39:23.049 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.RazorPages.RazorPagesOptions] - Compatibility switch "AllowMappingHeadRequestsToGetHandler" in type "RazorPagesOptions" is using default value False <7> 2019-06-11 09:39:23.054 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionReauthenticator] - EdgeHub cloud connection established, refreshing device scope cache. <7> 2019-06-11 09:39:23.055 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Received request to refresh cache. <7> 2019-06-11 09:39:23.058 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Found stored reported properties for edge-02/$edgeHub to sync to cloud <6> 2019-06-11 09:39:23.058 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Cloud connection for edge-02/$edgeHub is True <6> 2019-06-11 09:39:23.069 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Connection status for edge-02/$edgeHub changed to ConnectionEstablished <7> 2019-06-11 09:39:23.070 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Invoking cloud connection established event for edge-02/$edgeHub <7> 2019-06-11 09:39:23.075 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:23.082 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Device scope identities refresh is ready because a refresh was signalled. <6> 2019-06-11 09:39:23.083 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Starting refresh of device scope identities cache <7> 2019-06-11 09:39:23.083 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ServiceProxy] - Created iterator to iterate all service identities in the scope of this IoT Edge device <7> 2019-06-11 09:39:23.083 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to SignAsync <7> 2019-06-11 09:39:23.083 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.084 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.085 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/sign?api-version=2019-01-30 <6> 2019-06-11 09:39:23.088 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - Entering connected state <7> 2019-06-11 09:39:23.092 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation OpenAsync succeeded for edge-02/$edgeHub <7> 2019-06-11 09:39:23.096 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:23.096 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for SignAsync <6> 2019-06-11 09:39:23.096 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Created cloud proxy for client edge-02/$edgeHub via AMQP, with client operation timeout 20 seconds. <6> 2019-06-11 09:39:23.106 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Initialized cloud proxy 3ead1dd2-9040-4034-b99b-6f1fbb451e35 for edge-02/$edgeHub <6> 2019-06-11 09:39:23.109 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection] - Created cloud connection for client edge-02/$edgeHub <7> 2019-06-11 09:39:23.130 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device edge-02/$edgeHub <7> 2019-06-11 09:39:23.149 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.SubscriptionProcessor] - Processing subscription DesiredPropertyUpdates for client edge-02/$edgeHub. <7> 2019-06-11 09:39:23.256 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device edge-02/$edgeHub <7> 2019-06-11 09:39:23.273 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.MvcViewOptions] - Compatibility switch "SuppressTempDataAttributePrefix" in type "MvcViewOptions" is using default value False <7> 2019-06-11 09:39:23.322 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device edge-02/$edgeHub <7> 2019-06-11 09:39:23.330 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.SubscriptionProcessor] - Processing subscription DesiredPropertyUpdates for client edge-02/$edgeHub. <7> 2019-06-11 09:39:23.332 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device edge-02/$edgeHub <7> 2019-06-11 09:39:23.374 -07:00 [DBG] [Microsoft.AspNetCore.Mvc.ModelBinding.ModelBinderFactory] - Registered model binder providers, in the following order: ["Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BinderTypeModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ServicesModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.HeaderModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FloatingPointTypeModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.EnumTypeModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CancellationTokenModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ByteArrayModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormFileModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.FormCollectionModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.KeyValuePairModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.DictionaryModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ArrayModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.CollectionModelBinderProvider", "Microsoft.AspNetCore.Mvc.ModelBinding.Binders.ComplexTypeModelBinderProvider"] <7> 2019-06-11 09:39:23.382 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation SetDesiredPropertyUpdateCallbackAsync succeeded for edge-02/$edgeHub <7> 2019-06-11 09:39:23.388 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.SubscriptionProcessor] - Processing subscription Methods for client edge-02/$edgeHub. <7> 2019-06-11 09:39:23.444 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation SetDesiredPropertyUpdateCallbackAsync succeeded for edge-02/$edgeHub <7> 2019-06-11 09:39:23.445 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.SubscriptionProcessor] - Processing subscription Methods for client edge-02/$edgeHub. <4> 2019-06-11 09:39:23.473 -07:00 [WRN] [Microsoft.AspNetCore.Server.Kestrel] - Overriding address(es) '"http://+:80"'. Binding to endpoints defined in "UseKestrel()" instead. <7> 2019-06-11 09:39:23.496 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded <7> 2019-06-11 09:39:23.498 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiClient] - Got valid device scope result <7> 2019-06-11 09:39:23.498 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ServiceProxy] - Received scope result with 1 devices, 3 modules and null continuation link <7> 2019-06-11 09:39:23.501 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to Encrypt <7> 2019-06-11 09:39:23.501 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.502 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation SetMethodDefaultHandlerAsync succeeded for edge-02/$edgeHub <7> 2019-06-11 09:39:23.502 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.502 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/encrypt?api-version=2019-01-30 <7> 2019-06-11 09:39:23.505 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded <7> 2019-06-11 09:39:23.505 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation GetTwinAsync succeeded for edge-02/$edgeHub <7> 2019-06-11 09:39:23.505 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.InvokeMethodHandler] - Processing pending method invoke requests for client edge-02/$edgeHub. <7> 2019-06-11 09:39:23.507 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Getting twin for device edge-02/$edgeHub <7> 2019-06-11 09:39:23.515 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:23.515 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for Encrypt <7> 2019-06-11 09:39:23.517 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Got twin for edge-02/$edgeHub <7> 2019-06-11 09:39:23.522 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Got twin for edge-02/$edgeHub from cloud <7> 2019-06-11 09:39:23.533 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating twin in store for edge-02/$edgeHub <7> 2019-06-11 09:39:23.540 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updated twin in store for edge-02/$edgeHub <7> 2019-06-11 09:39:23.549 -07:00 [DBG] [Microsoft.AspNetCore.Hosting.Internal.WebHost] - Hosting started <7> 2019-06-11 09:39:23.550 -07:00 [DBG] [Microsoft.AspNetCore.Hosting.Internal.WebHost] - Loaded hosting startup assembly "Microsoft.Azure.Devices.Edge.Hub.Service" <6> 2019-06-11 09:39:23.550 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Http.HttpProtocolHead] - Started HTTP head <7> 2019-06-11 09:39:23.556 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded <7> 2019-06-11 09:39:23.556 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation SetMethodDefaultHandlerAsync succeeded for edge-02/$edgeHub <7> 2019-06-11 09:39:23.557 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.InvokeMethodHandler] - Processing pending method invoke requests for client edge-02/$edgeHub. <7> 2019-06-11 09:39:23.558 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - edge-02 is in device scope, adding to cache. <7> 2019-06-11 09:39:23.558 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to Encrypt <7> 2019-06-11 09:39:23.558 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.559 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.559 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/encrypt?api-version=2019-01-30 <7> 2019-06-11 09:39:23.566 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:23.566 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for Encrypt <7> 2019-06-11 09:39:23.566 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - edge-02/$edgeAgent is in device scope, adding to cache. <7> 2019-06-11 09:39:23.566 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to Encrypt <7> 2019-06-11 09:39:23.566 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.567 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.567 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/encrypt?api-version=2019-01-30 <7> 2019-06-11 09:39:23.568 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:23.568 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:23.574 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:23.574 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for Encrypt <7> 2019-06-11 09:39:23.574 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - edge-02/$edgeHub is in device scope, adding to cache. <7> 2019-06-11 09:39:23.574 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///C:/ProgramData/iotedge/workload/sock to Encrypt <7> 2019-06-11 09:39:23.574 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.575 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket C:\ProgramData\iotedge\workload\sock <7> 2019-06-11 09:39:23.575 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://sock/modules/%24edgeHub/genid/636941583382838107/encrypt?api-version=2019-01-30 <7> 2019-06-11 09:39:23.584 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded <7> 2019-06-11 09:39:23.584 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for edge-02/$edgeHub <7> 2019-06-11 09:39:23.585 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for device edge-02/$edgeHub <7> 2019-06-11 09:39:23.587 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Merged reported properties in store for edge-02/$edgeHub <6> 2019-06-11 09:39:23.587 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updated reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:23.588 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updated reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:23.592 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK <7> 2019-06-11 09:39:23.592 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Received a valid Http response from unix:///C:/ProgramData/iotedge/workload/sock for Encrypt <7> 2019-06-11 09:39:23.593 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - edge-02/AzureBlobStorage is in device scope, adding to cache. <7> 2019-06-11 09:39:23.593 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.IDeviceScopeIdentitiesCache] - Done refreshing device scope identities cache. Waiting for 60 minutes. <7> 2019-06-11 09:39:23.602 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Storing reported properties in store for edge-02/$edgeHub with version 0 <7> 2019-06-11 09:39:23.602 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties in store with version 0 for edge-02/$edgeHub <6> 2019-06-11 09:39:23.602 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.EdgeHubConnection] - Obtained edge hub config from module twin <6> 2019-06-11 09:39:23.613 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - No routes set in the edge hub <6> 2019-06-11 09:39:23.614 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Updated message store TTL to 7200 seconds <7> 2019-06-11 09:39:23.614 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Twin for edge-02/$edgeHub synced at 6/11/2019 4:39:23 PM which is sooner than twin sync period 120 secs, skipping syncing twin <6> 2019-06-11 09:39:23.615 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Updated the edge hub store and forward configuration <6> 2019-06-11 09:39:23.616 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater] - Successfully completed periodic operation Get EdgeHub config <7> 2019-06-11 09:39:25.658 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Syncing stored reported properties to cloud in edge-02/$edgeHub <7> 2019-06-11 09:39:25.659 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Found stored reported properties for edge-02/$edgeHub to sync to cloud <7> 2019-06-11 09:39:25.659 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updating reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:25.662 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.ConnectionManager] - Obtained cloud connection for device edge-02/$edgeHub <7> 2019-06-11 09:39:25.796 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceConnectivityManager] - IotHub call succeeded <7> 2019-06-11 09:39:25.796 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient] - Operation UpdateReportedPropertiesAsync succeeded for edge-02/$edgeHub <7> 2019-06-11 09:39:25.796 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudProxy] - Updating reported properties for device edge-02/$edgeHub <6> 2019-06-11 09:39:25.796 -07:00 [INF] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updated reported properties for edge-02/$edgeHub <7> 2019-06-11 09:39:25.796 -07:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Twin.StoringTwinManager] - Updated reported properties for edge-02/$edgeHub ```

Additional Information

I don't understand how and why desired value for Image URI is this. The reported value is the last value I've set.

[mbialecka]

Now I think it may be an issue with Azure Portal. Maybe when I set desired properties through portal, it sent old, cached manifest with it? Is this the right place for portal bug?

[mma-mm]

I had a similar behaviour with the following steps:

1. Create an Edge device in portal
2. give the edge device a custom module named "a" + save
3. refresh the device overview
4. edit the module and rename it to "b" + save
5. edit the modules and add a custom module "c" + save
6. refresh the device overview

There are now 2 modules, "a" and "c".

To prevent this, i always refresh the edge device before editing the modules.

[myagley]

Let me loop in our portal team. The runtime doesn't edit the desired properties so this is likely an issue in the portal only.

[chieftn]

The portal view displays $edgeAgent twin...so a couple possibilities...

1.) a deployment may be overwriting any manual settings (whether applied to twin or via 'Set Modules') You can verify by looking at the Deployments tab of the Edge device view.

2.) as mma-mm pointed out, the portal does not (yet) refresh the edge settings after closing the 'Set Modules' view. So re-entering 'Set Modules' can cause old settings to be reposted.

We'll be fixing the bug mma-mm pointed out in the coming week.

[ancaantochi]

@chieftn, was the bug fixed in the portal? If so please close this issue.

[lt72]

@chieftn was the bug fixed in the portal? Can we close this issue?

[github-actions[bot]]

This issue is being marked as stale because it has been open for 30 days with no activity.