Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Security daemon could not start successfully: Could not start management service #5933

Open
FrankSHLi opened this issue Dec 14, 2021 · 8 comments
Open

Security daemon could not start successfully: Could not start management service #5933

FrankSHLi opened this issue Dec 14, 2021 · 8 comments
Assignees
@bilalsellak
Labels
1.0.9 Targeted for 1.0.9 release customer-reported iotedge no-issue-activity

Comments

@FrankSHLi
Copy link

Expected Behavior

edgeAgent, edgeHub and other custom modules should be started by IoT Edge service.

Current Behavior

Security daemon failed to start up and module containers are not being created.

Steps to Reproduce

Not sure how to replicate this.

Context (Environment)

Output of iotedge check

Click here 
Configuration checks
--------------------
√ config.yaml is well-formed - OK
‼ config.yaml has well-formed connection string - Warning
    Device not configured with manual provisioning, in this configuration 'iotedge check' is not able to discover the device's backing IoT Hub.
    To run connectivity checks in this configuration please specify the backing IoT Hub name using --iothub-hostname switch if you have that information.
    If no hostname is provided, all hub connectivity tests will be skipped.
√ container engine is installed and functional - OK
√ config.yaml has correct hostname - OK
× config.yaml has correct URIs for daemon mgmt endpoint - Error
    Error: could not execute list-modules request: an IO error occurred: Connection reset by peer (os error 104)
‼ latest security daemon - Warning
    Installed IoT Edge daemon has version 1.0.9 but 1.1.8 is the latest stable version available.
    Please see https://aka.ms/iotedge-update-runtime for update instructions.
√ host time is close to real time - OK
√ container time is close to host time - OK
√ DNS server - OK
√ production readiness: certificates - OK
√ production readiness: container engine - OK
‼ production readiness: logs policy - Warning
    Container engine is not configured to rotate module logs which may cause it run out of disk space.
    Please see https://aka.ms/iotedge-prod-checklist-logs for best practices.
    You can ignore this warning if you are setting log policy per module in the Edge deployment.
× production readiness: Edge Agent's storage directory is persisted on the host filesystem - Error
    Could not check current state of edgeAgent container
× production readiness: Edge Hub's storage directory is persisted on the host filesystem - Error
    Could not check current state of edgeHub container

Connectivity checks
-------------------
√ host can connect to and perform TLS handshake with DPS endpoint - OK

9 check(s) succeeded.
3 check(s) raised warnings. Re-run with --verbose for more details.
3 check(s) raised errors. Re-run with --verbose for more details.
9 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]: Debian 9
  • Architecture [e.g. amd64, arm32, arm64]: armhf
  • Container OS [e.g. Linux containers, Windows containers]: Linux

Runtime Versions

  • aziot-edged [run iotedge version]: 1.0.9
  • Edge Agent [image tag (e.g. 1.0.0)]: 1.0.9
  • Edge Hub [image tag (e.g. 1.0.0)]: 1.0.9
  • Docker/Moby [run docker version]: 3.0.5

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

Logs

aziot-edged logs 
Dec 14 11:53:10 Moxa systemd[1]: Started Azure IoT Edge daemon.
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Starting Azure IoT Edge Security Daemon
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Version - 1.0.9
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Using config file: /etc/iotedge/config.yaml
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Configuring certificates...
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Configuring the Device CA certificate using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.crt".
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Configuring the Device private key using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.key".
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Configuring the trusted CA certificates using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/RootCA_moxa.crt".
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Finished configuring provisioning environment variables and certificates.
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Initializing hsm...
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Finished initializing hsm.
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Provisioning edge device...
Dec 14 11:53:10 Moxa iotedged[25313]: 2021-12-14T19:53:10Z [INFO] - Starting provisioning edge device via TPM...
Dec 14 11:53:11 Moxa iotedged[25313]: 2021-12-14T19:53:11Z [INFO] - Starting DPS registration with scope_id "0ne00236C76", registration_id "taiib1028226"
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - DPS registration assigned device "taiib1028226" in hub "pf-p314-iot-iothub-prod.azure-devices.net"
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Finished provisioning edge device.
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Initializing the module runtime...
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Initializing module runtime...
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Using runtime network id azure-iot-edge
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Successfully initialized module runtime
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Finished initializing the module runtime.
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Reprovisioning status InitialAssignment will trigger reconfiguration of modules.
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Detecting if configuration file has changed...
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - No change to configuration file detected.
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Edge issuer CA expiration date: 2037-07-07T01:07:06Z
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Obtaining workload CA succeeded.
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Starting management API...
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Starting workload API...
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [INFO] - Starting watchdog with 60 second frequency...
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [ERR!] - The daemon could not start up successfully: Could not start management service
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [ERR!] -         caused by: An error occurred for path /var/run/iotedge/mgmt.sock
Dec 14 11:53:24 Moxa iotedged[25313]: 2021-12-14T19:53:24Z [ERR!] -         caused by: Permission denied (os error 13)
Dec 14 11:53:24 Moxa systemd[1]: iotedge.service: Main process exited, code=exited, status=1/FAILURE
Dec 14 11:53:24 Moxa systemd[1]: iotedge.service: Unit entered failed state.
Dec 14 11:53:24 Moxa systemd[1]: iotedge.service: Failed with result 'exit-code'.
Dec 14 11:53:25 Moxa systemd[1]: iotedge.service: Service hold-off time over, scheduling restart.
Dec 14 11:53:25 Moxa systemd[1]: Stopped Azure IoT Edge daemon.

Additional Information

Permission of /var/run/iotedge/mgmt.sock

# ls -alh /var/run/iotedge/
total 0
drwxr-xr-x  2 root    root     80 Dec 14 12:08 .
drwxr-xr-x 20 root    root    740 Dec 14 11:53 ..
srw-rw----  1 iotedge iotedge   0 Dec 14 12:08 mgmt.sock
srw-rw-rw-  1 iotedge iotedge   0 Dec 14 12:08 workload.sock
@bilalsellak bilalsellak self-assigned this Dec 14, 2021
@bilalsellak
Copy link
Contributor

Hmm. The permissions look correct. Could you run iotedge system logs and post the result?

@ksaye
Copy link
Contributor

ksaye commented Dec 15, 2021

@brotherneeru Edge 1.0.9 does not include that command:

iotedge --help
iotedge 1.0.9
The iotedge tool is used to manage the IoT Edge runtime.

USAGE:
    iotedge [OPTIONS] <SUBCOMMAND>

FLAGS:
    -h, --help       Prints help information
    -V, --version    Prints version information

OPTIONS:
    -H, --host <HOST>    Daemon socket to connect to [env: IOTEDGE_HOST=]  [default: unix:///var/run/iotedge/mgmt.sock]

SUBCOMMANDS:
    check             Check for common config and deployment issues
    check-list        List the checks that are run for 'iotedge check'
    help              Prints this message or the help of the given subcommand(s)
    list              List modules
    logs              Fetch the logs of a module
    restart           Restart a module
    support-bundle    Bundles troubleshooting information
    version           Show the version information

and trying to get the support bundle is a challenge:

iotedge support-bundle
Making support bundle
Writing all logs since 2021-12-14 16:38:21 UTC (local time 2021-12-14 08:38:21 -08:00)
A module runtime error occurred
        caused by: Could not list modules
        caused by: an IO error occurred: Connection reset by peer (os error 104)

What I notice is that the management service keeps restarting:

journalctl -n 100 -u iotedge.mgmt.socket
-- Logs begin at Tue 2021-12-14 22:22:51 PST, end at Wed 2021-12-15 08:46:43 PST. --
Dec 15 08:40:37 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:40:37 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:40:37 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:40:37 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:40:52 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:40:52 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:40:52 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:40:52 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:41:07 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:41:07 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:41:07 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:41:07 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:41:23 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:41:23 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:41:23 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:41:23 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:41:38 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:41:38 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:41:38 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:41:38 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:41:52 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:41:52 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:41:52 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:41:52 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:42:07 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:42:07 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:42:07 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:42:07 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:42:22 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:42:22 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:42:22 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:42:22 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:42:36 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:42:36 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:42:36 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:42:36 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:42:51 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:42:51 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:42:51 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:42:51 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:43:06 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:43:06 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:43:06 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:43:06 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:43:21 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:43:21 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:43:21 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:43:21 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:43:35 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:43:35 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:43:35 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:43:35 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:43:50 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:43:50 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:43:50 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:43:50 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:44:05 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:44:05 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:44:05 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:44:05 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:44:19 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:44:19 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:44:19 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:44:19 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:44:34 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:44:34 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:44:34 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:44:34 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:44:49 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:44:49 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:44:49 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:44:49 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:45:04 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:45:04 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:45:04 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:45:04 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:45:18 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:45:18 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:45:18 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.
Dec 15 08:45:18 Moxa systemd[1]: Listening on Azure IoT Edge daemon management socket.
Dec 15 08:45:33 Moxa systemd[1]: Closed Azure IoT Edge daemon management socket.
Dec 15 08:45:33 Moxa systemd[1]: Stopping Azure IoT Edge daemon management socket.
Dec 15 08:45:33 Moxa systemd[1]: Starting Azure IoT Edge daemon management socket.

and of course Edge does also:

journalctl -n 150 -u iotedge
-- Logs begin at Tue 2021-12-14 22:22:51 PST, end at Wed 2021-12-15 08:45:04 PST. --
Dec 15 08:44:05 Moxa iotedged[30567]: 2021-12-15T16:44:05Z [INFO] - Finished configuring provisioning environment variables and certificates.
Dec 15 08:44:05 Moxa iotedged[30567]: 2021-12-15T16:44:05Z [INFO] - Initializing hsm...
Dec 15 08:44:05 Moxa iotedged[30567]: 2021-12-15T16:44:05Z [INFO] - Finished initializing hsm.
Dec 15 08:44:05 Moxa iotedged[30567]: 2021-12-15T16:44:05Z [INFO] - Provisioning edge device...
Dec 15 08:44:05 Moxa iotedged[30567]: 2021-12-15T16:44:05Z [INFO] - Starting provisioning edge device via TPM...
Dec 15 08:44:05 Moxa iotedged[30567]: 2021-12-15T16:44:05Z [INFO] - Starting DPS registration with scope_id "0ne00236C76", registration_id "taiib1028226"
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - DPS registration assigned device "taiib1028226" in hub "pf-p314-iot-iothub-prod.azure-devices.net"
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Finished provisioning edge device.
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Initializing the module runtime...
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Initializing module runtime...
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Using runtime network id azure-iot-edge
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Successfully initialized module runtime
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Finished initializing the module runtime.
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Reprovisioning status InitialAssignment will trigger reconfiguration of modules.
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Detecting if configuration file has changed...
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - No change to configuration file detected.
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Edge issuer CA expiration date: 2037-07-07T01:07:06Z
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Obtaining workload CA succeeded.
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Starting management API...
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Starting workload API...
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [INFO] - Starting watchdog with 60 second frequency...
Dec 15 08:44:19 Moxa iotedged[30567]: 2021-12-15T16:44:19Z [ERR!] - The daemon could not start up successfully: Could not start management service
Dec 15 08:44:19 Moxa systemd[1]: iotedge.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 08:44:19 Moxa systemd[1]: iotedge.service: Unit entered failed state.
Dec 15 08:44:19 Moxa systemd[1]: iotedge.service: Failed with result 'exit-code'.
Dec 15 08:44:19 Moxa systemd[1]: iotedge.service: Service hold-off time over, scheduling restart.
Dec 15 08:44:19 Moxa systemd[1]: Stopped Azure IoT Edge daemon.
Dec 15 08:44:19 Moxa systemd[1]: Started Azure IoT Edge daemon.
Dec 15 08:44:19 Moxa iotedged[30967]: 2021-12-15T16:44:19Z [INFO] - Starting Azure IoT Edge Security Daemon
Dec 15 08:44:19 Moxa iotedged[30967]: 2021-12-15T16:44:19Z [INFO] - Version - 1.0.9
Dec 15 08:44:19 Moxa iotedged[30967]: 2021-12-15T16:44:19Z [INFO] - Using config file: /etc/iotedge/config.yaml
Dec 15 08:44:19 Moxa iotedged[30967]: 2021-12-15T16:44:19Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Configuring certificates...
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Configuring the Device CA certificate using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.crt".
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Configuring the Device private key using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.key".
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Configuring the trusted CA certificates using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/RootCA_moxa.crt".
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Finished configuring provisioning environment variables and certificates.
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Initializing hsm...
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Finished initializing hsm.
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Provisioning edge device...
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Starting provisioning edge device via TPM...
Dec 15 08:44:20 Moxa iotedged[30967]: 2021-12-15T16:44:20Z [INFO] - Starting DPS registration with scope_id "0ne00236C76", registration_id "taiib1028226"
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - DPS registration assigned device "taiib1028226" in hub "pf-p314-iot-iothub-prod.azure-devices.net"
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Finished provisioning edge device.
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Initializing the module runtime...
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Initializing module runtime...
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Using runtime network id azure-iot-edge
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Successfully initialized module runtime
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Finished initializing the module runtime.
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Reprovisioning status InitialAssignment will trigger reconfiguration of modules.
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Detecting if configuration file has changed...
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - No change to configuration file detected.
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Edge issuer CA expiration date: 2037-07-07T01:07:06Z
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Obtaining workload CA succeeded.
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Starting management API...
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Starting workload API...
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [INFO] - Starting watchdog with 60 second frequency...
Dec 15 08:44:34 Moxa iotedged[30967]: 2021-12-15T16:44:34Z [ERR!] - The daemon could not start up successfully: Could not start management service
Dec 15 08:44:34 Moxa systemd[1]: iotedge.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 08:44:34 Moxa systemd[1]: iotedge.service: Unit entered failed state.
Dec 15 08:44:34 Moxa systemd[1]: iotedge.service: Failed with result 'exit-code'.
Dec 15 08:44:34 Moxa systemd[1]: iotedge.service: Service hold-off time over, scheduling restart.
Dec 15 08:44:34 Moxa systemd[1]: Stopped Azure IoT Edge daemon.
Dec 15 08:44:34 Moxa systemd[1]: Started Azure IoT Edge daemon.
Dec 15 08:44:34 Moxa iotedged[31708]: 2021-12-15T16:44:34Z [INFO] - Starting Azure IoT Edge Security Daemon
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Version - 1.0.9
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Using config file: /etc/iotedge/config.yaml
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Configuring certificates...
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Configuring the Device CA certificate using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.crt".
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Configuring the Device private key using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.key".
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Configuring the trusted CA certificates using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/RootCA_moxa.crt".
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Finished configuring provisioning environment variables and certificates.
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Initializing hsm...
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Finished initializing hsm.
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Provisioning edge device...
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Starting provisioning edge device via TPM...
Dec 15 08:44:35 Moxa iotedged[31708]: 2021-12-15T16:44:35Z [INFO] - Starting DPS registration with scope_id "0ne00236C76", registration_id "taiib1028226"
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - DPS registration assigned device "taiib1028226" in hub "pf-p314-iot-iothub-prod.azure-devices.net"
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Finished provisioning edge device.
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Initializing the module runtime...
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Initializing module runtime...
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Using runtime network id azure-iot-edge
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Successfully initialized module runtime
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Finished initializing the module runtime.
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Reprovisioning status InitialAssignment will trigger reconfiguration of modules.
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Detecting if configuration file has changed...
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - No change to configuration file detected.
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Edge issuer CA expiration date: 2037-07-07T01:07:06Z
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Obtaining workload CA succeeded.
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Starting management API...
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Starting workload API...
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [INFO] - Starting watchdog with 60 second frequency...
Dec 15 08:44:49 Moxa iotedged[31708]: 2021-12-15T16:44:49Z [ERR!] - The daemon could not start up successfully: Could not start management service
Dec 15 08:44:49 Moxa systemd[1]: iotedge.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 08:44:49 Moxa systemd[1]: iotedge.service: Unit entered failed state.
Dec 15 08:44:49 Moxa systemd[1]: iotedge.service: Failed with result 'exit-code'.
Dec 15 08:44:49 Moxa systemd[1]: iotedge.service: Service hold-off time over, scheduling restart.
Dec 15 08:44:49 Moxa systemd[1]: Stopped Azure IoT Edge daemon.
Dec 15 08:44:49 Moxa systemd[1]: Started Azure IoT Edge daemon.
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Starting Azure IoT Edge Security Daemon
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Version - 1.0.9
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Using config file: /etc/iotedge/config.yaml
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Configuring certificates...
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Configuring the Device CA certificate using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.crt".
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Configuring the Device private key using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.key".
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Configuring the trusted CA certificates using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/RootCA_moxa.crt".
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Finished configuring provisioning environment variables and certificates.
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Initializing hsm...
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Finished initializing hsm.
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Provisioning edge device...
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Starting provisioning edge device via TPM...
Dec 15 08:44:49 Moxa iotedged[32181]: 2021-12-15T16:44:49Z [INFO] - Starting DPS registration with scope_id "0ne00236C76", registration_id "taiib1028226"
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - DPS registration assigned device "taiib1028226" in hub "pf-p314-iot-iothub-prod.azure-devices.net"
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Finished provisioning edge device.
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Initializing the module runtime...
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Initializing module runtime...
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Using runtime network id azure-iot-edge
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Successfully initialized module runtime
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Finished initializing the module runtime.
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Reprovisioning status InitialAssignment will trigger reconfiguration of modules.
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Detecting if configuration file has changed...
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - No change to configuration file detected.
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Edge issuer CA expiration date: 2037-07-07T01:07:06Z
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Obtaining workload CA succeeded.
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Starting management API...
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Starting workload API...
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [INFO] - Starting watchdog with 60 second frequency...
Dec 15 08:45:03 Moxa iotedged[32181]: 2021-12-15T16:45:03Z [ERR!] - The daemon could not start up successfully: Could not start management service
Dec 15 08:45:03 Moxa systemd[1]: iotedge.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 08:45:03 Moxa systemd[1]: iotedge.service: Unit entered failed state.
Dec 15 08:45:03 Moxa systemd[1]: iotedge.service: Failed with result 'exit-code'.
Dec 15 08:45:04 Moxa systemd[1]: iotedge.service: Service hold-off time over, scheduling restart.
Dec 15 08:45:04 Moxa systemd[1]: Stopped Azure IoT Edge daemon.
Dec 15 08:45:04 Moxa systemd[1]: Started Azure IoT Edge daemon.
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Starting Azure IoT Edge Security Daemon
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Version - 1.0.9
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Using config file: /etc/iotedge/config.yaml
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Configuring /var/lib/iotedge as the home directory.
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Configuring certificates...
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Configuring the Device CA certificate using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.crt".
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Configuring the Device private key using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/iotEdge_moxa.key".
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Configuring the trusted CA certificates using "/var/thingspro/apps/cloud/data/setting/azureiotedge/enroll/RootCA_moxa.crt".
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Finished configuring provisioning environment variables and certificates.
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Initializing hsm...
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Finished initializing hsm.
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Provisioning edge device...
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Starting provisioning edge device via TPM...
Dec 15 08:45:04 Moxa iotedged[32609]: 2021-12-15T16:45:04Z [INFO] - Starting DPS registration with scope_id "0ne00236C76", registration_id "taiib1028226"

This is quite baffeling.

@bilalsellak
Copy link
Contributor

Sorry about the delay, was on holidays. To be frank, without a support bundle, its some trouble to debug the issue. Also, we no longer support 1.0.9. Is there anything preventing you from upgrading versions?

@pmzara pmzara added the 1.0.9 Targeted for 1.0.9 release label Jan 10, 2022
@bilalsellak
Copy link
Contributor

@FrankSHLi following up on the comment above. Would you be able to upgrade to a version we currently support?

@FrankSHLi
Copy link
Author

@brotherneeru This issue occurs on deployed units and the cost of upgrading all of the units in the field is high. It's difficult for us to make the decision without knowing the root cause and having enough confidence level that this has been fixed in the later version.

@veyalla
Copy link
Contributor

veyalla commented Jan 20, 2022 •
edited
Loading

@FrankSHLi Unfortunately, we'll need (preferably latest) v1.1 or v1.2 to be able to make progress in diagnosing this issue. We don't have the ability to perform any investigation with older versions.

Additionally, the installed version Moby has known severe security vulnerabilities, so it be prudent to plan an upgrade of your fleet, regardless.

@arsing
Copy link
Member

arsing commented Feb 16, 2022 •
edited
Loading

For all distros except CentOS 7 (ie including Debian 9 that you're using), the default config is to use systemd socket activation. This means a) iotedge.socket and iotedge.workload.socket units are enabled, b) the socket units instruct systemd to create the sockets under /var/run/iotedge, c) the iotedge config uses fd:// URLs in the listen section since it expects systemd to bind the sockets and pass them to the process, and d) the iotedge config uses unix:///var/run/iotedge/*.sock in the connect section.

For distros that don't use systemd socket activation, a) the iotedge.socket and iotedge.mgmt.socket systemd units don't exist, b) the iotedge config uses unix:///var/lib/iotedge/*.sock URLs for both the listen and connect sections, and c) the service process unlinks and mounts the sockets itself.

Now, I assume you've changed your config to not use socket activation but left the URLs as /var/run/iotedge/*.sock. So you'll have to make sure that /var/run/iotedge is writable by the iotedge user so that iotedged can unlock and mount the sockets itself. Also, depending on the distro, /var/run is ephemeral so you'll need to recreate the directory on every boot.

But if you really don't want to use socket activation for some reason, then you should switch entirely to the config that is used for non-socket-activated distros and put the sockets in /var/lib/iotedge/. That means you should a) run systemctl disable iotedge.socket iotedge.mgmt.socket to disable the socket units so that systemd doesn't start them unnecessarily, b) change the iotedge config to use /var/lib/iotedge/*.sock in both connect and listen sections, and c) if you already have modules, they will have the old /var/run/iotedge/*.sock mounts, so docker rm -f them.

@github-actions
Copy link

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@bilalsellak bilalsellak

Labels
1.0.9 Targeted for 1.0.9 release customer-reported iotedge no-issue-activity
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@arsing @pmzara @ksaye @veyalla @FrankSHLi @bilalsellak