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.

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

aziot-identityd 1.5.0 fails to start #613

Open
jkateva opened this issue May 23, 2024 · 2 comments
Open

aziot-identityd 1.5.0 fails to start #613

jkateva opened this issue May 23, 2024 · 2 comments

Comments

@jkateva
Copy link

jkateva commented May 23, 2024

Hi. We have recently tried to use the IoT Edge 1.5 version, but we have been unable to use it. At least aziot-identityd does not start. Installing 1.4 version to clean Ubuntu 22 LTS works, but doing the same for 1.5 fails to start.

Expected Behavior

aziot-identityd starts after installation

Current Behavior

aziot-identityd fails to start:


touko 23 21:25:17 user-VirtualBox systemd[1]: Stopped Azure IoT Identity Service.
touko 23 21:25:17 user-VirtualBox systemd[1]: Started Azure IoT Identity Service.
touko 23 21:25:17 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:17Z [INFO] - Starting service...
touko 23 21:25:17 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:17Z [INFO] - Version - 1.5.0
touko 23 21:25:17 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:17Z [INFO] - Loaded openssl'd Default provider
touko 23 21:25:17 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:17Z [INFO] - Provisioning starting. Reason: Startup
touko 23 21:25:17 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:17Z [INFO] - Updated device info for temporary-test-device.
touko 23 21:25:17 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:17Z [INFO] - Provisioning complete.
touko 23 21:25:17 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:17Z [INFO] - Identity reconciliation started. Reason: Startup
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:18Z [INFO] - Could not reconcile Identities with current device data. Reprovisioning.
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:18Z [INFO] - Updated device info for temporary-test-device.
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:18Z [ERR!] - Failed to provision with IoT Hub, and no valid device backup was found: Hub client error
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:18Z [ERR!] - service encountered an error
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:18Z [ERR!] - caused by: Hub client error
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:18Z [ERR!] - caused by: ErrorCode:IotHubUnauthorizedAccess;Unauthorized
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]: 2024-05-23T18:25:18Z [ERR!] -    0: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    1: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    2: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    3: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    4: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    5: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    6: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    7: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    8: <unknown>
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:    9: __libc_start_call_main
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:              at ./csu/../sysdeps/nptl/libc_start_call_main.h:58:16
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:   10: __libc_start_main_impl
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:              at ./csu/../csu/libc-start.c:392:3
touko 23 21:25:18 user-VirtualBox aziot-identityd[9643]:   11: <unknown>
touko 23 21:25:18 user-VirtualBox systemd[1]: aziot-identityd.service: Main process exited, code=exited, status=1/FAILURE
touko 23 21:25:18 user-VirtualBox systemd[1]: aziot-identityd.service: Failed with result 'exit-code'.

Steps to Reproduce

Install Azure IoT Edge 1.5 on clean Ubuntu 22 LTS using the instructions from https://learn.microsoft.com/en-gb/azure/iot-edge/how-to-provision-single-device-linux-symmetric?view=iotedge-1.5&tabs=azure-portal%2Cubuntu

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 - Error
    could not load cert with ID "aziot-edged-trust-bundle"
    
    Caused by:
        parameter "id" has an invalid value
        caused by: not found
√ 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 - OK
√ host can connect to and perform TLS handshake with iothub HTTPS / WebSockets port - OK
√ host can connect to and perform TLS handshake with iothub MQTT port - 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 - Error
    SocketError - SocketErrorCode (TimedOut) : Operation timed out
    One or more errors occurred. (Got bad response: )
√ aziot-edge package is up-to-date - OK
√ container time is close to host time - OK
‼ DNS server - Warning
    Container engine is not configured with DNS server setting, which may impact connectivity to IoT Hub.
    Please see https://aka.ms/iotedge-prod-checklist-dns for best practices.
    You can ignore this warning if you are setting DNS server per module in the Edge deployment.
‼ 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
√ Agent image is valid and can be pulled from upstream - OK
√ proxy settings are consistent in aziot-edged, aziot-identityd, moby daemon and config.toml - OK

Connectivity checks
-------------------
√ container on the default network can connect to upstream AMQP port - OK
√ container on the default network can connect to upstream HTTPS / WebSockets port - OK
× container on the IoT Edge module network can connect to upstream AMQP port - Error
    Container on the azure-iot-edge network could not connect to liazeuwedgedevflex.azure-devices.net:5671
× container on the IoT Edge module network can connect to upstream HTTPS / WebSockets port - Error
    Container on the azure-iot-edge network could not connect to liazeuwedgedevflex.azure-devices.net:443
27 check(s) succeeded.
2 check(s) raised warnings. Re-run with --verbose for more details.
6 check(s) raised errors. Re-run with --verbose for more details.
2 check(s) were skipped due to errors from other checks. Re-run with --verbose for more details.

Output of iotedge system status

Click here

System services:
    aziot-edged             Running
    aziot-identityd         Down - activating 
    aziot-keyd              Running
    aziot-certd             Running
    aziot-tpmd              Ready

aziot-identityd is in a bad state because:
aziot-identityd.service: Down - activating : Printing the last 10 log lines.
touko 23 21:36:19 user-VirtualBox aziot-identityd[11035]:    6: <unknown>
touko 23 21:36:19 user-VirtualBox aziot-identityd[11035]:    7: <unknown>
touko 23 21:36:19 user-VirtualBox aziot-identityd[11035]:    8: <unknown>
touko 23 21:36:19 user-VirtualBox aziot-identityd[11035]:    9: __libc_start_call_main
touko 23 21:36:19 user-VirtualBox aziot-identityd[11035]:              at ./csu/../sysdeps/nptl/libc_start_call_main.h:58:16
touko 23 21:36:19 user-VirtualBox aziot-identityd[11035]:   10: __libc_start_main_impl
touko 23 21:36:19 user-VirtualBox aziot-identityd[11035]:              at ./csu/../csu/libc-start.c:392:3
touko 23 21:36:19 user-VirtualBox aziot-identityd[11035]:   11: <unknown>
touko 23 21:36:19 user-VirtualBox systemd[1]: aziot-identityd.service: Main process exited, code=exited, status=1/FAILURE
touko 23 21:36:19 user-VirtualBox systemd[1]: aziot-identityd.service: Failed with result 'exit-code'.

Device Information

  • Host OS: Ubuntu 22.04
  • Architecture: amd64
  • Container OS: Linux containers

Runtime Versions

  • aziot-edged: iotedge 1.5.0
  • Edge Agent: 1.5
  • Edge Hub: 1.5
  • Moby: 26.1.3-1

Logs

aziot-edged logs

touko 23 21:06:50 user-VirtualBox systemd[1]: Started Azure IoT Edge daemon.
touko 23 21:06:50 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:06:50Z [INFO] - Starting Azure IoT Edge Daemon
touko 23 21:06:50 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:06:50Z [INFO] - Version - 1.5.0
touko 23 21:06:50 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:06:50Z [INFO] - Obtaining Edge device provisioning data...
touko 23 21:06:55 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:06:55Z [WARN] - Failed to send HTTP request (attempt 1 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:01 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:01Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:01 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:01Z [WARN] - Failed to obtain device identity: connection error: Connection reset by peer (os error 104)
touko 23 21:07:01 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:01Z [INFO] - Requesting device reprovision
touko 23 21:07:01 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:01Z [WARN] - Failed to send HTTP request (attempt 1 of 2): error trying to connect: Permission denied (os error 13)
touko 23 21:07:07 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:07Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:07 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:07Z [WARN] - Failed to reprovision: connection error: Connection reset by peer (os error 104)
touko 23 21:07:12 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:12Z [INFO] - Obtaining Edge device provisioning data...
touko 23 21:07:12 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:12Z [WARN] - Failed to send HTTP request (attempt 1 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:18 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:18Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:18 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:18Z [WARN] - Failed to obtain device identity: connection error: Connection reset by peer (os error 104)
touko 23 21:07:18 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:18Z [INFO] - Requesting device reprovision
touko 23 21:07:18 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:18Z [WARN] - Failed to clear provisioning cache before reprovision: No such file or directory (os error 2)
touko 23 21:07:18 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:18Z [WARN] - Failed to send HTTP request (attempt 1 of 2): error trying to connect: Permission denied (os error 13)
touko 23 21:07:24 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:24Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:24 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:24Z [WARN] - Failed to reprovision: connection error: Connection reset by peer (os error 104)
touko 23 21:07:29 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:29Z [INFO] - Obtaining Edge device provisioning data...
touko 23 21:07:30 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:30Z [WARN] - Failed to send HTTP request (attempt 1 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:35 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:35Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:35 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:35Z [WARN] - Failed to obtain device identity: connection error: Connection reset by peer (os error 104)
touko 23 21:07:35 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:35Z [INFO] - Requesting device reprovision
touko 23 21:07:35 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:35Z [WARN] - Failed to clear provisioning cache before reprovision: No such file or directory (os error 2)
touko 23 21:07:35 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:35Z [WARN] - Failed to send HTTP request (attempt 1 of 2): error trying to connect: Permission denied (os error 13)
touko 23 21:07:41 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:41Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:41 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:41Z [WARN] - Failed to reprovision: connection error: Connection reset by peer (os error 104)
touko 23 21:07:46 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:46Z [INFO] - Obtaining Edge device provisioning data...
touko 23 21:07:47 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:47Z [WARN] - Failed to send HTTP request (attempt 1 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:53 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:53Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:53 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:53Z [WARN] - Failed to obtain device identity: connection error: Connection reset by peer (os error 104)
touko 23 21:07:53 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:53Z [INFO] - Requesting device reprovision
touko 23 21:07:53 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:53Z [WARN] - Failed to clear provisioning cache before reprovision: No such file or directory (os error 2)
touko 23 21:07:53 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:53Z [WARN] - Failed to send HTTP request (attempt 1 of 2): error trying to connect: Connection refused (os error 111)
touko 23 21:07:58 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:58Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:07:58 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:07:58Z [WARN] - Failed to reprovision: connection error: Connection reset by peer (os error 104)
touko 23 21:08:04 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:04Z [INFO] - Obtaining Edge device provisioning data...
touko 23 21:08:04 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:04Z [WARN] - Failed to send HTTP request (attempt 1 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:10 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:10Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:10 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:10Z [WARN] - Failed to obtain device identity: connection error: Connection reset by peer (os error 104)
touko 23 21:08:10 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:10Z [INFO] - Requesting device reprovision
touko 23 21:08:10 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:10Z [WARN] - Failed to clear provisioning cache before reprovision: No such file or directory (os error 2)
touko 23 21:08:10 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:10Z [WARN] - Failed to send HTTP request (attempt 1 of 2): error trying to connect: Connection refused (os error 111)
touko 23 21:08:16 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:16Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:16 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:16Z [WARN] - Failed to reprovision: connection error: Connection reset by peer (os error 104)
touko 23 21:08:21 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:21Z [INFO] - Obtaining Edge device provisioning data...
touko 23 21:08:21 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:21Z [WARN] - Failed to send HTTP request (attempt 1 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:27 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:27Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:27 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:27Z [WARN] - Failed to obtain device identity: connection error: Connection reset by peer (os error 104)
touko 23 21:08:27 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:27Z [INFO] - Requesting device reprovision
touko 23 21:08:27 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:27Z [WARN] - Failed to clear provisioning cache before reprovision: No such file or directory (os error 2)
touko 23 21:08:27 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:27Z [WARN] - Failed to send HTTP request (attempt 1 of 2): error trying to connect: Permission denied (os error 13)
touko 23 21:08:33 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:33Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:33 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:33Z [WARN] - Failed to reprovision: connection error: Connection reset by peer (os error 104)
touko 23 21:08:38 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:38Z [INFO] - Obtaining Edge device provisioning data...
touko 23 21:08:39 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:39Z [WARN] - Failed to send HTTP request (attempt 1 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:45 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:45Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:45 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:45Z [WARN] - Failed to obtain device identity: connection error: Connection reset by peer (os error 104)
touko 23 21:08:45 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:45Z [INFO] - Requesting device reprovision
touko 23 21:08:45 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:45Z [WARN] - Failed to clear provisioning cache before reprovision: No such file or directory (os error 2)
touko 23 21:08:45 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:45Z [WARN] - Failed to send HTTP request (attempt 1 of 2): error trying to connect: Connection refused (os error 111)
touko 23 21:08:51 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:51Z [WARN] - Failed to send HTTP request (attempt 2 of 2): connection error: Connection reset by peer (os error 104)
touko 23 21:08:51 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:51Z [WARN] - Failed to reprovision: connection error: Connection reset by peer (os error 104)
touko 23 21:08:56 user-VirtualBox aziot-edged[6290]: 2024-05-23T18:08:56Z [INFO] - Obtaining Edge device provisioning data...

aziot-identityd logs

touko 23 21:42:04 user-VirtualBox systemd[1]: aziot-identityd.service: Scheduled restart job, restart counter is at 369.
touko 23 21:42:04 user-VirtualBox systemd[1]: Stopped Azure IoT Identity Service.
touko 23 21:42:04 user-VirtualBox systemd[1]: Started Azure IoT Identity Service.
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Starting service...
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Version - 1.5.0
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Loaded openssl'd Default provider
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Provisioning starting. Reason: Startup
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Updated device info for temporary-test-device.
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Provisioning complete.
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Identity reconciliation started. Reason: Startup
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Could not reconcile Identities with current device data. Reprovisioning.
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [INFO] - Updated device info for temporary-test-device.
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [ERR!] - Failed to provision with IoT Hub, and no valid device backup was found: Hub client error
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [ERR!] - service encountered an error
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [ERR!] - caused by: Hub client error
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [ERR!] - caused by: ErrorCode:IotHubUnauthorizedAccess;Unauthorized
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]: 2024-05-23T18:42:05Z [ERR!] -    0: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    1: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    2: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    3: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    4: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    5: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    6: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    7: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    8: <unknown>
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:    9: __libc_start_call_main
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:              at ./csu/../sysdeps/nptl/libc_start_call_main.h:58:16
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:   10: __libc_start_main_impl
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:              at ./csu/../csu/libc-start.c:392:3
touko 23 21:42:05 user-VirtualBox aziot-identityd[12091]:   11: <unknown>
touko 23 21:42:05 user-VirtualBox systemd[1]: aziot-identityd.service: Main process exited, code=exited, status=1/FAILURE
touko 23 21:42:05 user-VirtualBox systemd[1]: aziot-identityd.service: Failed with result 'exit-code'.

aziot-certd logs

touko 23 21:17:56 user-VirtualBox systemd[1]: Stopped Azure IoT Certificates Service.
touko 23 21:34:09 user-VirtualBox systemd[1]: Started Azure IoT Certificates Service.
touko 23 21:34:09 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:34:09Z [INFO] - Starting service...
touko 23 21:34:09 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:34:09Z [INFO] - Version - 1.5.0
touko 23 21:34:09 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:34:09Z [INFO] - Starting server...
touko 23 21:34:09 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:34:09Z [INFO] - <-- GET /certificates/aziot-edged-trust-bundle?api-version=2020-09-01 {"host": "certd.sock"}
touko 23 21:34:09 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:34:09Z [INFO] - !!! parameter "id" has an invalid value
touko 23 21:34:09 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:34:09Z [INFO] - !!! caused by: not found
touko 23 21:34:09 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:34:09Z [INFO] - --> 400 {"content-type": "application/json"}
touko 23 21:41:27 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:41:27Z [INFO] - <-- GET /certificates/aziot-edged-trust-bundle?api-version=2020-09-01 {"host": "certd.sock"}
touko 23 21:41:27 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:41:27Z [INFO] - !!! parameter "id" has an invalid value
touko 23 21:41:27 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:41:27Z [INFO] - !!! caused by: not found
touko 23 21:41:27 user-VirtualBox aziot-certd[10331]: 2024-05-23T18:41:27Z [INFO] - --> 400 {"content-type": "application/json"}

@jkateva
Copy link
Author

jkateva commented May 23, 2024

I'm not certain is this aziot-identityd problem, but iotedge system status gives only this as error.

@jkateva
Copy link
Author

jkateva commented May 24, 2024

I can reproduce this problem using an edge device that has been used with 1.4 previously, but the startup succeeds using a new edge device created today.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant