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

aziot-edged is overwhelming IoT Hub with identity operations #7395

Open
PAKalucki opened this issue Nov 19, 2024 · 4 comments
Open

aziot-edged is overwhelming IoT Hub with identity operations #7395

PAKalucki opened this issue Nov 19, 2024 · 4 comments
Assignees
@ggjjj

Comments

@PAKalucki
Copy link

Expected Behavior

aziot-edged should not be sending so many requests

Current Behavior

After half year of using IoT Hub we started getting throttling errors.
Image
During investigation we found out that IoT Hub is being bombarded with identity get operations
Image

We have checked logs from devices which are source of most of the requests and we found aziot-edged is unsucessfully trying to list every few seconds (logs below)

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 - Warning
    Installed aziot-identity-service package has version 1.2.6 but 1.4.9 is the latest stable version available.
    Please see https://aka.ms/aziot-update-runtime for update instructions.
√ 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
√ 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.2.10 but 1.4.41 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 - 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 - OK
√ production readiness: Edge Hub's storage directory is persisted on the host filesystem - OK
√ proxy settings are consistent in aziot-edged, aziot-identityd, moby daemon and config.toml - OK

Connectivity checks
-------------------
23 check(s) succeeded.
7 check(s) raised warnings. 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 22.04, Windows Server IoT 2019]: Debian GNU/Linux 10 (buster)
  • Architecture [e.g. amd64, arm32, arm64]: arm32
  • Container OS [e.g. Linux containers, Windows containers]: Linux containers

Runtime Versions

  • aziot-edged [run iotedge version]: 1.2.10
  • Edge Agent [image tag (e.g. 1.0.0)]: 1.2
  • Edge Hub [image tag (e.g. 1.0.0)]: 1.2
  • Docker/Moby [run docker version]: Docker version 3.0.13+azure, build dd360c7c0de8d9132a3965db6a59d3ae74f43ba7

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

Logs

aziot-edged logs 
Nov 19 14:10:41 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:10:41Z [INFO] - [mgmt] - - - [2024-11-19 14:10:41.162019389 UTC] "GET /identities/?api-version=2021-12-07 HTTP/1.1" 500 Internal Server Error 148 "-" "-" auth_id(-)
Nov 19 14:10:46 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:10:46Z [INFO] - <-- GET /identities/modules?api-version=2020-09-01&type=aziot {"host": "2f72756e2f617a696f742f6964656e74697479642e736f636b:0"}
Nov 19 14:10:46 il3-48-241325-0138 aziot-keyd[949]: 2024-11-19T14:10:46Z [INFO] - <-- GET /key/device-id?api-version=2020-09-01 {"host": "keyd.sock"}
Nov 19 14:10:46 il3-48-241325-0138 aziot-keyd[949]: 2024-11-19T14:10:46Z [INFO] - --> 200 {"content-type": "application/json"}
Nov 19 14:10:46 il3-48-241325-0138 aziot-keyd[949]: 2024-11-19T14:10:46Z [INFO] - <-- POST /sign?api-version=2020-09-01 {"content-type": "application/json", "host": "keyd.sock", "content-length": "398"}
Nov 19 14:10:46 il3-48-241325-0138 aziot-keyd[949]: 2024-11-19T14:10:46Z [INFO] - --> 200 {"content-type": "application/json"}
Nov 19 14:10:49 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:10:49Z [INFO] - Querying system resources...
Nov 19 14:10:56 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:10:56Z [WARN] - Failed to communicate with IoT Hub (attempt 1 of 1): timed out
Nov 19 14:10:56 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:10:56Z [INFO] - !!! Hub client error
Nov 19 14:10:56 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:10:56Z [INFO] - !!! caused by: timed out
Nov 19 14:10:56 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:10:56Z [INFO] - --> 404 {"content-type": "application/json"}
Nov 19 14:10:56 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:10:56Z [ERR!] - Internal server error: Could not list identities
Nov 19 14:10:56 il3-48-241325-0138 aziot-edged[906]:         caused by: HTTP response error: [404 Not Found] {"message":"Hub client error\ncaused by: timed out"}
Nov 19 14:10:56 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:10:56Z [INFO] - [mgmt] - - - [2024-11-19 14:10:56.084436107 UTC] "GET /identities/?api-version=2021-12-07 HTTP/1.1" 500 Internal Server Error 148 "-" "-" auth_id(-)
Nov 19 14:11:01 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:11:01Z [INFO] - [mgmt] - - - [2024-11-19 14:11:01.299404856 UTC] "GET /systeminfo/resources?api-version=2021-12-07 HTTP/1.1" 200 OK 12575 "-" "-" auth_id(-)
Nov 19 14:11:07 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:11:07Z [INFO] - <-- GET /identities/modules?api-version=2020-09-01&type=aziot {"host": "2f72756e2f617a696f742f6964656e74697479642e736f636b:0"}
Nov 19 14:11:07 il3-48-241325-0138 aziot-keyd[949]: 2024-11-19T14:11:07Z [INFO] - <-- GET /key/device-id?api-version=2020-09-01 {"host": "keyd.sock"}
Nov 19 14:11:07 il3-48-241325-0138 aziot-keyd[949]: 2024-11-19T14:11:07Z [INFO] - --> 200 {"content-type": "application/json"}
Nov 19 14:11:07 il3-48-241325-0138 aziot-keyd[949]: 2024-11-19T14:11:07Z [INFO] - <-- POST /sign?api-version=2020-09-01 {"content-type": "application/json", "host": "keyd.sock", "content-length": "398"}
Nov 19 14:11:07 il3-48-241325-0138 aziot-keyd[949]: 2024-11-19T14:11:07Z [INFO] - --> 200 {"content-type": "application/json"}
Nov 19 14:11:11 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:11:11Z [INFO] - Checking edge runtime status
Nov 19 14:11:11 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:11:11Z [INFO] - Edge runtime is running.
Nov 19 14:11:17 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:11:17Z [WARN] - Failed to communicate with IoT Hub (attempt 1 of 1): timed out
Nov 19 14:11:17 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:11:17Z [INFO] - !!! Hub client error
Nov 19 14:11:17 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:11:17Z [INFO] - !!! caused by: timed out
Nov 19 14:11:17 il3-48-241325-0138 aziot-identityd[923]: 2024-11-19T14:11:17Z [INFO] - --> 404 {"content-type": "application/json"}
Nov 19 14:11:17 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:11:17Z [ERR!] - Internal server error: Could not list identities
Nov 19 14:11:17 il3-48-241325-0138 aziot-edged[906]:         caused by: HTTP response error: [404 Not Found] {"message":"Hub client error\ncaused by: timed out"}
Nov 19 14:11:17 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:11:17Z [INFO] - [mgmt] - - - [2024-11-19 14:11:17.800236771 UTC] "GET /identities/?api-version=2021-12-07 HTTP/1.1" 500 Internal Server Error 148 "-" "-" auth_id(-)
Nov 19 14:11:22 il3-48-241325-0138 aziot-edged[906]: 2024-11-19T14:11:22Z [INFO] - [mgmt] - - - [2024-11-19 14:11:22.921294785 UTC] "GET /modules?api-version=2021-12-07 HTTP/1.1" 200 OK 4062 "-" "-" auth_id(-)
edge-agent logs 

<Paste here between the triple backticks>
edge-hub logs 

2024-11-19 13:56:00 +00:00 Starting Edge Hub
�[2mNov 19 13:56:00.115 �[0m�[32m INFO�[0m watchdog: Starting Watchdog
�[2mNov 19 13:56:00.116 �[0m�[32m INFO�[0m watchdog: Registering shutdown signal listener
�[2mNov 19 13:56:00.124 �[0m�[32m INFO�[0m watchdog: MQTT broker is disabled
�[2mNov 19 13:56:00.131 �[0m�[32m INFO�[0m watchdog::child: Launched Edge Hub process with pid 9
2024-11-19 13:56:01.343 +00:00 Edge Hub Main()
<6> 2024-11-19 13:56:11.839 +00:00 [INF] - Installing certificates [CN=iotedged workload ca il3-48-241325-0138:11/27/2024 13:22:20] to Root
<6> 2024-11-19 13:56:12.422 +00:00 [INF] - Installing certificates [CN=iotedged workload ca il3-48-241325-0138:11/27/2024 13:22:20] to Root
<6> 2024-11-19 13:56:12.475 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12
<6> 2024-11-19 13:56:16.445 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableMqttBroker":false}
<6> 2024-11-19 13:56:36.099 +00:00 [INF] - Created persistent store at /iotedge/storage/edgeHub
<6> 2024-11-19 13:56:39.025 +00:00 [INF] - Initializing Edge Hub
<6> 2024-11-19 13:56:39.042 +00:00 [INF] - 
        █████╗ ███████╗██╗   ██╗██████╗ ███████╗
       ██╔══██╗╚══███╔╝██║   ██║██╔══██╗██╔════╝
       ███████║  ███╔╝ ██║   ██║██████╔╝█████╗
       ██╔══██║ ███╔╝  ██║   ██║██╔══██╗██╔══╝
       ██║  ██║███████╗╚██████╔╝██║  ██║███████╗
       ╚═╝  ╚═╝╚══════╝ ╚═════╝ ╚═╝  ╚═╝╚══════╝

 ██╗ ██████╗ ████████╗    ███████╗██████╗  ██████╗ ███████╗
 ██║██╔═══██╗╚══██╔══╝    ██╔════╝██╔══██╗██╔════╝ ██╔════╝
 ██║██║   ██║   ██║       █████╗  ██║  ██║██║  ███╗█████╗
 ██║██║   ██║   ██║       ██╔══╝  ██║  ██║██║   ██║██╔══╝
 ██║╚██████╔╝   ██║       ███████╗██████╔╝╚██████╔╝███████╗
 ╚═╝ ╚═════╝    ╚═╝       ╚══════╝╚═════╝  ╚═════╝ ╚══════╝

<6> 2024-11-19 13:56:39.055 +00:00 [INF] - Version - 1.2.10.55800403 (719bffd58b353dc0156010ad76ede96c611fb4ef)
<6> 2024-11-19 13:56:39.088 +00:00 [INF] - OptimizeForPerformance=False
<6> 2024-11-19 13:56:39.090 +00:00 [INF] - MessageAckTimeoutSecs=30
<6> 2024-11-19 13:56:39.144 +00:00 [INF] - Loaded server certificate with expiration date of "2024-11-27T13:22:20.0000000+00:00"
<6> 2024-11-19 13:56:39.303 +00:00 [INF] - Using Asp Net server for metrics
<6> 2024-11-19 13:56:40.317 +00:00 [INF] - Started task to cleanup processed and stale messages
<6> 2024-11-19 13:56:40.378 +00:00 [INF] - Created new message store
<6> 2024-11-19 13:56:42.030 +00:00 [INF] - Add node: il3-48-241325-0138
<6> 2024-11-19 13:56:42.073 +00:00 [INF] - Add node: il3-48-241325-0138/$edgeAgent
<6> 2024-11-19 13:56:42.098 +00:00 [INF] - Add node: il3-48-241325-0138/$edgeHub
<6> 2024-11-19 13:56:42.099 +00:00 [INF] - Add node: il3-48-241325-0138/IoTHubDeviceUpdate
<6> 2024-11-19 13:56:42.100 +00:00 [INF] - Add node: il3-48-241325-0138/MetricsCollector
<6> 2024-11-19 13:56:42.100 +00:00 [INF] - Add node: il3-48-241325-0138/gpioiot
<6> 2024-11-19 13:56:42.102 +00:00 [INF] - Add node: il3-48-241325-0138/ilmanager
<6> 2024-11-19 13:56:42.107 +00:00 [INF] - Add node: il3-48-241325-0138/lighttpd
<6> 2024-11-19 13:56:42.109 +00:00 [INF] - Add node: il3-48-241325-0138/logger
<6> 2024-11-19 13:56:42.195 +00:00 [INF] - Created device scope identities cache
<6> 2024-11-19 13:56:42.436 +00:00 [INF] - Starting refresh of device scope identities cache
<6> 2024-11-19 13:56:42.747 +00:00 [INF] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00
<6> 2024-11-19 13:56:43.433 +00:00 [INF] - Initialized storing twin manager
<6> 2024-11-19 13:56:44.043 +00:00 [INF] - Updated node: il3-48-241325-0138/$edgeHub
<6> 2024-11-19 13:56:44.057 +00:00 [INF] - Initializing configuration
<6> 2024-11-19 13:56:44.329 +00:00 [INF] - New device connection for device il3-48-241325-0138/$edgeHub
<6> 2024-11-19 13:56:44.481 +00:00 [INF] - Client il3-48-241325-0138/$edgeHub connected to edgeHub, processing existing subscriptions.
<6> 2024-11-19 13:56:45.423 +00:00 [INF] - Attempting to connect to IoT Hub for client il3-48-241325-0138/$edgeHub via AMQP over WebSockets...
<6> 2024-11-19 13:56:45.980 +00:00 [INF] - Processing pending subscriptions for il3-48-241325-0138/$edgeHub
<6> 2024-11-19 13:56:53.905 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableMqttBroker":false}
<6> 2024-11-19 13:56:54.941 +00:00 [INF] - Starting timer to authenticate connections with a period of 300 seconds
<6> 2024-11-19 13:56:57.927 +00:00 [INF] - Scheduling server certificate renewal for "2024-11-27T13:19:50.0009057Z".
<6> 2024-11-19 13:57:01.619 +00:00 [INF] - Created cloud endpoint iothub with max batch size 10 and fan-out factor of 10.
<6> 2024-11-19 13:57:08.077 +00:00 [INF] - Set the following 10 route(s) in edge hub
<6> 2024-11-19 13:57:08.096 +00:00 [INF] - MetricsCollectorToIoTHub: FROM /messages/modules/MetricsCollector/* INTO $upstream
<6> 2024-11-19 13:57:08.097 +00:00 [INF] - gpioiotToIoTHub: FROM /messages/modules/gpioiot/outputs/* INTO $upstream
<6> 2024-11-19 13:57:08.100 +00:00 [INF] - gpioiotToilmanager: FROM /messages/modules/gpioiot/outputs/gpioiotToilmanager INTO BrokeredEndpoint("/modules/ilmanager/inputs/gpioiotToilmanager")
<6> 2024-11-19 13:57:08.102 +00:00 [INF] - gpioiotTolighttpd: FROM /messages/modules/gpioiot/outputs/gpioiotTolighttpd INTO BrokeredEndpoint("/modules/lighttpd/inputs/gpioiotTolighttpd")
<6> 2024-11-19 13:57:08.104 +00:00 [INF] - ilmanagerToIoTHub: FROM /messages/modules/ilmanager/outputs/* INTO $upstream
<6> 2024-11-19 13:57:08.107 +00:00 [INF] - ilmanagerTogpioiot: FROM /messages/modules/ilmanager/outputs/ilmanagerTogpioiot INTO BrokeredEndpoint("/modules/gpioiot/inputs/ilmanagerTogpioiot")
<6> 2024-11-19 13:57:08.119 +00:00 [INF] - ilmanagerTolighttpd: FROM /messages/modules/ilmanager/outputs/ilmanagerTolighttpd INTO BrokeredEndpoint("/modules/lighttpd/inputs/ilmanagerTolighttpd")
<6> 2024-11-19 13:57:08.121 +00:00 [INF] - lighttpdToIoTHub: FROM /messages/modules/lighttpd/outputs/* INTO $upstream
<6> 2024-11-19 13:57:08.122 +00:00 [INF] - lighttpdTogpioiot: FROM /messages/modules/lighttpd/outputs/lighttpdTogpioiot INTO BrokeredEndpoint("/modules/gpioiot/inputs/lighttpdTogpioiot")
<6> 2024-11-19 13:57:08.126 +00:00 [INF] - lighttpdToilmanager: FROM /messages/modules/lighttpd/outputs/lighttpdToilmanager INTO BrokeredEndpoint("/modules/ilmanager/inputs/lighttpdToilmanager")
<6> 2024-11-19 13:57:08.206 +00:00 [INF] - Updated message store TTL to 7200 seconds
<6> 2024-11-19 13:57:08.215 +00:00 [INF] - Updated the edge hub store and forward configuration
<6> 2024-11-19 13:57:08.653 +00:00 [INF] - Started operation Get EdgeHub config
<6> 2024-11-19 13:57:08.669 +00:00 [INF] - Initialized edge hub configuration
<6> 2024-11-19 13:57:08.677 +00:00 [INF] - Starting protocol heads - (MQTT, AMQP, HTTP)
<6> 2024-11-19 13:57:08.724 +00:00 [INF] - Starting MQTT head
<6> 2024-11-19 13:57:09.114 +00:00 [INF] - Initializing TLS endpoint on port 8883 for MQTT head.
<6> 2024-11-19 13:57:10.086 +00:00 [INF] - Starting AMQP head
<6> 2024-11-19 13:57:10.341 +00:00 [INF] - Started MQTT head
<6> 2024-11-19 13:57:12.470 +00:00 [INF] - Started AMQP head
<6> 2024-11-19 13:57:12.519 +00:00 [INF] - Starting HTTP head
<4> 2024-11-19 13:57:16.460 +00:00 [WRN] - Overriding address(es) '"http://+:80"'. Binding to endpoints defined in "UseKestrel()" instead.
<6> 2024-11-19 13:57:16.634 +00:00 [INF] - Started HTTP head
<6> 2024-11-19 13:57:17.901 +00:00 [INF] - Client il3-48-241325-0138/lighttpd in device scope authenticated locally.
<6> 2024-11-19 13:57:18.220 +00:00 [INF] - Successfully generated identity for clientId il3-48-241325-0138/lighttpd and username xyz.azure-devices.net/il3-48-241325-0138/lighttpd/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.6.0%20(native%3b%20Linux%3b%20armv7l)
<6> 2024-11-19 13:57:18.303 +00:00 [INF] - ClientAuthenticated, il3-48-241325-0138/lighttpd, 13579d36
<6> 2024-11-19 13:57:18.638 +00:00 [INF] - New device connection for device il3-48-241325-0138/lighttpd
<6> 2024-11-19 13:57:18.644 +00:00 [INF] - Client il3-48-241325-0138/lighttpd connected to edgeHub, processing existing subscriptions.
<6> 2024-11-19 13:57:18.667 +00:00 [INF] - Attempting to connect to IoT Hub for client il3-48-241325-0138/lighttpd via AMQP over WebSockets...
<6> 2024-11-19 13:57:19.107 +00:00 [INF] - Bind device proxy for device il3-48-241325-0138/lighttpd
<6> 2024-11-19 13:57:19.117 +00:00 [INF] - Binding message channel for device Id il3-48-241325-0138/lighttpd
<6> 2024-11-19 13:57:19.265 +00:00 [INF] - Processing subscriptions TwinResponse, ModuleMessages, DesiredPropertyUpdates for client il3-48-241325-0138/lighttpd.
<6> 2024-11-19 13:57:19.342 +00:00 [INF] - Set subscriptions from session state for il3-48-241325-0138/lighttpd
<4> 2024-11-19 13:57:21.958 +00:00 [WRN] - Module il3-48-241325-0138/gpioiot is not connected
<4> 2024-11-19 13:57:23.398 +00:00 [WRN] - Module il3-48-241325-0138/gpioiot is not connected
<4> 2024-11-19 13:57:25.232 +00:00 [WRN] - Module il3-48-241325-0138/gpioiot is not connected
<6> 2024-11-19 13:57:25.311 +00:00 [INF] - Client il3-48-241325-0138/gpioiot in device scope authenticated locally.
<6> 2024-11-19 13:57:25.316 +00:00 [INF] - Successfully generated identity for clientId il3-48-241325-0138/gpioiot and username xyz.azure-devices.net/il3-48-241325-0138/gpioiot/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.6.0%20(native%3b%20Linux%3b%20armv7l)
<6> 2024-11-19 13:57:25.318 +00:00 [INF] - ClientAuthenticated, il3-48-241325-0138/gpioiot, 7237f0fa
<6> 2024-11-19 13:57:25.339 +00:00 [INF] - New device connection for device il3-48-241325-0138/gpioiot
<6> 2024-11-19 13:57:25.341 +00:00 [INF] - Client il3-48-241325-0138/gpioiot connected to edgeHub, processing existing subscriptions.
<6> 2024-11-19 13:57:25.346 +00:00 [INF] - Attempting to connect to IoT Hub for client il3-48-241325-0138/gpioiot via AMQP over WebSockets...
<6> 2024-11-19 13:57:25.374 +00:00 [INF] - Bind device proxy for device il3-48-241325-0138/gpioiot
<6> 2024-11-19 13:57:25.374 +00:00 [INF] - Binding message channel for device Id il3-48-241325-0138/gpioiot
<6> 2024-11-19 13:57:25.379 +00:00 [INF] - Processing subscriptions TwinResponse, ModuleMessages, DesiredPropertyUpdates for client il3-48-241325-0138/gpioiot.
<6> 2024-11-19 13:57:25.382 +00:00 [INF] - Set subscriptions from session state for il3-48-241325-0138/gpioiot
<6> 2024-11-19 13:57:35.333 +00:00 [INF] - Client il3-48-241325-0138/ilmanager in device scope authenticated locally.
<6> 2024-11-19 13:57:35.353 +00:00 [INF] - Successfully generated identity for clientId il3-48-241325-0138/ilmanager and username xyz.azure-devices.net/il3-48-241325-0138/ilmanager/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.6.0%20(native%3b%20Linux%3b%20armv7l)
<6> 2024-11-19 13:57:35.357 +00:00 [INF] - ClientAuthenticated, il3-48-241325-0138/ilmanager, 61ef046d
<6> 2024-11-19 13:57:35.394 +00:00 [INF] - New device connection for device il3-48-241325-0138/ilmanager
<6> 2024-11-19 13:57:35.397 +00:00 [INF] - Client il3-48-241325-0138/ilmanager connected to edgeHub, processing existing subscriptions.
<6> 2024-11-19 13:57:35.404 +00:00 [INF] - Attempting to connect to IoT Hub for client il3-48-241325-0138/ilmanager via AMQP over WebSockets...
<6> 2024-11-19 13:57:35.437 +00:00 [INF] - Bind device proxy for device il3-48-241325-0138/ilmanager
<6> 2024-11-19 13:57:35.438 +00:00 [INF] - Binding message channel for device Id il3-48-241325-0138/ilmanager
<6> 2024-11-19 13:57:35.463 +00:00 [INF] - Processing subscriptions TwinResponse, ModuleMessages, DesiredPropertyUpdates for client il3-48-241325-0138/ilmanager.
<6> 2024-11-19 13:57:35.495 +00:00 [INF] - Set subscriptions from session state for il3-48-241325-0138/ilmanager
<6> 2024-11-19 13:58:06.524 +00:00 [INF] - Not changed node: il3-48-241325-0138
<6> 2024-11-19 13:58:06.527 +00:00 [INF] - Not changed node: il3-48-241325-0138/$edgeAgent
<6> 2024-11-19 13:58:06.528 +00:00 [INF] - Updated node: il3-48-241325-0138/$edgeHub
<6> 2024-11-19 13:58:06.774 +00:00 [INF] - Service identity for il3-48-241325-0138/$edgeHub in device scope was updated.
<6> 2024-11-19 13:58:06.776 +00:00 [INF] - Not changed node: il3-48-241325-0138/IoTHubDeviceUpdate
<6> 2024-11-19 13:58:06.777 +00:00 [INF] - Not changed node: il3-48-241325-0138/lighttpd
<6> 2024-11-19 13:58:06.778 +00:00 [INF] - Not changed node: il3-48-241325-0138/ilmanager
<6> 2024-11-19 13:58:06.778 +00:00 [INF] - Not changed node: il3-48-241325-0138/gpioiot
<6> 2024-11-19 13:58:06.779 +00:00 [INF] - Not changed node: il3-48-241325-0138/logger
<6> 2024-11-19 13:58:06.780 +00:00 [INF] - Not changed node: il3-48-241325-0138/MetricsCollector
<6> 2024-11-19 13:58:06.804 +00:00 [INF] - Done refreshing device scope identities cache. Waiting for 60 minutes.
<4> 2024-11-19 13:58:26.052 +00:00 [WRN] - Error creating cloud connection for client il3-48-241325-0138/lighttpd
System.TimeoutException: The operation timed out.
 ---> Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException: Creation of RequestResponseAmqpLink did not complete in 0 milliseconds.
 ---> System.TimeoutException: Creation of RequestResponseAmqpLink did not complete in 0 milliseconds.
   at Microsoft.Azure.Amqp.Singleton`1.GetOrCreateAsync(TimeSpan timeout)
   at Microsoft.Azure.Amqp.TaskHelpers.EndAsyncResult(IAsyncResult asyncResult)
   at Microsoft.Azure.Amqp.IteratorAsyncResult`1.<>c.<CallTask>b__24_1(TIteratorAsyncResult thisPtr, IAsyncResult r)
   at Microsoft.Azure.Amqp.IteratorAsyncResult`1.StepCallback(IAsyncResult result)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Amqp.ExceptionDispatcher.Throw(Exception exception)
   at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at Microsoft.Azure.Amqp.AsyncResult`1.End(IAsyncResult asyncResult)
   at Microsoft.Azure.Amqp.AmqpCbsLink.EndSendToken(IAsyncResult result)
   at Microsoft.Azure.Amqp.AmqpCbsLink.<>c__DisplayClass4_0.<SendTokenAsync>b__1(IAsyncResult a)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTCbsLink.SendTokenAsync(ICbsTokenProvider tokenProvider, Uri namespaceAddress, String audience, String resource, String[] requiredClaims, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpAuthenticationRefresher.InitLoopAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTConnection.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTConnection.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpConnectionHolder.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.EnsureSessionIsOpenAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.OpenAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.OpenAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.Transport.ProtocolRoutingDelegatingHandler.OpenAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass27_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
   at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass38_0.<<OpenInternalAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.EnsureOpenedAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.InternalClient.OpenAsync()
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.Client.InternalClient.OpenAsync()
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 158
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 56
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<<InvokeFunc>b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 194
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 146
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 182
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 62
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.ConnectToIoTHub(ITokenProvider newTokenProvider) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 137
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 112
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.Create(IIdentity identity, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, ITokenProvider tokenProvider, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, TimeSpan cloudConnectionHangingTimeout, String productInfo, Option`1 modelId) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 101
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.TryCreateCloudConnectionFromServiceIdentity(IIdentity identity, Action`2 connectionStatusChangedHandler, Boolean refreshOutOfDateCache, CloudListener cloudListener, String authChain) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 285
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternalWithDeviceStateTracking(IIdentity identity, Action`2 connectionStatusChangedHandler, Boolean refreshCachedIdentity) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 256
<4> 2024-11-19 13:58:26.221 +00:00 [WRN] - Error creating cloud connection for client il3-48-241325-0138/gpioiot
System.TimeoutException: The operation timed out.
 ---> Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException: The operation did not complete within the allocated time 00:00:00.0057252 for object $cbs.
 ---> System.TimeoutException: The operation did not complete within the allocated time 00:00:00.0057252 for object $cbs.
   at Microsoft.Azure.Amqp.ExceptionDispatcher.Throw(Exception exception)
   at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at Microsoft.Azure.Amqp.AsyncResult`1.End(IAsyncResult asyncResult)
   at Microsoft.Azure.Amqp.AmqpCbsLink.EndCreateCbsLink(IAsyncResult result)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Amqp.FaultTolerantAmqpObject`1.OnCreateAsync(TimeSpan timeout)
   at Microsoft.Azure.Amqp.Singleton`1.GetOrCreateAsync(TimeSpan timeout)
   at Microsoft.Azure.Amqp.Singleton`1.GetOrCreateAsync(TimeSpan timeout)
   at Microsoft.Azure.Amqp.TaskHelpers.EndAsyncResult(IAsyncResult asyncResult)
   at Microsoft.Azure.Amqp.IteratorAsyncResult`1.<>c.<CallTask>b__24_1(TIteratorAsyncResult thisPtr, IAsyncResult r)
   at Microsoft.Azure.Amqp.IteratorAsyncResult`1.StepCallback(IAsyncResult result)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Amqp.ExceptionDispatcher.Throw(Exception exception)
   at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at Microsoft.Azure.Amqp.AsyncResult`1.End(IAsyncResult asyncResult)
   at Microsoft.Azure.Amqp.AmqpCbsLink.EndSendToken(IAsyncResult result)
   at Microsoft.Azure.Amqp.AmqpCbsLink.<>c__DisplayClass4_0.<SendTokenAsync>b__1(IAsyncResult a)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTCbsLink.SendTokenAsync(ICbsTokenProvider tokenProvider, Uri namespaceAddress, String audience, String resource, String[] requiredClaims, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpAuthenticationRefresher.InitLoopAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTConnection.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTConnection.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpConnectionHolder.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.EnsureSessionIsOpenAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.OpenAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.OpenAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.Transport.ProtocolRoutingDelegatingHandler.OpenAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass27_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
   at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass38_0.<<OpenInternalAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.EnsureOpenedAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.InternalClient.OpenAsync()
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.Client.InternalClient.OpenAsync()
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 158
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 56
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<<InvokeFunc>b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 194
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 146
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 182
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 62
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.ConnectToIoTHub(ITokenProvider newTokenProvider) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 137
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 112
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.Create(IIdentity identity, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, ITokenProvider tokenProvider, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, TimeSpan cloudConnectionHangingTimeout, String productInfo, Option`1 modelId) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 101
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.TryCreateCloudConnectionFromServiceIdentity(IIdentity identity, Action`2 connectionStatusChangedHandler, Boolean refreshOutOfDateCache, CloudListener cloudListener, String authChain) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 285
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternalWithDeviceStateTracking(IIdentity identity, Action`2 connectionStatusChangedHandler, Boolean refreshCachedIdentity) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 256
<4> 2024-11-19 13:58:26.051 +00:00 [WRN] - Error creating cloud connection for client il3-48-241325-0138/$edgeHub
System.TimeoutException: The operation timed out.
 ---> Microsoft.Azure.Devices.Client.Exceptions.IotHubCommunicationException: Creation of RequestResponseAmqpLink did not complete in 0 milliseconds.
 ---> System.TimeoutException: Creation of RequestResponseAmqpLink did not complete in 0 milliseconds.
   at Microsoft.Azure.Amqp.Singleton`1.GetOrCreateAsync(TimeSpan timeout)
   at Microsoft.Azure.Amqp.TaskHelpers.EndAsyncResult(IAsyncResult asyncResult)
   at Microsoft.Azure.Amqp.IteratorAsyncResult`1.<>c.<CallTask>b__24_1(TIteratorAsyncResult thisPtr, IAsyncResult r)
   at Microsoft.Azure.Amqp.IteratorAsyncResult`1.StepCallback(IAsyncResult result)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Amqp.ExceptionDispatcher.Throw(Exception exception)
   at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at Microsoft.Azure.Amqp.AsyncResult`1.End(IAsyncResult asyncResult)
   at Microsoft.Azure.Amqp.AmqpCbsLink.EndSendToken(IAsyncResult result)
   at Microsoft.Azure.Amqp.AmqpCbsLink.<>c__DisplayClass4_0.<SendTokenAsync>b__1(IAsyncResult a)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTCbsLink.SendTokenAsync(ICbsTokenProvider tokenProvider, Uri namespaceAddress, String audience, String resource, String[] requiredClaims, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpAuthenticationRefresher.InitLoopAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTConnection.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpIoTConnection.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpConnectionHolder.CreateRefresherAsync(DeviceIdentity deviceIdentity, TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.EnsureSessionIsOpenAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.AmqpIoT.AmqpUnit.OpenAsync(TimeSpan timeout)
   at Microsoft.Azure.Devices.Client.Transport.Amqp.AmqpTransportHandler.OpenAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.Transport.ProtocolRoutingDelegatingHandler.OpenAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.<>c__DisplayClass27_0.<<ExecuteWithErrorHandlingAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.ErrorDelegatingHandler.ExecuteWithErrorHandlingAsync[T](Func`1 asyncOperation)
   at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.<>c__DisplayClass38_0.<<OpenInternalAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Client.Transport.RetryDelegatingHandler.EnsureOpenedAsync(CancellationToken cancellationToken)
   at Microsoft.Azure.Devices.Client.InternalClient.OpenAsync()
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Devices.Client.InternalClient.OpenAsync()
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout, Action action) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 158
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 56
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<<InvokeFunc>b__0>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 194
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 146
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 182
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 62
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.ConnectToIoTHub(ITokenProvider newTokenProvider) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 137
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 112
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.Create(IIdentity identity, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, ITokenProvider tokenProvider, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, TimeSpan cloudConnectionHangingTimeout, String productInfo, Option`1 modelId) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 101
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.TryCreateCloudConnectionFromServiceIdentity(IIdentity identity, Action`2 connectionStatusChangedHandler, Boolean refreshOutOfDateCache, CloudListener cloudListener, String authChain) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 285
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternalWithDeviceStateTracking(IIdentity identity, Action`2 connectionStatusChangedHandler, Boolean refreshCachedIdentity) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 256
...
<4> 2024-11-19 13:58:26.924 +00:00 [WRN] - Updating reported properties failed il3-48-241325-0138/$edgeHub
<4> 2024-11-19 13:58:26.976 +00:00 [WRN] - Could not get an active Iot Hub connection for client il3-48-241325-0138/lighttpd
<6> 2024-11-19 13:58:27.823 +00:00 [INF] - Processing subscriptions TwinResponse, ModuleMessages, DesiredPropertyUpdates for client il3-48-241325-0138/ilmanager.
<6> 2024-11-19 13:58:28.005 +00:00 [INF] - Set subscriptions from session state for il3-48-241325-0138/ilmanager
<6> 2024-11-19 13:58:29.373 +00:00 [INF] - Exiting disconnected state
<6> 2024-11-19 13:58:29.421 +00:00 [INF] - Received device connected callback
<6> 2024-11-19 13:58:29.442 +00:00 [INF] - Device connected to cloud, processing subscriptions for connected clients.
<6> 2024-11-19 13:58:29.461 +00:00 [INF] - Processing subscriptions for client il3-48-241325-0138/$edgeHub on device connected to cloud.
<6> 2024-11-19 13:58:29.478 +00:00 [INF] - Attempting to connect to IoT Hub for client il3-48-241325-0138/$edgeHub via AMQP over WebSockets...
<6> 2024-11-19 13:58:29.501 +00:00 [INF] - Processing subscriptions for client il3-48-241325-0138/gpioiot on device connected to cloud.
<6> 2024-11-19 13:58:29.506 +00:00 [INF] - Attempting to connect to IoT Hub for client il3-48-241325-0138/gpioiot via AMQP over WebSockets...
<6> 2024-11-19 13:58:29.511 +00:00 [INF] - Processing subscriptions for client il3-48-241325-0138/lighttpd on device connected to cloud.
<6> 2024-11-19 13:58:29.511 +00:00 [INF] - Processing subscriptions for client il3-48-241325-0138/ilmanager on device connected to cloud.
<6> 2024-11-19 13:58:29.514 +00:00 [INF] - Attempting to connect to IoT Hub for client il3-48-241325-0138/ilmanager via AMQP over WebSockets...
<6> 2024-11-19 13:58:29.545 +00:00 [INF] - Skipping cache refresh, waiting 97 seconds until refreshing again.
<6> 2024-11-19 13:58:29.622 +00:00 [INF] - Entering connected state
@ggjjj ggjjj self-assigned this Nov 19, 2024
@ggjjj
Copy link
Contributor

ggjjj commented Nov 19, 2024

The support for 1.2 Versions ended 2 years ago I believe. So please upgrade to latest to fix this issue!

@PAKalucki
Copy link
Author

Can you specify which version fixes this issue.

@ggjjj
Copy link
Contributor

ggjjj commented Nov 20, 2024

https://github.com/Azure/iotedge/releases/tag/1.5.15 current latest

@PAKalucki
Copy link
Author

Can you explain how does this version fix this issue? I don't see anything in changelog that would indicate that.

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

@ggjjj ggjjj

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@PAKalucki @ggjjj