Azure / Azure/iotedge

aziot-edged is overwhelming IoT Hub with identity operations

Open
#7,395 6 comments 0 reactions 1 assignee Claimed by @ggjjj View on GitHub
Dominant language
C#
Stars
1.5k
Forks
473
Avg merge
2d 17h
Merged PRs (30d)
7

Description

## 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](https://github.com/user-attachments/assets/45b8748c-85fa-4adf-8b03-ff19666bb2a4)
During investigation we found out that IoT Hub is being bombarded with identity get operations
![Image](https://github.com/user-attachments/assets/38edb98b-0623-48c6-b809-f94e8416ac8f)

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

```

```

edge-hub logs

```

2024-11-19 13:56:00 +00:00 Starting Edge Hub
Nov 19 13:56:00.115  INFO watchdog: Starting Watchdog
Nov 19 13:56:00.116  INFO watchdog: Registering shutdown signal listener
Nov 19 13:56:00.124  INFO watchdog: MQTT broker is disabled
Nov 19 13:56:00.131  INFO 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.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.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.<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.<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.<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.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.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.<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.<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.<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.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.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.<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.<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.<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

```

Contributor guide

No contributing guide indexed for this repository

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.