iotedge: edgeHub can not start due to "Could not decrypt" error

Expected Behavior

edgeHub container should start

Current Behavior

edgeHub container not starting

Steps to Reproduce

Provide a detailed set of steps to reproduce the bug.

  1. Create certs
  2. Connect server to IoT Hub using self signed certs
  3. Start iotedge service

Context (Environment)

Output of iotedge check

Click here 

--------------------
√ config.yaml is well-formed - OK
√ config.yaml has well-formed connection string - OK
√ container engine is installed and functional - OK
√ config.yaml has correct hostname - OK
√ config.yaml has correct URIs for daemon mgmt endpoint - OK
√ latest security daemon - OK
√ host time is close to real time - OK
√ container time is close to host time - OK
√ DNS server - OK
√ production readiness: identity certificates expiry - OK
√ production readiness: certificates - OK
√ production readiness: container engine - OK
√ production readiness: logs policy - OK
√ production readiness: Edge Agent's storage directory is persisted on the host filesystem - OK
√ production readiness: Edge Hub's storage directory is persisted on the host filesystem - OK

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

24 check(s) succeeded.

Device Information

  • Host OS: Ubuntu 18.04
  • Architecture: amd64
  • Container OS: Linux

Runtime Versions

  • aziot-edged [run iotedge version]: 1.1.6
  • Edge Agent [image tag (e.g. 1.0.0)]: 1.1.3
  • Edge Hub [image tag (e.g. 1.0.0)]: 1.1.3
  • Docker/Moby [run docker version]: 20.10.6+azure

Note: when using Windows containers on Windows, run docker -H npipe:////./pipe/iotedge_moby_engine version instead

Logs

aziot-edged logs 

-- Logs begin at Tue 2021-09-14 08:33:07 CEST, end at Tue 2021-09-14 15:06:33 CEST. --
Sep 14 08:33:07 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:04Z [INFO] - [mgmt] - - - [2021-09-14 06:33:04.056456104 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:09 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:09Z [INFO] - [mgmt] - - - [2021-09-14 06:33:09.088263026 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:14 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:14Z [INFO] - [mgmt] - - - [2021-09-14 06:33:14.120589379 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:19 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:19Z [INFO] - [mgmt] - - - [2021-09-14 06:33:19.154666865 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:24 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:24Z [INFO] - [mgmt] - - - [2021-09-14 06:33:24.192187220 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:29 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:29Z [INFO] - [mgmt] - - - [2021-09-14 06:33:29.220821943 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:34 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:34Z [INFO] - [mgmt] - - - [2021-09-14 06:33:34.252295386 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:35Z [INFO] - Checking edge runtime status
Sep 14 08:33:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:35Z [INFO] - Edge runtime is running.
Sep 14 08:33:39 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:39Z [INFO] - [mgmt] - - - [2021-09-14 06:33:39.282395008 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:44 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:44Z [INFO] - [mgmt] - - - [2021-09-14 06:33:44.309043240 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:49 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:49Z [INFO] - [mgmt] - - - [2021-09-14 06:33:49.349380875 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:54 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:54Z [INFO] - [mgmt] - - - [2021-09-14 06:33:54.389553086 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:33:59 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:33:59Z [INFO] - [mgmt] - - - [2021-09-14 06:33:59.421907552 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:04 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:04Z [INFO] - [mgmt] - - - [2021-09-14 06:34:04.452534069 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:09 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:09Z [INFO] - [mgmt] - - - [2021-09-14 06:34:09.492576842 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:14 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:14Z [INFO] - [mgmt] - - - [2021-09-14 06:34:14.525787750 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:19 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:19Z [INFO] - [mgmt] - - - [2021-09-14 06:34:19.555268146 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:24 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:24Z [INFO] - [mgmt] - - - [2021-09-14 06:34:24.589766641 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:29 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:29Z [INFO] - [mgmt] - - - [2021-09-14 06:34:29.618656571 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:34 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:34Z [INFO] - [mgmt] - - - [2021-09-14 06:34:34.651579520 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:35Z [INFO] - Checking edge runtime status
Sep 14 08:34:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:35Z [INFO] - Edge runtime is running.
Sep 14 08:34:39 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:39Z [INFO] - [mgmt] - - - [2021-09-14 06:34:39.689375456 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:44 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:44Z [INFO] - [mgmt] - - - [2021-09-14 06:34:44.723732404 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:45 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:45Z [INFO] - Querying system resources...
Sep 14 08:34:49 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:49Z [INFO] - [mgmt] - - - [2021-09-14 06:34:49.755882764 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:54 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:54Z [INFO] - [mgmt] - - - [2021-09-14 06:34:54.787789396 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:34:59 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:34:59Z [INFO] - [mgmt] - - - [2021-09-14 06:34:59.822618956 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:04 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:04Z [INFO] - [mgmt] - - - [2021-09-14 06:35:04.853716206 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:09 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:09Z [INFO] - [mgmt] - - - [2021-09-14 06:35:09.885575408 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:14 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:14Z [INFO] - [mgmt] - - - [2021-09-14 06:35:14.917041571 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:19 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:19Z [INFO] - [mgmt] - - - [2021-09-14 06:35:19.949436001 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:24 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:24Z [INFO] - [mgmt] - - - [2021-09-14 06:35:24.981027758 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:30 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:30Z [INFO] - [mgmt] - - - [2021-09-14 06:35:30.018640896 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:35Z [INFO] - [mgmt] - - - [2021-09-14 06:35:35.045585059 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:35Z [INFO] - Checking edge runtime status
Sep 14 08:35:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:35Z [INFO] - Edge runtime is running.
Sep 14 08:35:38 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:38Z [INFO] - [mgmt] - - - [2021-09-14 06:35:38.950911047 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/
Sep 14 08:35:40 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:40Z [INFO] - [mgmt] - - - [2021-09-14 06:35:40.080745682 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:45 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:45Z [INFO] - [mgmt] - - - [2021-09-14 06:35:45.110304042 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:50 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:50Z [INFO] - [mgmt] - - - [2021-09-14 06:35:50.143265571 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:35:55 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:35:55Z [INFO] - [mgmt] - - - [2021-09-14 06:35:55.170444923 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:00 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:00Z [INFO] - [mgmt] - - - [2021-09-14 06:36:00.202527066 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:05 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:05Z [INFO] - [mgmt] - - - [2021-09-14 06:36:05.235257654 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:10 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:10Z [INFO] - [mgmt] - - - [2021-09-14 06:36:10.272320986 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:15 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:15Z [INFO] - [mgmt] - - - [2021-09-14 06:36:15.300554794 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:20 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:20Z [INFO] - [mgmt] - - - [2021-09-14 06:36:20.336752541 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:25 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:25Z [INFO] - [mgmt] - - - [2021-09-14 06:36:25.368843248 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:30 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:30Z [INFO] - [mgmt] - - - [2021-09-14 06:36:30.401126163 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:35Z [INFO] - [mgmt] - - - [2021-09-14 06:36:35.433087745 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:35Z [INFO] - Checking edge runtime status
Sep 14 08:36:35 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:35Z [INFO] - Edge runtime is running.
Sep 14 08:36:40 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:40Z [INFO] - [mgmt] - - - [2021-09-14 06:36:40.466058403 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:45 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:45Z [INFO] - [mgmt] - - - [2021-09-14 06:36:45.493056268 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 08:36:50 LNX-IoT-PRE iotedged[13054]: 2021-09-14T06:36:50Z [INFO] - [mgmt] - - - [2021-09-14 06:36:50.527264512 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
...skipping...
Sep 14 15:05:29 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:29Z [INFO] - [mgmt] - - - [2021-09-14 13:05:29.344723542 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:05:34 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:34Z [INFO] - [mgmt] - - - [2021-09-14 13:05:34.351707645 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:05:39 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:39Z [INFO] - [mgmt] - - - [2021-09-14 13:05:39.353366608 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:05:44 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:44Z [INFO] - [mgmt] - - - [2021-09-14 13:05:44.360181997 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:05:49 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:49Z [INFO] - [mgmt] - - - [2021-09-14 13:05:49.363369186 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:05:49 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:49Z [INFO] - Checking edge runtime status
Sep 14 15:05:49 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:49Z [INFO] - Edge runtime is running.
Sep 14 15:05:54 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:54Z [INFO] - [mgmt] - - - [2021-09-14 13:05:54.369768841 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:05:59 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:05:59Z [INFO] - [mgmt] - - - [2021-09-14 13:05:59.377370895 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:06:04 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:04Z [INFO] - [mgmt] - - - [2021-09-14 13:06:04.384991350 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:06:06 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:06Z [INFO] - [mgmt] - - - [2021-09-14 13:06:06.584087577 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:06:06 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:06Z [INFO] - Querying system resources...
Sep 14 15:06:07 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:07Z [INFO] - [mgmt] - - - [2021-09-14 13:06:07.913913573 UTC] "GET /systeminfo/resources?api-version=2020-07-07 HTTP/
Sep 14 15:06:09 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:09Z [INFO] - [mgmt] - - - [2021-09-14 13:06:09.392814322 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:06:14 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:14Z [INFO] - [mgmt] - - - [2021-09-14 13:06:14.401489964 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:06:19 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:19Z [INFO] - [mgmt] - - - [2021-09-14 13:06:19.408671382 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:06:24 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:24Z [INFO] - [mgmt] - - - [2021-09-14 13:06:24.415682586 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:06:29 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:29Z [INFO] - [mgmt] - - - [2021-09-14 13:06:29.419701741 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
Sep 14 15:06:34 LNX-IoT-PRE iotedged[29329]: 2021-09-14T13:06:34Z [INFO] - [mgmt] - - - [2021-09-14 13:06:34.423712696 UTC] "GET /modules?api-version=2020-07-07 HTTP/1.1" 200 OK 1
edge-agent logs 

<7> 2021-09-14 13:04:19.264 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock
<7> 2021-09-14 13:04:19.264 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock
<7> 2021-09-14 13:04:19.264 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/modules?api-version=2020-07-07
<7> 2021-09-14 13:04:19.264 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Getting edge agent config...
<7> 2021-09-14 13:04:19.264 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Obtained edge agent config
<7> 2021-09-14 13:04:19.267 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK
<7> 2021-09-14 13:04:19.267 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for List modules
<7> 2021-09-14 13:04:19.268 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of desired modules is - {"edgeHub":{"status":"running","restartPolicy":"always","version":"","imagePullPolicy":"on-create","type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-hub:1.1.3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"],\"PortBindings\":{\"5671/tcp\":[{\"HostPort\":\"5671\"}],\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}},"edgeAgent":{"version":"","status":"running","restartPolicy":"always","imagePullPolicy":"on-create","startupOrder":0,"type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-agent:1.1.3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}}}
<7> 2021-09-14 13:04:19.269 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of current modules is - {"edgeHub":{"restartPolicy":"always","exitCode":139,"statusDescription":"exited","lastStartTimeUtc":"2021-09-14T12:59:23.5811338","lastExitTimeUtc":"2021-09-14T13:01:25.5937077","restartCount":20,"lastRestartTimeUtc":"2021-09-14T12:59:22.8731676Z","runtimeStatus":"failed","status":"running","imagePullPolicy":"on-create","type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-hub:1.1.3","imageHash":"sha256:dd0d4897a65fae460909e497386606b5cd7a2ad7ae0605f5bb766644e352fac3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"],\"PortBindings\":{\"5671/tcp\":[{\"HostPort\":\"5671\"}],\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}},"edgeAgent":{"exitCode":0,"statusDescription":"running","lastStartTimeUtc":"2021-09-14T12:44:57.9751365","lastExitTimeUtc":"0001-01-01T00:00:00","runtimeStatus":"running","imagePullPolicy":"on-create","startupOrder":0,"type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-agent:1.1.3","imageHash":"sha256:f0eda4eb5fd4aecbc0d260cf9e31eb88d58db9483fc2d54425e820c94fe6dd08","createOptions":"{\"Labels\":{\"net.azure-devices.edge.create-options\":\"{\\\"HostConfig\\\":{\\\"Binds\\\":[\\\"/appdata/iotedge_storage:/iotedge/storage\\\"]}}\",\"net.azure-devices.edge.env\":\"{\\\"storageFolder\\\":{\\\"value\\\":\\\"/iotedge/storage\\\"}}\",\"net.azure-devices.edge.owner\":\"Microsoft.Azure.Devices.Edge.Agent\"}"},"env":{"storageFolder":{"value":"/iotedge/storage"}}}
<7> 2021-09-14 13:04:19.269 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - HealthRestartPlanner created Plan, with 0 command(s).
<7> 2021-09-14 13:04:19.270 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.Reporters.IoTHubReporter] - Not updating reported properties as patch was found to be empty
<7> 2021-09-14 13:04:19.270 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Finished reconcile operation
<7> 2021-09-14 13:04:24.274 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Starting reconcile operation
<7> 2021-09-14 13:04:24.274 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to List modules
<7> 2021-09-14 13:04:24.274 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock
<7> 2021-09-14 13:04:24.274 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock
<7> 2021-09-14 13:04:24.274 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/modules?api-version=2020-07-07
<7> 2021-09-14 13:04:24.274 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Getting edge agent config...
<7> 2021-09-14 13:04:24.274 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Obtained edge agent config
<7> 2021-09-14 13:04:24.277 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK
<7> 2021-09-14 13:04:24.277 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for List modules
<7> 2021-09-14 13:04:24.278 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of desired modules is - {"edgeHub":{"status":"running","restartPolicy":"always","version":"","imagePullPolicy":"on-create","type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-hub:1.1.3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"],\"PortBindings\":{\"5671/tcp\":[{\"HostPort\":\"5671\"}],\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}},"edgeAgent":{"version":"","status":"running","restartPolicy":"always","imagePullPolicy":"on-create","startupOrder":0,"type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-agent:1.1.3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}}}
<7> 2021-09-14 13:04:24.278 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of current modules is - {"edgeHub":{"restartPolicy":"always","exitCode":139,"statusDescription":"exited","lastStartTimeUtc":"2021-09-14T12:59:23.5811338","lastExitTimeUtc":"2021-09-14T13:01:25.5937077","restartCount":20,"lastRestartTimeUtc":"2021-09-14T12:59:22.8731676Z","runtimeStatus":"failed","status":"running","imagePullPolicy":"on-create","type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-hub:1.1.3","imageHash":"sha256:dd0d4897a65fae460909e497386606b5cd7a2ad7ae0605f5bb766644e352fac3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"],\"PortBindings\":{\"5671/tcp\":[{\"HostPort\":\"5671\"}],\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}},"edgeAgent":{"exitCode":0,"statusDescription":"running","lastStartTimeUtc":"2021-09-14T12:44:57.9751365","lastExitTimeUtc":"0001-01-01T00:00:00","runtimeStatus":"running","imagePullPolicy":"on-create","startupOrder":0,"type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-agent:1.1.3","imageHash":"sha256:f0eda4eb5fd4aecbc0d260cf9e31eb88d58db9483fc2d54425e820c94fe6dd08","createOptions":"{\"Labels\":{\"net.azure-devices.edge.create-options\":\"{\\\"HostConfig\\\":{\\\"Binds\\\":[\\\"/appdata/iotedge_storage:/iotedge/storage\\\"]}}\",\"net.azure-devices.edge.env\":\"{\\\"storageFolder\\\":{\\\"value\\\":\\\"/iotedge/storage\\\"}}\",\"net.azure-devices.edge.owner\":\"Microsoft.Azure.Devices.Edge.Agent\"}"},"env":{"storageFolder":{"value":"/iotedge/storage"}}}
<7> 2021-09-14 13:04:24.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - HealthRestartPlanner created Plan, with 0 command(s).
<7> 2021-09-14 13:04:24.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.Reporters.IoTHubReporter] - Not updating reported properties as patch was found to be empty
<7> 2021-09-14 13:04:24.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Finished reconcile operation
<7> 2021-09-14 13:04:29.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Starting reconcile operation
<7> 2021-09-14 13:04:29.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to List modules
<7> 2021-09-14 13:04:29.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock
<7> 2021-09-14 13:04:29.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock
<7> 2021-09-14 13:04:29.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/modules?api-version=2020-07-07
<7> 2021-09-14 13:04:29.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Getting edge agent config...
<7> 2021-09-14 13:04:29.279 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Obtained edge agent config
<7> 2021-09-14 13:04:29.282 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK
<7> 2021-09-14 13:04:29.282 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for List modules
<7> 2021-09-14 13:04:29.283 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of desired modules is - {"edgeHub":{"status":"running","restartPolicy":"always","version":"","imagePullPolicy":"on-create","type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-hub:1.1.3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"],\"PortBindings\":{\"5671/tcp\":[{\"HostPort\":\"5671\"}],\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}},"edgeAgent":{"version":"","status":"running","restartPolicy":"always","imagePullPolicy":"on-create","startupOrder":0,"type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-agent:1.1.3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}}}
<7> 2021-09-14 13:04:29.283 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of current modules is - {"edgeHub":{"restartPolicy":"always","exitCode":139,"statusDescription":"exited","lastStartTimeUtc":"2021-09-14T12:59:23.5811338","lastExitTimeUtc":"2021-09-14T13:01:25.5937077","restartCount":20,"lastRestartTimeUtc":"2021-09-14T12:59:22.8731676Z","runtimeStatus":"failed","status":"running","imagePullPolicy":"on-create","type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-hub:1.1.3","imageHash":"sha256:dd0d4897a65fae460909e497386606b5cd7a2ad7ae0605f5bb766644e352fac3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"],\"PortBindings\":{\"5671/tcp\":[{\"HostPort\":\"5671\"}],\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}},"edgeAgent":{"exitCode":0,"statusDescription":"running","lastStartTimeUtc":"2021-09-14T12:44:57.9751365","lastExitTimeUtc":"0001-01-01T00:00:00","runtimeStatus":"running","imagePullPolicy":"on-create","startupOrder":0,"type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-agent:1.1.3","imageHash":"sha256:f0eda4eb5fd4aecbc0d260cf9e31eb88d58db9483fc2d54425e820c94fe6dd08","createOptions":"{\"Labels\":{\"net.azure-devices.edge.create-options\":\"{\\\"HostConfig\\\":{\\\"Binds\\\":[\\\"/appdata/iotedge_storage:/iotedge/storage\\\"]}}\",\"net.azure-devices.edge.env\":\"{\\\"storageFolder\\\":{\\\"value\\\":\\\"/iotedge/storage\\\"}}\",\"net.azure-devices.edge.owner\":\"Microsoft.Azure.Devices.Edge.Agent\"}"},"env":{"storageFolder":{"value":"/iotedge/storage"}}}
<7> 2021-09-14 13:04:29.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - HealthRestartPlanner created Plan, with 0 command(s).
<7> 2021-09-14 13:04:29.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.Reporters.IoTHubReporter] - Not updating reported properties as patch was found to be empty
<7> 2021-09-14 13:04:29.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Finished reconcile operation
<7> 2021-09-14 13:04:34.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Starting reconcile operation
<7> 2021-09-14 13:04:34.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Making a Http call to unix:///var/run/iotedge/mgmt.sock to List modules
<7> 2021-09-14 13:04:34.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/mgmt.sock
<7> 2021-09-14 13:04:34.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/mgmt.sock
<7> 2021-09-14 13:04:34.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://mgmt.sock/modules?api-version=2020-07-07
<7> 2021-09-14 13:04:34.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Getting edge agent config...
<7> 2021-09-14 13:04:34.284 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Obtained edge agent config
<7> 2021-09-14 13:04:34.287 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received OK
<7> 2021-09-14 13:04:34.287 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient] - Received a valid Http response from unix:///var/run/iotedge/mgmt.sock for List modules
<7> 2021-09-14 13:04:34.288 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of desired modules is - {"edgeHub":{"status":"running","restartPolicy":"always","version":"","imagePullPolicy":"on-create","type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-hub:1.1.3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"],\"PortBindings\":{\"5671/tcp\":[{\"HostPort\":\"5671\"}],\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}},"edgeAgent":{"version":"","status":"running","restartPolicy":"always","imagePullPolicy":"on-create","startupOrder":0,"type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-agent:1.1.3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}}}
<7> 2021-09-14 13:04:34.289 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - List of current modules is - {"edgeHub":{"restartPolicy":"always","exitCode":139,"statusDescription":"exited","lastStartTimeUtc":"2021-09-14T12:59:23.5811338","lastExitTimeUtc":"2021-09-14T13:01:25.5937077","restartCount":20,"lastRestartTimeUtc":"2021-09-14T12:59:22.8731676Z","runtimeStatus":"failed","status":"running","imagePullPolicy":"on-create","type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-hub:1.1.3","imageHash":"sha256:dd0d4897a65fae460909e497386606b5cd7a2ad7ae0605f5bb766644e352fac3","createOptions":"{\"HostConfig\":{\"Binds\":[\"/appdata/iotedge_storage:/iotedge/storage\"],\"PortBindings\":{\"5671/tcp\":[{\"HostPort\":\"5671\"}],\"8883/tcp\":[{\"HostPort\":\"8883\"}],\"443/tcp\":[{\"HostPort\":\"443\"}]}}"},"env":{"storageFolder":{"value":"/iotedge/storage"}},"edgeAgent":{"exitCode":0,"statusDescription":"running","lastStartTimeUtc":"2021-09-14T12:44:57.9751365","lastExitTimeUtc":"0001-01-01T00:00:00","runtimeStatus":"running","imagePullPolicy":"on-create","startupOrder":0,"type":"docker","settings":{"image":"mcr.microsoft.com/azureiotedge-agent:1.1.3","imageHash":"sha256:f0eda4eb5fd4aecbc0d260cf9e31eb88d58db9483fc2d54425e820c94fe6dd08","createOptions":"{\"Labels\":{\"net.azure-devices.edge.create-options\":\"{\\\"HostConfig\\\":{\\\"Binds\\\":[\\\"/appdata/iotedge_storage:/iotedge/storage\\\"]}}\",\"net.azure-devices.edge.env\":\"{\\\"storageFolder\\\":{\\\"value\\\":\\\"/iotedge/storage\\\"}}\",\"net.azure-devices.edge.owner\":\"Microsoft.Azure.Devices.Edge.Agent\"}"},"env":{"storageFolder":{"value":"/iotedge/storage"}}}
<7> 2021-09-14 13:04:34.289 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Planners.HealthRestartPlanner] - HealthRestartPlanner created Plan, with 0 command(s).
<7> 2021-09-14 13:04:34.290 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.IoTHub.Reporters.IoTHubReporter] - Not updating reported properties as patch was found to be empty
<7> 2021-09-14 13:04:34.290 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Agent.Core.Agent] - Finished reconcile operation
edge-hub logs 

<7> 2021-09-14 12:47:00.108 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
<7> 2021-09-14 12:47:00.109 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Error when getting an Http response from unix:///var/run/iotedge/workload.sock for Decrypt
HTTP Response: 

{"message":"Could not decrypt\n\tcaused by: An error occurred in the key store.\n\tcaused by: HSM failure\n\tcaused by: HSM API failure occurred: 431"}

Microsoft.Azure.Devices.Edge.Util.Edged.Version_2019_01_30.GeneratedCode.IoTEdgedException`1[Microsoft.Azure.Devices.Edge.Util.Edged.Version_2019_01_30.GeneratedCode.ErrorResponse]: Error
   at Microsoft.Azure.Devices.Edge.Util.Edged.Version_2019_01_30.GeneratedCode.HttpWorkloadClient.DecryptAsync(String api_version, String name, String genid, DecryptRequest payload, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/version_2019_01_30/generatedCode/HttpWorkloadClient.cs:line 396
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter[T](Task`1 task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 128
   at Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClientVersioned.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/WorkloadClientVersioned.cs:line 79
<7> 2021-09-14 12:47:00.109 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///var/run/iotedge/workload.sock to Decrypt
<7> 2021-09-14 12:47:00.110 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:00.110 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:00.110 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637672187158193955/decrypt?api-version=2019-01-30
<7> 2021-09-14 12:47:00.129 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
<7> 2021-09-14 12:47:00.129 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Retrying Http call to unix:///var/run/iotedge/workload.sock to Decrypt because of error Error, retry count = 1
<7> 2021-09-14 12:47:00.129 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:00.129 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:00.129 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637672187158193955/decrypt?api-version=2019-01-30
<7> 2021-09-14 12:47:00.147 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
<7> 2021-09-14 12:47:00.148 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Retrying Http call to unix:///var/run/iotedge/workload.sock to Decrypt because of error Error, retry count = 2
<7> 2021-09-14 12:47:03.086 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:03.086 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:03.086 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637672187158193955/decrypt?api-version=2019-01-30
<7> 2021-09-14 12:47:03.105 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
<7> 2021-09-14 12:47:03.106 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Retrying Http call to unix:///var/run/iotedge/workload.sock to Decrypt because of error Error, retry count = 3
<7> 2021-09-14 12:47:06.106 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:06.106 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:06.106 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637672187158193955/decrypt?api-version=2019-01-30
<7> 2021-09-14 12:47:06.127 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
<7> 2021-09-14 12:47:06.127 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Error when getting an Http response from unix:///var/run/iotedge/workload.sock for Decrypt
HTTP Response: 

{"message":"Could not decrypt\n\tcaused by: An error occurred in the key store.\n\tcaused by: HSM failure\n\tcaused by: HSM API failure occurred: 431"}

Microsoft.Azure.Devices.Edge.Util.Edged.Version_2019_01_30.GeneratedCode.IoTEdgedException`1[Microsoft.Azure.Devices.Edge.Util.Edged.Version_2019_01_30.GeneratedCode.ErrorResponse]: Error
   at Microsoft.Azure.Devices.Edge.Util.Edged.Version_2019_01_30.GeneratedCode.HttpWorkloadClient.DecryptAsync(String api_version, String name, String genid, DecryptRequest payload, CancellationToken cancellationToken) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/version_2019_01_30/generatedCode/HttpWorkloadClient.cs:line 396
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter[T](Task`1 task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 128
   at Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClientVersioned.Execute[T](Func`1 func, String operation) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/edged/WorkloadClientVersioned.cs:line 79
<7> 2021-09-14 12:47:06.128 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Making a Http call to unix:///var/run/iotedge/workload.sock to Decrypt
<7> 2021-09-14 12:47:06.128 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:06.128 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:06.128 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637672187158193955/decrypt?api-version=2019-01-30
<7> 2021-09-14 12:47:06.148 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
<7> 2021-09-14 12:47:06.148 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Retrying Http call to unix:///var/run/iotedge/workload.sock to Decrypt because of error Error, retry count = 1
<7> 2021-09-14 12:47:06.148 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:06.148 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:06.148 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637672187158193955/decrypt?api-version=2019-01-30
<7> 2021-09-14 12:47:06.168 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
<7> 2021-09-14 12:47:06.168 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Retrying Http call to unix:///var/run/iotedge/workload.sock to Decrypt because of error Error, retry count = 2
<7> 2021-09-14 12:47:08.857 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connecting socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:08.857 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Connected socket /var/run/iotedge/workload.sock
<7> 2021-09-14 12:47:08.857 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Sending request http://workload.sock/modules/%24edgeHub/genid/637672187158193955/decrypt?api-version=2019-01-30
<7> 2021-09-14 12:47:08.878 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler] - Response received InternalServerError
<7> 2021-09-14 12:47:08.878 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Util.Edged.WorkloadClient] - Retrying Http call to unix:///var/run/iotedge/workload.sock to Decrypt because of error Error, retry count = 3
Unhandled exception. System.AggregateException: One or more errors occurred. (Operation timed out)
 ---> System.TimeoutException: Operation timed out
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 141
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.ReadCacheFromStore(IKeyValueStore`2 encryptedStore) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 202
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.Create(IServiceProxy serviceProxy, IKeyValueStore`2 encryptedStorage, TimeSpan refreshRate, TimeSpan refreshDelay) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 69
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.CommonModule.<Load>b__24_14(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/CommonModule.cs:line 295
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__31_10(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 228
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__31_12(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 265
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__31_25(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 450
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__31_29(IComponentContext c) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 520
   at Microsoft.Azure.Devices.Edge.Hub.Service.Program.MainAsync(IConfigurationRoot configuration) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 76
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at System.Threading.Tasks.Task`1.get_Result()
   at Microsoft.Azure.Devices.Edge.Hub.Service.Program.Main() in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 33

Additional Information

Worth to mention that I only have the edgeAgent and the edgeHub modules in my deployment template.

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Comments: 18 (9 by maintainers)

Most upvoted comments

We found the issue and resolved it.

The deployment manifest here binds "/appdata/iotedge_storage:/iotedge/storage". This was causing old data to be left behind between edgeHub redeployments. The solution was to rm -rf /appdata/iotedge_storage/* after redeploying edgeHub.

+2
gordonwang0 on Oct 6, 2021

I forgot to mention you @ggjjj in my previous comment so not sure if you have seen it.

+1
NestorRV on Sep 15, 2021
Read more comments on GitHub
← iotedge: edgeHub and modules are not able to connect with AMQP or MQTT using modem connection
iotedge: edgeHub container fails to start, probably due to user permissions (listen on port 443 with unprivileged user) →