1.4.2 System modules, edgeAgent and/or edgeHub, fails to start with the error `System.Security.Cryptography.CryptographicException: The X509 certificate could not be added to the store.`.
- Dominant language
- C#
- Stars
- 1.5k
- Forks
- 473
- Avg merge
- 2d 17h
- Merged PRs (30d)
- 7
Description
System modules, edgeAgent and/or edgeHub, fails to start with the error `System.Security.Cryptography.CryptographicException: The X509 certificate could not be added to the store.`.
This happens to devices we have in production, we managed to run `iotedge support-bundle` to get the collection of logs. But had to reinstall the system module after that as the device is in a production environment.
## Expected Behavior
The system modules should never fail like this.
## Current Behavior
System modules, edgeAgent and/or edgeHub, fails to start with the error `System.Security.Cryptography.CryptographicException: The X509 certificate could not be added to the store.`. This seems to happen at random.
Stopping the iotedge system (`iotedge system stop`), uninstalling the container and image of the failed system module via docker and restarting the iotedge system (`iotedge system restart`) reinstalls the failed system module, which makes it work as expected.
## Steps to Reproduce
Provide a detailed set of steps to reproduce the bug.
1. Run the system for a while.
2. One of the system modules fails to start.
## Context (Environment)
### Output of `iotedge check`
Click here
```
```
### Device Information
* Host OS [e.g. Ubuntu 18.04, Windows Server IoT 2019]: Raspbery Pi OS, Buster, debian 10
* Architecture [e.g. amd64, arm32, arm64]: ARM32
* Container OS [e.g. Linux containers, Windows containers]: -
### Runtime Versions
* aziot-edged [run `iotedge version`]: 1.4.2
* Edge Agent [image tag (e.g. 1.0.0)]: 1.4.2
* Edge Hub [image tag (e.g. 1.0.0)]: 1.4.2
* Docker/Moby [run `docker version`]: 20.10.21+azure-1
Note: when using Windows containers on Windows, run `docker -H npipe:////./pipe/iotedge_moby_engine version` instead
## Logs
aziot-edged logs
```
-- Logs begin at Mon 2023-01-16 13:17:01 CET, end at Mon 2023-01-16 14:48:24 CET. --
jan 16 13:36:48 edge-dev-pi systemd[1]: Started Azure IoT Edge daemon.
jan 16 13:36:48 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:48Z [INFO] - Starting Azure IoT Edge Daemon
jan 16 13:36:48 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:48Z [INFO] - Version - 1.4.2
jan 16 13:36:48 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:48Z [INFO] - Obtaining Edge device provisioning data...
jan 16 13:36:48 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:48Z [INFO] - Device is c4c7bb59-0977-4dc8-9c2e-f82cf5410e45-edge on syscomiotI.azure-devices.net
jan 16 13:36:48 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:48Z [INFO] - Initializing module runtime...
jan 16 13:36:48 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:48Z [INFO] - Using runtime network id azure-iot-edge
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Successfully initialized module runtime
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Using existing Edge CA certificate
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Certificate aziot-edged-ca will be auto-renewed. Next renewal at 2023-01-26T07:26:22+00:00.
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping all modules...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module A...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module B...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module C...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module D...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module E...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module F...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module G...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module H...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module I...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping module J...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - All modules stopped
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Detecting if device information has changed...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Device information has not changed
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting management API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module A
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module B
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module C
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module D
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module E
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module F
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module G
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module H
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module I
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module J
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module A
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module B
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module C
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Workload API stopped
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Workload API stopped
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module D
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module E
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module F
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Workload API stopped
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Workload API stopped
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Workload API stopped
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting watchdog with 60 second period...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module G
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module H
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module I
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Stopping listener for module J
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Workload API stopped
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting image garbage collection task...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Watchdog checking Edge runtime status
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Edge runtime status is failed, starting module now...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting module J...
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting new listener for module J
jan 16 13:36:49 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:49Z [INFO] - Starting workload API...
jan 16 13:36:51 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:51Z [INFO] - Started Edge runtime module J
jan 16 13:36:53 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:53Z [INFO] - <-- GET /trust-bundle?api-version=2020-07-07 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:36:53 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:53Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:54Z [INFO] - <-- GET /systeminfo?api-version=2022-08-03 {"accept": "application/json", "host": "mgmt.sock:80", "connection": "close"}
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:54Z [INFO] - Querying system info...
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: none
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:54Z [INFO] - Successfully queried system info
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:54Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:54Z [INFO] - <-- GET /systeminfo?api-version=2022-08-03 {"accept": "application/json", "host": "mgmt.sock:80", "connection": "close"}
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:54Z [INFO] - Querying system info...
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: none
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:54Z [INFO] - Successfully queried system info
jan 16 13:36:54 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:54Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:36:57 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:57Z [INFO] - <-- POST /modules/%24J/genid/637987505423400772/sign?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/json", "content-length": "217"}
jan 16 13:36:57 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:57Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:58Z [INFO] - <-- GET /systeminfo?api-version=2022-08-03 {"accept": "application/json", "host": "mgmt.sock:80", "connection": "close"}
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:58Z [INFO] - Querying system info...
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: none
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:58Z [INFO] - Successfully queried system info
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:58Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:58Z [INFO] - <-- POST /modules/%24J/genid/637987505423400772/decrypt?api-version=2022-08-03 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/json", "content-length": "6155"}
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:58Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:58Z [INFO] - <-- GET /modules?api-version=2022-08-03 {"accept": "application/json", "host": "mgmt.sock:80", "connection": "close"}
jan 16 13:36:58 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:58Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - <-- POST /modules/%24J/genid/637987505423400772/encrypt?api-version=2022-08-03 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/json", "content-length": "6134"}
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - <-- POST /modules/F/stop?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - Stopping module F...
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - Stopping listener for module F
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - --> 204 {}
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - <-- POST /modules/F/start?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - Starting module F...
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - Starting new listener for module F
jan 16 13:36:59 edge-dev-pi aziot-edged[924]: 2023-01-16T12:36:59Z [INFO] - Starting workload API...
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - --> 204 {}
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - <-- POST /modules/B/stop?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - Stopping module B...
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - Stopping listener for module B
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - --> 204 {}
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - <-- POST /modules/B/start?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - Starting module B...
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - Starting new listener for module B
jan 16 13:37:00 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:00Z [INFO] - Starting workload API...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - --> 204 {}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - <-- POST /modules/D/stop?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Stopping module D...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Stopping listener for module D
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - --> 204 {}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - <-- POST /modules/D/start?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting module D...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting new listener for module D
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting workload API...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - --> 204 {}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - <-- POST /modules/A/stop?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Stopping module A...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Stopping listener for module A
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - --> 204 {}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - <-- POST /modules/A/start?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting module A...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting new listener for module A
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting workload API...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - --> 204 {}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - <-- POST /modules/E/stop?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Stopping module E...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Stopping listener for module E
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - --> 204 {}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - <-- POST /modules/E/start?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting module E...
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting new listener for module E
jan 16 13:37:01 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:01Z [INFO] - Starting workload API...
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - --> 204 {}
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - <-- POST /modules/H/stop?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Stopping module H...
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Stopping listener for module H
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - --> 204 {}
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - <-- POST /modules/H/start?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Starting module H...
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Starting new listener for module H
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Starting workload API...
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - --> 204 {}
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - <-- POST /modules/G/stop?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Stopping module G...
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Stopping listener for module G
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - --> 204 {}
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - <-- POST /modules/G/start?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Starting module G...
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Starting new listener for module G
jan 16 13:37:02 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:02Z [INFO] - Starting workload API...
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - --> 204 {}
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - <-- POST /modules/C/stop?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - Stopping module C...
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - Stopping listener for module C
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - --> 204 {}
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - <-- POST /modules/C/start?api-version=2022-08-03 {"host": "mgmt.sock:80", "connection": "close", "content-type": "application/json; charset=utf-8", "content-length": "0"}
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - Starting module C...
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - Starting new listener for module C
jan 16 13:37:03 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:03Z [INFO] - Starting workload API...
jan 16 13:37:04 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:04Z [INFO] - --> 204 {}
jan 16 13:37:04 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:04Z [INFO] - <-- POST /modules/%24J/genid/637987505423400772/encrypt?api-version=2022-08-03 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/json", "content-length": "6134"}
jan 16 13:37:04 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:04Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:04 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:04Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:37:04 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:04Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:06 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:06Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:37:06 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:06Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:06 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:06Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:37:06 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:06Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:06 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:06Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:37:06 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:06Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:07 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:07Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:37:07 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:07Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:07 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:07Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:37:07 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:07Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:08 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:08Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:37:08 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:08Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:09 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:09Z [INFO] - <-- GET /trust-bundle?api-version=2018-06-28 {"accept": "application/json", "host": "workload.sock:80", "connection": "close"}
jan 16 13:37:09 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:09Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:37:10 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:10Z [INFO] - <-- GET /modules?api-version=2022-08-03 {"accept": "application/json", "host": "mgmt.sock:80", "connection": "close"}
jan 16 13:37:10 edge-dev-pi aziot-edged[924]: 2023-01-16T12:37:10Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:57:33 edge-dev-pi aziot-edged[924]: 2023-01-16T12:57:33Z [INFO] - <-- GET /modules?api-version=2022-08-03 {"accept": "application/json", "host": "mgmt.sock:80", "connection": "close"}
jan 16 13:57:33 edge-dev-pi aziot-edged[924]: 2023-01-16T12:57:33Z [INFO] - --> 200 {"content-type": "application/json"}
jan 16 13:57:33 edge-dev-pi aziot-edged[924]: 2023-01-16T12:57:33Z [INFO] - <-- POST /modules/%24J/genid/637987505423400772/encrypt?api-version=2022-08-03 {"accept": "application/json", "host": "workload.sock:80", "connection": "close", "content-type": "application/json", "content-length": "6134"}
```
edge-agent logs
```
2023-01-16 10:51:59 Starting Edge Agent
2023-01-16 10:51:59 Creating UID 1000 as Juser
2023-01-16 10:51:59 Changing ownership of storage folder: /iotedge/storage//J to 1000
2023-01-16 10:51:59 Creating backup folder: /tmp/J_backup
2023-01-16 10:51:59 Changing ownership of management socket: /var/run/iotedge/mgmt.sock
2023-01-16 10:51:59 Completed necessary setup. Starting Edge Agent.
2023-01-16 10:51:59.546 +00:00 Edge Agent Main()
<6> 2023-01-16 10:52:00.130 +00:00 [INF] - Initializing Edge Agent.
<6> 2023-01-16 10:52:00.608 +00:00 [INF] - Version - 1.4.2.61356014 (bb9a26162c4c88b3ef9a50d33632ab78bd4247d6)
<6> 2023-01-16 10:52:00.610 +00:00 [INF] -
█████╗ ███████╗██╗ ██╗██████╗ ███████╗
██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝
███████║ ███╔╝ ██║ ██║██████╔╝█████╗
██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝
██║ ██║███████╗╚██████╔╝██║ ██║███████╗
╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝
██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗
██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝
██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗
██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝
██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗
╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝
<6> 2023-01-16 10:52:00.618 +00:00 [INF] - ModuleUpdateMode: NonBlocking
<6> 2023-01-16 10:52:00.754 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false}
<6> 2023-01-16 10:52:01.073 +00:00 [INF] - Installing certificates [CN=iotedged workload ca edge-dev-pi:02/13/2023 07:26:22] to Root
<6> 2023-01-16 10:52:01.537 +00:00 [INF] - Starting metrics listener on Host: *, Port: 9600, Suffix: metrics
<6> 2023-01-16 10:52:01.583 +00:00 [INF] - Updating performance metrics every 05m:00s
<6> 2023-01-16 10:52:01.600 +00:00 [INF] - Started operation Get system resources
<6> 2023-01-16 10:52:01.605 +00:00 [INF] - Collecting metadata metrics
<6> 2023-01-16 10:52:01.845 +00:00 [INF] - Set metadata metrics: 1.4.2.61356014 (bb9a26162c4c88b3ef9a50d33632ab78bd4247d6), {"Enabled":false,"DisableCloudSubscriptions":false}, {"OperatingSystemType":"Linux","Architecture":"arm","Version":"1.4.2","Provisioning":{"Type":"ProvisioningType","DynamicReprovisioning":false,"AlwaysReprovisionOnStartup":false},"ServerVersion":"20.10.21+azure-1","KernelVersion":"#1496 SMP Wed Dec 1 15:58:56 GMT 2021","OperatingSystem":"raspbian","NumCpus":4,"TotalMemory":4121808896,"Virtualized":"no"}, True
<6> 2023-01-16 10:52:01.901 +00:00 [INF] - Started operation Checkpoint Availability
<6> 2023-01-16 10:52:01.910 +00:00 [INF] - Started operation refresh twin config
<6> 2023-01-16 10:52:01.964 +00:00 [INF] - Edge agent attempting to connect to IoT Hub via Amqp_Tcp_Only...
<6> 2023-01-16 10:52:03.153 +00:00 [INF] - Created persistent store at /iotedge/storage/J
<6> 2023-01-16 10:52:03.388 +00:00 [INF] - Started operation Metrics Scrape
<6> 2023-01-16 10:52:03.389 +00:00 [INF] - Started operation Metrics Upload
Scraping frequency: 01:00:00
Upload Frequency: 1.00:00:00
<6> 2023-01-16 10:52:04.066 +00:00 [INF] - Registering request handler UploadModuleLogs
<6> 2023-01-16 10:52:04.066 +00:00 [INF] - Registering request handler GetModuleLogs
<6> 2023-01-16 10:52:04.067 +00:00 [INF] - Registering request handler UploadSupportBundle
<6> 2023-01-16 10:52:04.067 +00:00 [INF] - Registering request handler RestartModule
<6> 2023-01-16 10:52:04.538 +00:00 [INF] - Edge agent connected to IoT Hub via Amqp_Tcp_Only.
<6> 2023-01-16 10:52:04.862 +00:00 [INF] - Initialized new module client with subscriptions enabled
<6> 2023-01-16 10:52:05.009 +00:00 [INF] - Obtained Edge agent twin from IoTHub with desired properties version 21 and reported properties version 1461.
<6> 2023-01-16 10:52:11.316 +00:00 [INF] - Plan execution started for deployment 21
<6> 2023-01-16 10:52:11.324 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.334 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.334 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.335 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.335 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.335 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.335 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.335 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.336 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 10:52:11.366 +00:00 [INF] - Executing command: "Command Group: (\n [Command Group: (\n [Prepare module I]\n [Create module I]\n)]\n [Start module I]\n)"
<6> 2023-01-16 10:52:11.372 +00:00 [INF] - Executing command: "Command Group: (\n [Prepare module I]\n [Create module I]\n)"
at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter[T](Task`1 task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 135
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/versioning/ModuleManagementHttpClientVersioned.cs:line 147
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2022_08_03.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/version_2022_08_03/ModuleManagementHttpClient.cs:line 245
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/versioning/ModuleManagementHttpClientVersioned.cs:line 164
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2022_08_03.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/version_2022_08_03/ModuleManagementHttpClient.cs:line 214
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient.<>c__DisplayClass26_0.<b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/ModuleManagementHttpClient.cs:line 143
--- End of stack trace from previous location ---
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient.Throttle[T](Func`1 identityOperation) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/ModuleManagementHttpClient.cs:line 158
at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in /mnt/vss/_work/1/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 /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/LoggingCommandFactory.cs:line 61
at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in /mnt/vss/_work/1/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 /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/LoggingCommandFactory.cs:line 61
at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunner.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/planrunner/OrdererdRetryPlanRunner.cs:line 91
--- End of inner exception stack trace ---
at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunner.OrderedRetryPlanRunner.<>c.b__7_0(List`1 f) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/planrunner/OrdererdRetryPlanRunner.cs:line 129
at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunner.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token)
at Microsoft.Azure.Devices.Edge.Agent.Core.Agent.ReconcileAsync(CancellationToken token) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/Agent.cs:line 162
<4> 2023-01-16 11:14:26.499 +00:00 [WRN] - Reconcile failed because of the an exception
System.AggregateException: One or more errors occurred. (The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.)
---> System.Threading.Tasks.TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
---> System.TimeoutException: The operation was canceled.
---> System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.Threading.CancellationToken.ThrowIfCancellationRequested()
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
at System.IO.BufferedStream.ReadFromUnderlyingStreamAsync(Memory`1 buffer, CancellationToken cancellationToken, Int32 bytesAlreadySatisfied, Task semaphoreLockTask)
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpBufferedStream.ReadLineAsync(CancellationToken cancellationToken) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpBufferedStream.cs:line 62
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpRequestResponseSerializer.SetResponseStatusLine(HttpResponseMessage httpResponse, HttpBufferedStream bufferedStream, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpRequestResponseSerializer.cs:line 158
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpRequestResponseSerializer.DeserializeResponse(HttpBufferedStream bufferedStream, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpRequestResponseSerializer.cs:line 69
at Microsoft.Azure.Devices.Edge.Util.Uds.HttpUdsMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/uds/HttpUdsMessageHandler.cs:line 48
at System.Net.Http.HttpClient.g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
--- End of inner exception stack trace ---
--- End of inner exception stack trace ---
at System.Net.Http.HttpClient.HandleFailure(Exception e, Boolean telemetryStarted, HttpResponseMessage response, CancellationTokenSource cts, CancellationToken cancellationToken, CancellationTokenSource pendingRequestsCts)
at System.Net.Http.HttpClient.g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2022_08_03.GeneratedCode.EdgeletHttpClient.PrepareUpdateModuleAsync(String api_version, String name, ModuleSpec module, CancellationToken cancellationToken) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/version_2022_08_03/generatedCode/EdgeletHttpClient.cs:line 636
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.<>c__DisplayClass35_0.<b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/versioning/ModuleManagementHttpClientVersioned.cs:line 137
--- End of stack trace from previous location ---
at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter[T](Task`1 task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 135
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/versioning/ModuleManagementHttpClientVersioned.cs:line 147
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2022_08_03.ModuleManagementHttpClient.HandleException(Exception exception, String operation) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/version_2022_08_03/ModuleManagementHttpClient.cs:line 245
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Versioning.ModuleManagementHttpClientVersioned.Execute[T](Func`1 func, String operation) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/versioning/ModuleManagementHttpClientVersioned.cs:line 164
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.Version_2022_08_03.ModuleManagementHttpClient.PrepareUpdateAsync(ModuleSpec moduleSpec) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/version_2022_08_03/ModuleManagementHttpClient.cs:line 214
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient.<>c__DisplayClass26_0.<b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/ModuleManagementHttpClient.cs:line 143
--- End of stack trace from previous location ---
at Microsoft.Azure.Devices.Edge.Agent.Edgelet.ModuleManagementHttpClient.Throttle[T](Func`1 identityOperation) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Edgelet/ModuleManagementHttpClient.cs:line 158
at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in /mnt/vss/_work/1/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 /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/LoggingCommandFactory.cs:line 61
at Microsoft.Azure.Devices.Edge.Agent.Core.Commands.GroupCommand.ExecuteAsync(CancellationToken token) in /mnt/vss/_work/1/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 /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/LoggingCommandFactory.cs:line 61
at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunner.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/planrunner/OrdererdRetryPlanRunner.cs:line 91
--- End of inner exception stack trace ---
at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunner.OrderedRetryPlanRunner.<>c.b__7_0(List`1 f) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/planrunner/OrdererdRetryPlanRunner.cs:line 129
at Microsoft.Azure.Devices.Edge.Agent.Core.PlanRunner.OrderedRetryPlanRunner.ExecuteAsync(Int64 deploymentId, Plan plan, CancellationToken token)
at Microsoft.Azure.Devices.Edge.Agent.Core.Agent.ReconcileAsync(CancellationToken token) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/Agent.cs:line 162
at Microsoft.Azure.Devices.Edge.Agent.Core.Agent.ReconcileAsync(CancellationToken token) in /mnt/vss/_work/1/s/edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/Agent.cs:line 174
<6> 2023-01-16 11:14:26.990 +00:00 [INF] - Updated reported properties
<6> 2023-01-16 11:14:33.590 +00:00 [INF] - Module 'I' scheduled to restart after 20s (17s left).
<6> 2023-01-16 11:14:33.594 +00:00 [INF] - Plan execution started for deployment 21
<6> 2023-01-16 11:14:33.596 +00:00 [INF] - Executing command: "[Null]"
<6> 2023-01-16 11:14:33.600 +00:00 [INF] - Executing command: "Command Group: (\n [Command Group: (\n [Prepare module A]\n [Create module A]\n)]\n [Start module A]\n)"
<6> 2023-01-16 11:14:33.600 +00:00 [INF] - Executing command: "Command Group: (\n [Prepare module A]\n [Create module A]\n)"
<6> 2023-01-16 11:14:35.595 +00:00 [INF] - Executing command: "Start module A"
<6> 2023-01-16 11:14:35.871 +00:00 [INF] - Plan execution ended for deployment 21
<6> 2023-01-16 11:14:36.132 +00:00 [INF] - Updated reported properties
<6> 2023-01-16 11:14:41.199 +00:00 [INF] - Module 'I' scheduled to restart after 20s (09s left).
<6> 2023-01-16 11:14:41.411 +00:00 [INF] - Updated reported properties
<6> 2023-01-16 11:14:46.540 +00:00 [INF] - Module 'I' scheduled to restart after 20s (04s left).
<6> 2023-01-16 11:14:51.627 +00:00 [INF] - Plan execution started for deployment 21
<6> 2023-01-16 11:14:51.627 +00:00 [INF] - Executing command: "Command Group: (\n [Stop module I]\n [Start module I]\n [Saving I to store]\n)"
<6> 2023-01-16 11:14:51.628 +00:00 [INF] - Executing command: "Stop module I"
<6> 2023-01-16 11:14:51.632 +00:00 [INF] - Executing command: "Start module I"
<6> 2023-01-16 11:14:52.796 +00:00 [INF] - Executing command: "Saving I to store"
<6> 2023-01-16 11:14:52.798 +00:00 [INF] - Plan execution ended for deployment 21
<6> 2023-01-16 11:14:58.028 +00:00 [INF] - Module 'I' scheduled to restart after 40s (38s left).
<6> 2023-01-16 11:14:58.235 +00:00 [INF] - Updated reported properties
<6> 2023-01-16 11:15:03.359 +00:00 [INF] - Module 'I' scheduled to restart after 40s (33s left).
<6> 2023-01-16 11:15:08.481 +00:00 [INF] - Module 'I' scheduled to restart after 40s (27s left).
<6> 2023-01-16 11:15:13.595 +00:00 [INF] - Module 'I' scheduled to restart after 40s (22s left).
<6> 2023-01-16 11:15:18.720 +00:00 [INF] - Module 'I' scheduled to restart after 40s (17s left).
<6> 2023-01-16 11:15:23.847 +00:00 [INF] - Module 'I' scheduled to restart after 40s (12s left).
<6> 2023-01-16 11:15:28.994 +00:00 [INF] - Module 'I' scheduled to restart after 40s (07s left).
<6> 2023-01-16 11:15:34.111 +00:00 [INF] - Module 'I' scheduled to restart after 40s (02s left).
<6> 2023-01-16 11:15:39.233 +00:00 [INF] - Plan execution started for deployment 21
<6> 2023-01-16 11:15:39.234 +00:00 [INF] - Executing command: "Command Group: (\n [Stop module I]\n [Start module I]\n [Saving I to store]\n)"
```
edge-hub logs
```
2023-01-16 11:14:26 Starting Edge Hub
2023-01-16 11:14:26 Starting Edge Hub
2023-01-16 11:14:26 Changing ownership of storage folder: /iotedge/storage//edgeHub to 1000
2023-01-16 11:14:26 Creating backup folder: /tmp/edgeHub_backup
2023-01-16 11:14:26.682 +00:00 Edge Hub Main()
<6> 2023-01-16 11:14:30.581 +00:00 [INF] - Installing certificates [CN=iotedged workload ca edge-dev-pi:02/13/2023 07:26:22] to Root
<3> 2023-01-16 11:14:30.647 +00:00 [ERR] - Stopping with exception
System.Security.Cryptography.CryptographicException: The X509 certificate could not be added to the store.
---> System.UnauthorizedAccessException: Access to the path '/home/edgehubuser/.dotnet/corefx/cryptography/x509stores/root' is denied.
---> System.IO.IOException: Permission denied
--- End of inner exception stack trace ---
at System.IO.FileSystem.CreateDirectory(String fullPath)
at System.IO.Directory.CreateDirectory(String path)
at Internal.Cryptography.Pal.DirectoryBasedStoreProvider.AddCertToStore(ICertificatePal certPal)
at Internal.Cryptography.Pal.DirectoryBasedStoreProvider.Add(ICertificatePal certPal)
--- End of inner exception stack trace ---
at Internal.Cryptography.Pal.DirectoryBasedStoreProvider.Add(ICertificatePal certPal)
at System.Security.Cryptography.X509Certificates.X509Store.Add(X509Certificate2 certificate)
at Microsoft.Azure.Devices.Edge.Util.CertificateHelper.InstallCertificates(IEnumerable`1 certificateChain, ILogger logger) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/CertificateHelper.cs:line 226
at Microsoft.Azure.Devices.Edge.Hub.Service.EdgeHubCertificates.LoadAsync(IConfigurationRoot configuration, ILogger logger) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/EdgeHubCertificates.cs:line 95
at Microsoft.Azure.Devices.Edge.Hub.Service.Program.MainAsync(IConfigurationRoot configuration) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 58
Unhandled exception. System.AggregateException: One or more errors occurred. (The X509 certificate could not be added to the store.)
---> System.Security.Cryptography.CryptographicException: The X509 certificate could not be added to the store.
---> System.UnauthorizedAccessException: Access to the path '/home/edgehubuser/.dotnet/corefx/cryptography/x509stores/root' is denied.
---> System.IO.IOException: Permission denied
--- End of inner exception stack trace ---
at System.IO.FileSystem.CreateDirectory(String fullPath)
at System.IO.Directory.CreateDirectory(String path)
at Internal.Cryptography.Pal.DirectoryBasedStoreProvider.AddCertToStore(ICertificatePal certPal)
at Internal.Cryptography.Pal.DirectoryBasedStoreProvider.Add(ICertificatePal certPal)
--- End of inner exception stack trace ---
at Internal.Cryptography.Pal.DirectoryBasedStoreProvider.Add(ICertificatePal certPal)
at System.Security.Cryptography.X509Certificates.X509Store.Add(X509Certificate2 certificate)
at Microsoft.Azure.Devices.Edge.Util.CertificateHelper.InstallCertificates(IEnumerable`1 certificateChain, ILogger logger) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/CertificateHelper.cs:line 226
at Microsoft.Azure.Devices.Edge.Hub.Service.EdgeHubCertificates.LoadAsync(IConfigurationRoot configuration, ILogger logger) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/EdgeHubCertificates.cs:line 95
at Microsoft.Azure.Devices.Edge.Hub.Service.Program.MainAsync(IConfigurationRoot configuration) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 58
--- 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 /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/Program.cs:line 35
```
## Additional Information
We have upgraded from 1.2.x to 1.4.2 on our devices. Under 1.2.x we had no issue like this.
Contributor guide
No contributing guide indexed for this repository
Assessment
This issue has not been assessed yet.