iotedge: edgeAgent module fails to start when using iotedge modules hosted by private registry

Expected Behavior

edgeAgent module should startup successfully

Current Behavior

edgeAgent module fails to start.

Steps to Reproduce

Provide a detailed set of steps to reproduce the bug.

  1. configure iotedge config.toml file /etc/aziot/config.toml
  2. run iotedge config apply

Context (Environment)

Output of iotedge check

Click here


Configuration checks (aziot-identity-service)
---------------------------------------------
√ keyd configuration is well-formed - OK
√ certd configuration is well-formed - OK
√ tpmd configuration is well-formed - OK
√ identityd configuration is well-formed - OK
√ daemon configurations up-to-date with config.toml - OK
√ identityd config toml file specifies a valid hostname - OK
√ aziot-identity-service package is up-to-date - OK
√ host time is close to reference time - OK
√ preloaded certificates are valid - OK
√ keyd is running - OK
√ certd is running - OK
√ identityd is running - OK
√ read all preloaded certificates from the Certificates Service - OK
√ read all preloaded key pairs from the Keys Service - OK
√ check all EST server URLs utilize HTTPS - OK
√ ensure all preloaded certificates match preloaded private keys with the same ID - OK

Connectivity checks (aziot-identity-service)
--------------------------------------------
‼ host can connect to and perform TLS handshake with iothub AMQP port - Warning
    Could not retrieve iothub_hostname from provisioning file.
    Please specify the backing IoT Hub name using --iothub-hostname switch if you have that information.
    Since no hostname is provided, all hub connectivity tests will be skipped.
‼ host can connect to and perform TLS handshake with iothub HTTPS / WebSockets port - Warning
    Could not retrieve iothub_hostname from provisioning file.
    Please specify the backing IoT Hub name using --iothub-hostname switch if you have that information.
    Since no hostname is provided, all hub connectivity tests will be skipped.
‼ host can connect to and perform TLS handshake with iothub MQTT port - Warning
    Could not retrieve iothub_hostname from provisioning file.
    Please specify the backing IoT Hub name using --iothub-hostname switch if you have that information.
    Since no hostname is provided, all hub connectivity tests will be skipped.
√ host can connect to and perform TLS handshake with DPS endpoint - OK

Configuration checks
--------------------
√ aziot-edged configuration is well-formed - OK
√ configuration up-to-date with config.toml - OK
√ container engine is installed and functional - OK
√ configuration has correct URIs for daemon mgmt endpoint - OK
‼ aziot-edge package is up-to-date - Warning
    Installed IoT Edge daemon has version 1.4.2 but 1.4.3 is the latest stable version available.
    Please see https://aka.ms/iotedge-update-runtime for update instructions.
√ container time is close to host time - OK
√ DNS server - OK
√ production readiness: logs policy - OK
‼ production readiness: Edge Agent's storage directory is persisted on the host filesystem - Warning
    The edgeAgent module is not configured to persist its /tmp/edgeAgent directory on the host filesystem.
    Data might be lost if the module is deleted or updated.
    Please see https://aka.ms/iotedge-storage-host for best practices.
× production readiness: Edge Hub's storage directory is persisted on the host filesystem - Error
    Could not check current state of edgeHub container
√ proxy settings are consistent in aziot-edged, aziot-identityd, moby daemon and config.toml - OK

Connectivity checks
-------------------
25 check(s) succeeded.
5 check(s) raised warnings. Re-run with --verbose for more details.
1 check(s) raised errors. Re-run with --verbose for more details.
7 check(s) were skipped due to errors from other checks. Re-run with --verbose for more details.

Device Information

  • Host OS [e.g. Ubuntu 18.04, Windows Server IoT 2019]: Yocto OS
  • Architecture [e.g. amd64, arm32, arm64]: arm64
  • Container OS [e.g. Linux containers, Windows containers]: linux containers

Runtime Versions

  • aziot-edged [run iotedge version]: 1.4.2
  • Edge Agent [image tag (e.g. 1.0.0)]: 1.4.3
  • Edge Hub [image tag (e.g. 1.0.0)]: 1.4.3
  • Docker/Moby [run docker version]: Docker version v19.03.15-ce, build 99e3ed8919

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

Logs

aziot-edged logs

Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting Azure IoT Edge Daemon
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Version - 1.4.2
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Obtaining Edge device provisioning data...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Device is S2207270004 on iotc-4d81d265-0206-48ec-88b>
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Initializing module runtime...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Using runtime network id azure-iot-edge
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Successfully initialized module runtime
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Using existing Edge CA certificate
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Certificate aziot-edged-ca will be auto-renewed. Nex>
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Stopping all modules...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Stopping module edgeAgent...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - All modules stopped
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Detecting if device information has changed...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Device information has not changed
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting management API...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting workload API...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting workload API...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Stopping listener for module edgeAgent
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Workload API stopped
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting image garbage collection task...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting watchdog with 60 second period...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting module edgeAgent...
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 21:53:45 bobcat aziot-edged[1210]: 2022-12-30T21:53:45Z [INFO] - Starting workload API...
Dec 30 21:53:46 bobcat aziot-edged[1210]: 2022-12-30T21:53:46Z [INFO] - Started Edge runtime module edgeAgent
Dec 30 21:54:45 bobcat aziot-edged[1210]: 2022-12-30T21:54:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 21:54:45 bobcat aziot-edged[1210]: 2022-12-30T21:54:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 21:54:45 bobcat aziot-edged[1210]: 2022-12-30T21:54:45Z [INFO] - Starting module edgeAgent...
Dec 30 21:54:45 bobcat aziot-edged[1210]: 2022-12-30T21:54:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 21:54:45 bobcat aziot-edged[1210]: 2022-12-30T21:54:45Z [INFO] - Starting workload API...
Dec 30 21:54:45 bobcat aziot-edged[1210]: 2022-12-30T21:54:45Z [INFO] - Workload API stopped
Dec 30 21:54:45 bobcat aziot-edged[1210]: 2022-12-30T21:54:45Z [INFO] - Started Edge runtime module edgeAgent
Dec 30 21:55:00 bobcat aziot-edged[1210]: 2022-12-30T21:55:00Z [INFO] - <-- GET /modules?api-version=2020-07-07 {"host": "2f>
Dec 30 21:55:00 bobcat aziot-edged[1210]: 2022-12-30T21:55:00Z [INFO] - --> 200 {"content-type": "application/json"}
Dec 30 21:55:09 bobcat aziot-edged[1210]: 2022-12-30T21:55:09Z [INFO] - <-- GET /modules/?api-version=2018-06-28 {"host": "u>
Dec 30 21:55:09 bobcat aziot-edged[1210]: 2022-12-30T21:55:09Z [INFO] - --> 200 {"content-type": "application/json"}
Dec 30 21:55:12 bobcat aziot-edged[1210]: 2022-12-30T21:55:12Z [INFO] - <-- GET /modules?api-version=2020-07-07 {"host": "2f>
Dec 30 21:55:12 bobcat aziot-edged[1210]: 2022-12-30T21:55:12Z [INFO] - --> 200 {"content-type": "application/json"}
Dec 30 21:55:12 bobcat aziot-edged[1210]: 2022-12-30T21:55:12Z [INFO] - <-- GET /modules/edgeAgent/logs?api-version=2020-07->
Dec 30 21:55:12 bobcat aziot-edged[1210]: 2022-12-30T21:55:12Z [INFO] - Getting logs for module edgeAgent...
Dec 30 21:55:12 bobcat aziot-edged[1210]: 2022-12-30T21:55:12Z [INFO] - --> 200 {"content-type": "text/plain"}
Dec 30 21:55:22 bobcat aziot-edged[1210]: 2022-12-30T21:55:22Z [INFO] - <-- GET /modules/edgeAgent/logs?api-version=2020-07->
Dec 30 21:55:22 bobcat aziot-edged[1210]: 2022-12-30T21:55:22Z [INFO] - Getting logs for module edgeAgent...
Dec 30 21:55:22 bobcat aziot-edged[1210]: 2022-12-30T21:55:22Z [INFO] - --> 200 {"content-type": "text/plain"}
Dec 30 21:55:45 bobcat aziot-edged[1210]: 2022-12-30T21:55:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 21:55:45 bobcat aziot-edged[1210]: 2022-12-30T21:55:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 21:55:45 bobcat aziot-edged[1210]: 2022-12-30T21:55:45Z [INFO] - Starting module edgeAgent...
Dec 30 21:55:45 bobcat aziot-edged[1210]: 2022-12-30T21:55:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 21:55:45 bobcat aziot-edged[1210]: 2022-12-30T21:55:45Z [INFO] - Starting workload API...
Dec 30 21:55:45 bobcat aziot-edged[1210]: 2022-12-30T21:55:45Z [INFO] - Workload API stopped
Dec 30 21:55:45 bobcat aziot-edged[1210]: 2022-12-30T21:55:45Z [INFO] - Started Edge runtime module edgeAgent
Dec 30 21:56:45 bobcat aziot-edged[1210]: 2022-12-30T21:56:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 21:56:45 bobcat aziot-edged[1210]: 2022-12-30T21:56:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 21:56:45 bobcat aziot-edged[1210]: 2022-12-30T21:56:45Z [INFO] - Starting module edgeAgent...
Dec 30 21:56:45 bobcat aziot-edged[1210]: 2022-12-30T21:56:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 21:56:45 bobcat aziot-edged[1210]: 2022-12-30T21:56:45Z [INFO] - Starting workload API...
Dec 30 21:56:45 bobcat aziot-edged[1210]: 2022-12-30T21:56:45Z [INFO] - Workload API stopped
Dec 30 21:56:46 bobcat aziot-edged[1210]: 2022-12-30T21:56:46Z [INFO] - Started Edge runtime module edgeAgent
Dec 30 21:57:12 bobcat aziot-edged[1210]: 2022-12-30T21:57:12Z [INFO] - <-- GET /modules/?api-version=2018-06-28 {"host": "u>
Dec 30 21:57:12 bobcat aziot-edged[1210]: 2022-12-30T21:57:12Z [INFO] - --> 200 {"content-type": "application/json"}
Dec 30 21:57:45 bobcat aziot-edged[1210]: 2022-12-30T21:57:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 21:57:45 bobcat aziot-edged[1210]: 2022-12-30T21:57:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 21:57:45 bobcat aziot-edged[1210]: 2022-12-30T21:57:45Z [INFO] - Starting module edgeAgent...
Dec 30 21:57:45 bobcat aziot-edged[1210]: 2022-12-30T21:57:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 21:57:45 bobcat aziot-edged[1210]: 2022-12-30T21:57:45Z [INFO] - Starting workload API...
Dec 30 21:57:45 bobcat aziot-edged[1210]: 2022-12-30T21:57:45Z [INFO] - Workload API stopped
Dec 30 21:57:45 bobcat aziot-edged[1210]: 2022-12-30T21:57:45Z [INFO] - Started Edge runtime module edgeAgent
Dec 30 21:58:45 bobcat aziot-edged[1210]: 2022-12-30T21:58:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 21:58:45 bobcat aziot-edged[1210]: 2022-12-30T21:58:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 21:58:45 bobcat aziot-edged[1210]: 2022-12-30T21:58:45Z [INFO] - Starting module edgeAgent...
Dec 30 21:58:45 bobcat aziot-edged[1210]: 2022-12-30T21:58:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 21:58:45 bobcat aziot-edged[1210]: 2022-12-30T21:58:45Z [INFO] - Starting workload API...
Dec 30 21:58:45 bobcat aziot-edged[1210]: 2022-12-30T21:58:45Z [INFO] - Workload API stopped
Dec 30 21:58:45 bobcat aziot-edged[1210]: 2022-12-30T21:58:45Z [INFO] - Started Edge runtime module edgeAgent
Dec 30 21:59:45 bobcat aziot-edged[1210]: 2022-12-30T21:59:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 21:59:45 bobcat aziot-edged[1210]: 2022-12-30T21:59:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 21:59:45 bobcat aziot-edged[1210]: 2022-12-30T21:59:45Z [INFO] - Starting module edgeAgent...
Dec 30 21:59:45 bobcat aziot-edged[1210]: 2022-12-30T21:59:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 21:59:45 bobcat aziot-edged[1210]: 2022-12-30T21:59:45Z [INFO] - Starting workload API...
Dec 30 21:59:45 bobcat aziot-edged[1210]: 2022-12-30T21:59:45Z [INFO] - Workload API stopped
Dec 30 21:59:45 bobcat aziot-edged[1210]: 2022-12-30T21:59:45Z [INFO] - Started Edge runtime module edgeAgent
Dec 30 22:00:45 bobcat aziot-edged[1210]: 2022-12-30T22:00:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 22:00:45 bobcat aziot-edged[1210]: 2022-12-30T22:00:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 22:00:45 bobcat aziot-edged[1210]: 2022-12-30T22:00:45Z [INFO] - Starting module edgeAgent...
Dec 30 22:00:45 bobcat aziot-edged[1210]: 2022-12-30T22:00:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 22:00:45 bobcat aziot-edged[1210]: 2022-12-30T22:00:45Z [INFO] - Starting workload API...
Dec 30 22:00:45 bobcat aziot-edged[1210]: 2022-12-30T22:00:45Z [INFO] - Workload API stopped
Dec 30 22:00:45 bobcat aziot-edged[1210]: 2022-12-30T22:00:45Z [INFO] - Started Edge runtime module edgeAgent
Dec 30 22:01:33 bobcat aziot-edged[1210]: 2022-12-30T22:01:33Z [INFO] - <-- GET /modules/edgeAgent/logs?api-version=2020-07->
Dec 30 22:01:33 bobcat aziot-edged[1210]: 2022-12-30T22:01:33Z [INFO] - Getting logs for module edgeAgent...
Dec 30 22:01:33 bobcat aziot-edged[1210]: 2022-12-30T22:01:33Z [INFO] - --> 200 {"content-type": "text/plain"}
Dec 30 22:01:45 bobcat aziot-edged[1210]: 2022-12-30T22:01:45Z [INFO] - Watchdog checking Edge runtime status
Dec 30 22:01:45 bobcat aziot-edged[1210]: 2022-12-30T22:01:45Z [INFO] - Edge runtime status is failed, starting module now...
Dec 30 22:01:45 bobcat aziot-edged[1210]: 2022-12-30T22:01:45Z [INFO] - Starting module edgeAgent...
Dec 30 22:01:45 bobcat aziot-edged[1210]: 2022-12-30T22:01:45Z [INFO] - Starting new listener for module edgeAgent
Dec 30 22:01:45 bobcat aziot-edged[1210]: 2022-12-30T22:01:45Z [INFO] - Starting workload API...
Dec 30 22:01:45 bobcat aziot-edged[1210]: 2022-12-30T22:01:45Z [INFO] - Workload API stopped
Dec 30 22:01:45 bobcat aziot-edged[1210]: 2022-12-30T22:01:45Z [INFO] - Started Edge runtime module edgeAgent
edge-agent logs

2022-12-30 21:57:45  Starting Edge Agent
2022-12-30 21:57:45  Changing ownership of storage folder: /tmp/edgeAgent to 13622
2022-12-30 22:00:45  Changing ownership of storage folder: /tmp/edgeAgent to 13622
2022-12-30 22:00:45  Changing ownership of backup folder: /tmp/edgeAgent_backup to 13622
2022-12-30 22:00:45  Changing ownership of management socket: /var/run/iotedge/mgmt.sock
2022-12-30 22:00:45  Completed necessary setup. Starting Edge Agent.
Failed to create CoreCLR, HRESULT: 0x80004005

This is a yocto OS running on an arm64 based device. When the yocto os image is build, a recipe is used to download and include iotedge runtime module container images and make them available to the docker image store of the rootfs. This also downloads the iotedge runtime module container images from a private container registry. I find the only way to get the modules to start is by deleting the module image and starting the iotedge service to have it pull the same module image again. support_bundle_2022_12_30_21_55_06_UTC.zip

Support-bundle files

Additional Information

Please provide any additional information that may be helpful in understanding the issue.

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 26 (14 by maintainers)

Most upvoted comments

Summary: the tmp dir in the agent container did not have permission to write by the dotnet framework and edgeAgent stopped right after startup. It was not clear what caused the permission issue, but using a workaround with mapping the tmp directory to a host directory let edgeAgent work.

Closing the issue for now