Azure / iotedge

The IoT Edge OSS project
MIT License
1.46k stars 459 forks source link

Setting AuthenticationMode to Cloud fails on mcr.microsoft.com/azureiotedge-hub:1.2 #6284

Open ksaye opened 2 years ago

ksaye commented 2 years ago

Expected Behavior

When using the URI mcr.microsoft.com/azureiotedge-hub:1.1, I can set the AuthenticationMode to Cloud with no issue.

When I use mcr.microsoft.com/azureiotedge-hub:1.2, I get the error:

System.InvalidOperationException: Could not obtain twin neither from local store nor from cloud. This happens when there is no upstream connection and this is the first EdgeHub startup, or there is no persistent store to save a previous twin configuration. EdgeHub cannot start without basic configuration stored in twin. Stopping now.

Current Behavior

When I use mcr.microsoft.com/azureiotedge-hub:1.2, I get the error:

System.InvalidOperationException: Could not obtain twin neither from local store nor from cloud. This happens when there is no upstream connection and this is the first EdgeHub startup, or there is no persistent store to save a previous twin configuration. EdgeHub cannot start without basic configuration stored in twin. Stopping now.

Steps to Reproduce

Provide a detailed set of steps to reproduce the bug.

  1. Deploy IoT Edge 1.2 using the URI mcr.microsoft.com/azureiotedge-hub:1.1
  2. On EdgeHub set the environment variable AuthenticationMode to Cloud
  3. Note it behaves as expected
  4. Change the URI of edgeHub to mcr.microsoft.com/azureiotedge-hub:1.2 and watch it fail

Context (Environment)

Output of iotedge check

Click here ``` iotedge check 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 - Error identityd config has hostname edgehubha.saye.org but device reports hostname host2. Hostname in identityd config must either be identical to the device hostname or be a fully-qualified domain name that has the device hostname as the first component. √ aziot-identity-service package is up-to-date - OK √ host time is close to reference time - OK √ preloaded certificates are valid - OK √ keyd is running - OK √ certd is running - OK √ identityd is running - OK √ read all preloaded certificates from the Certificates Service - OK √ read all preloaded key pairs from the Keys Service - OK √ ensure all preloaded certificates match preloaded private keys with the same ID - OK Connectivity checks (aziot-identity-service) -------------------------------------------- √ host can connect to and perform TLS handshake with iothub AMQP port - OK √ host can connect to and perform TLS handshake with iothub HTTPS / WebSockets port - OK √ host can connect to and perform TLS handshake with iothub MQTT port - OK Configuration checks -------------------- √ aziot-edged configuration is well-formed - OK √ configuration up-to-date with config.toml - OK √ container engine is installed and functional - OK √ configuration has correct URIs for daemon mgmt endpoint - OK √ aziot-edge package is up-to-date - OK √ container time is close to host time - OK ‼ DNS server - Warning Container engine is not configured with DNS server setting, which may impact connectivity to IoT Hub. Please see https://aka.ms/iotedge-prod-checklist-dns for best practices. You can ignore this warning if you are setting DNS server per module in the Edge deployment. ‼ production readiness: logs policy - Warning Container engine is not configured to rotate module logs which may cause it run out of disk space. Please see https://aka.ms/iotedge-prod-checklist-logs for best practices. You can ignore this warning if you are setting log policy per module in the Edge deployment. ‼ production readiness: Edge Agent's storage directory is persisted on the host filesystem - Warning The edgeAgent module is not configured to persist its /tmp/edgeAgent directory on the host filesystem. Data might be lost if the module is deleted or updated. Please see https://aka.ms/iotedge-storage-host for best practices. ‼ production readiness: Edge Hub's storage directory is persisted on the host filesystem - Warning The edgeHub module is not configured to persist its /tmp/edgeHub directory on the host filesystem. Data might be lost if the module is deleted or updated. Please see https://aka.ms/iotedge-storage-host for best practices. √ Agent image is valid and can be pulled from upstream - OK √ proxy settings are consistent in aziot-edged, aziot-identityd, moby daemon and config.toml - OK Connectivity checks ------------------- √ container on the default network can connect to upstream AMQP port - OK √ container on the default network can connect to upstream HTTPS / WebSockets port - OK √ container on the default network can connect to upstream MQTT port - OK √ container on the IoT Edge module network can connect to upstream AMQP port - OK √ container on the IoT Edge module network can connect to upstream HTTPS / WebSockets port - OK √ container on the IoT Edge module network can connect to upstream MQTT port - OK 31 check(s) succeeded. 4 check(s) raised warnings. Re-run with --verbose for more details. 1 check(s) raised errors. Re-run with --verbose for more details. ```

Device Information

Runtime Versions

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

Logs

aziot-edged logs ``` ```
edge-agent logs ``` ```
edge-hub logs ``` root@host1:~# docker logs -f edgeHub 2022-04-12 21:21:59 Starting Edge Hub Apr 12 21:21:59.332 INFO watchdog: Starting Watchdog Apr 12 21:21:59.332 INFO watchdog: Registering shutdown signal listener Apr 12 21:21:59.332 INFO watchdog: MQTT broker is disabled Apr 12 21:21:59.339 INFO watchdog::child: Launched Edge Hub process with pid 9 2022-04-12 21:21:59.402 +00:00 Edge Hub Main() <6> 2022-04-12 21:22:00.168 +00:00 [INF] - Installing certificates [CN=IoT Edge Root CA Host1:10/09/2022 17:22:39],[CN=Issuing CA for IoT Edge:10/09/2022 17:22:39],[CN=Root CA for IoT Edge:04/09/2032 17:22:38] to Root <6> 2022-04-12 21:22:00.215 +00:00 [INF] - Installing certificates [CN=IoT Edge Root CA Host1:10/09/2022 17:22:39],[CN=Issuing CA for IoT Edge:10/09/2022 17:22:39],[CN=Root CA for IoT Edge:04/09/2032 17:22:38] to Root <6> 2022-04-12 21:22:00.227 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12 <6> 2022-04-12 21:22:00.343 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableMqttBroker":false} <6> 2022-04-12 21:22:00.460 +00:00 [INF] - Initializing Edge Hub <6> 2022-04-12 21:22:00.460 +00:00 [INF] - █████╗ ███████╗██╗ ██╗██████╗ ███████╗ ██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝ ███████║ ███╔╝ ██║ ██║██████╔╝█████╗ ██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝ ██║ ██║███████╗╚██████╔╝██║ ██║███████╗ ╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝ ██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗ ██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝ ██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗ ██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝ ██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗ ╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝ <6> 2022-04-12 21:22:00.462 +00:00 [INF] - Version - 1.2.9.53764592 (4bbfdb99cf7afb16f23d6177865942cc22e197ce) <6> 2022-04-12 21:22:00.462 +00:00 [INF] - OptimizeForPerformance=True <6> 2022-04-12 21:22:00.462 +00:00 [INF] - MessageAckTimeoutSecs=30 <6> 2022-04-12 21:22:00.464 +00:00 [INF] - Loaded server certificate with expiration date of "2022-05-12T21:22:00.0000000+00:00" <6> 2022-04-12 21:22:00.470 +00:00 [INF] - Using Asp Net server for metrics <6> 2022-04-12 21:22:01.610 +00:00 [INF] - Created persistent store at /tmp/edgeHub <6> 2022-04-12 21:22:01.642 +00:00 [INF] - Started task to cleanup processed and stale messages <6> 2022-04-12 21:22:01.647 +00:00 [INF] - Created new message store <6> 2022-04-12 21:22:01.699 +00:00 [INF] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00 <6> 2022-04-12 21:22:02.046 +00:00 [INF] - Initialized storing twin manager <6> 2022-04-12 21:22:02.065 +00:00 [INF] - Add node: host1/$edgeHub <6> 2022-04-12 21:22:02.066 +00:00 [INF] - Initializing configuration <6> 2022-04-12 21:22:02.090 +00:00 [INF] - New device connection for device host1/$edgeHub <6> 2022-04-12 21:22:02.100 +00:00 [INF] - Client host1/$edgeHub connected to edgeHub, processing existing subscriptions. <4> 2022-04-12 21:22:02.115 +00:00 [WRN] - Error creating cloud connection for client host1/$edgeHub System.InvalidOperationException: No auth chain for the client identity: host1/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-04-12 21:22:02.133 +00:00 [INF] - Error getting cloud connection for device host1/$edgeHub System.InvalidOperationException: No auth chain for the client identity: host1/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-04-12 21:22:02.148 +00:00 [INF] - Processing pending subscriptions for host1/$edgeHub <4> 2022-04-12 21:22:02.149 +00:00 [WRN] - Error creating cloud connection for client host1/$edgeHub System.InvalidOperationException: No auth chain for the client identity: host1/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-04-12 21:22:02.151 +00:00 [INF] - Error getting cloud connection for device host1/$edgeHub System.InvalidOperationException: No auth chain for the client identity: host1/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-04-12 21:22:02.153 +00:00 [INF] - Processing pending subscriptions for host1/$edgeHub, but no cloud proxy was found <6> 2022-04-12 21:22:02.216 +00:00 [INF] - Processing pending subscriptions for host1/$edgeHub <6> 2022-04-12 21:22:02.458 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableMqttBroker":false} <4> 2022-04-12 21:22:02.519 +00:00 [WRN] - Empty edge hub configuration received. Ignoring... <4> 2022-04-12 21:22:02.524 +00:00 [WRN] - Error creating cloud connection for client host1/$edgeHub System.InvalidOperationException: No auth chain for the client identity: host1/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-04-12 21:22:02.525 +00:00 [INF] - Error getting cloud connection for device host1/$edgeHub System.InvalidOperationException: No auth chain for the client identity: host1/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-04-12 21:22:02.765 +00:00 [INF] - Scheduling server certificate renewal for "2022-05-12T21:19:30.0000782Z". <3> 2022-04-12 21:22:02.777 +00:00 [ERR] - Error getting edge hub config from twin desired properties Microsoft.Azure.Devices.Edge.Util.InvalidSchemaVersionException: EdgeHub config missing SchemaVersion at Microsoft.Azure.Devices.Edge.Hub.Core.Config.EdgeHubConfigParser.GetEdgeHubConfig(String twinJson) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/EdgeHubConfigParser.cs:line 83 at Microsoft.Azure.Devices.Edge.Hub.Core.Config.TwinConfigSource.GetConfigInternal() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/TwinConfigSource.cs:line 102 at Microsoft.Azure.Devices.Edge.Hub.Core.Config.TwinConfigSource.GetConfigInternal() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/TwinConfigSource.cs:line 109 <4> 2022-04-12 21:22:02.779 +00:00 [WRN] - Empty edge hub configuration received. Ignoring... <3> 2022-04-12 21:22:02.780 +00:00 [ERR] - Error initializing edge hub configuration System.InvalidOperationException: Could not obtain twin neither from local store nor from cloud. This happens when there is no upstream connection and this is the first EdgeHub startup, or there is no persistent store to save a previous twin configuration. EdgeHub cannot start without basic configuration stored in twin. Stopping now. at Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater.<>c.b__9_6() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/ConfigUpdater.cs:line 67 at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater.<>c__DisplayClass9_0.<b__4>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/ConfigUpdater.cs:line 73 --- End of stack trace from previous location where exception was thrown --- at Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater.Init(IConfigSource configProvider) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/ConfigUpdater.cs:line 56 <3> 2022-04-12 21:22:02.781 +00:00 [ERR] - Error starting protocol heads: Could not obtain twin neither from local store nor from cloud. This happens when there is no upstream connection and this is the first EdgeHub startup, or there is no persistent store to save a previous twin configuration. EdgeHub cannot start without basic configuration stored in twin. Stopping now. <6> 2022-04-12 21:22:02.781 +00:00 [INF] - Stopping the protocol heads... <6> 2022-04-12 21:22:02.782 +00:00 [INF] - Closing protocol heads - (MQTT, AMQP, HTTP) <6> 2022-04-12 21:22:02.784 +00:00 [INF] - Stopping MQTT protocol head <6> 2022-04-12 21:22:02.785 +00:00 [INF] - Stopped MQTT protocol head <6> 2022-04-12 21:22:02.789 +00:00 [INF] - Closing HTTP head <6> 2022-04-12 21:22:02.790 +00:00 [INF] - Closed HTTP head <6> 2022-04-12 21:22:02.790 +00:00 [INF] - Protocol heads stopped. <6> 2022-04-12 21:22:02.799 +00:00 [INF] - Shutdown complete. <6> 2022-04-12 21:22:02.800 +00:00 [INF] - Termination requested, initiating shutdown. <6> 2022-04-12 21:22:02.800 +00:00 [INF] - Waiting for cleanup to finish <6> 2022-04-12 21:22:02.800 +00:00 [INF] - Done with cleanup. Shutting down. Apr 12 21:22:03.340 INFO watchdog::child: Edge Hub process has stopped Apr 12 21:22:03.340 INFO watchdog: Successfully stopped Edge Hub process Apr 12 21:22:03.340 INFO watchdog: Stopped Watchdog process ```

Additional Information

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

nyanzebra commented 2 years ago

Hi @ksaye, I am going to try to replicate the situation to investigate this, but to confirm you AuthenticationMode to the value CloudAndScope? Or to Cloud? And if you go back to 1.1 does everything work again? Thanks

varunpuranik commented 2 years ago

Hi @ksaye - looks like this might be a bug in our authentication code. Meanwhile, is this a nested scenario? If not, can you try to turn off Nested Edge and try? For that, please set the env var NestedEdgeEnabled=false in EdgeHub module.

ksaye commented 2 years ago

Sorry for the late response @nyanzebra, I am setting AuthenticationMode to Cloud and it does work with 1.1 but not with 1.2.

@varunpuranik, thanks for the confirmation. Yes it is a Nested Edge + Leaf Devices, so the preference would be AuthenticationMode = Cloud on 1.2. The real goal/desire here was to enable the AuthenticationMode=Cloud FOR Nested Edge so we can have child Edge devices failover from parent 1 to parent 2 without making changes in the cloud. Happy to follow the status of this bug and retest.

jlian commented 2 years ago

@veyalla is there a VM-based failover system that doesn't require AuthenticationMode = Cloud? Vaguely remember you mentioning it?

jlian commented 2 years ago

@varunpuranik please post your thoughts on cloud authentication mode here for posterity

veyalla commented 2 years ago

@veyalla is there a VM-based failover system that doesn't require AuthenticationMode = Cloud? Vaguely remember you mentioning it?

The VM hostname and IP addresses don't change with a VM failover based solution. So it doesn't require Cloud AuthenticationMode. Note, while the failover is automatic, there is will be some downtime while the failure is detected by the underlying Server Virtualization platform and failover is completed.

github-actions[bot] commented 2 years ago

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

ksaye commented 2 years ago

Open to PM guidance here, I just know that if you use AuthenticationMode = Cloud and change the URL to mcr.microsoft.com/azureiotedge-hub:1.2, it will fail today.

jlian commented 2 years ago

We did update our docs a little to include issues with Cloud auth

https://github.com/Azure/iotedge/blob/main/doc/EnvironmentVariables.md#cloud-authenticationmode-not-supported-in-production

But Cloud auth not working at all seems unintended - @varunpuranik ?

varunpuranik commented 2 years ago

Yes, this seems like a bug in our code. I mentioned that in my previous comment - https://github.com/Azure/iotedge/issues/6284#issuecomment-1099695909

ksaye commented 2 years ago

Thanks all. Happy to close this comment but want customer to avoid this issue. I have some that use the AuthenticationMode = Cloud.

@jlian, Love the document https://github.com/Azure/iotedge/blob/main/doc/EnvironmentVariables.md#cloud-authenticationmode-not-supported-in-production, and perhaps it is acceptable to just modify that document for now.

ksaye commented 2 years ago

Hi @ksaye - looks like this might be a bug in our authentication code. Meanwhile, is this a nested scenario? If not, can you try to turn off Nested Edge and try? For that, please set the env var NestedEdgeEnabled=false in EdgeHub module.

Let me try that, sorry did not notice the request.

ksaye commented 2 years ago

I just tested on EdgeHub 1.2.4.

With AuthenticationMode:Cloud edgeHub crashes. With AuthenticationMode:Cloud and NestedEdgeEnabled:False API Proxy keeps getting 'invalid sas token'.

EdgeHub Crashes Error EdgeHub with AuthenticationMode = Cloud ``` Jun 08 21:08:29.357 INFO watchdog: Starting Watchdog Jun 08 21:08:29.357 INFO watchdog: Registering shutdown signal listener Jun 08 21:08:29.357 INFO watchdog: MQTT broker is disabled Jun 08 21:08:29.359 INFO watchdog::child: Launched Edge Hub process with pid 9 2022-06-08 21:08:29.417 +00:00 Edge Hub Main() <6> 2022-06-08 21:08:30.129 +00:00 [INF] - Installing certificates [CN=L5CA:05/13/2024 20:12:25] to Root <6> 2022-06-08 21:08:30.156 +00:00 [INF] - Installing certificates [CN=L5CA:05/13/2024 20:12:25],[CN=RootCA:05/21/2032 20:12:25],[CN=L5CA:05/13/2024 20:12:25] to Root <6> 2022-06-08 21:08:30.168 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12 <6> 2022-06-08 21:08:30.276 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableMqttBroker":false} <6> 2022-06-08 21:08:30.388 +00:00 [INF] - Initializing Edge Hub <6> 2022-06-08 21:08:30.388 +00:00 [INF] - █████╗ ███████╗██╗ ██╗██████╗ ███████╗ ██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝ ███████║ ███╔╝ ██║ ██║██████╔╝█████╗ ██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝ ██║ ██║███████╗╚██████╔╝██║ ██║███████╗ ╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝ ██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗ ██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝ ██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗ ██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝ ██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗ ╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝ <6> 2022-06-08 21:08:30.391 +00:00 [INF] - Version - 1.2.4.47309863 (d23e0cafc3a1e4b9741b99cba8077a6df3f015c6) <6> 2022-06-08 21:08:30.391 +00:00 [INF] - OptimizeForPerformance=True <6> 2022-06-08 21:08:30.391 +00:00 [INF] - MessageAckTimeoutSecs=30 <6> 2022-06-08 21:08:30.394 +00:00 [INF] - Loaded server certificate with expiration date of "2022-07-08T21:08:29.0000000+00:00" <6> 2022-06-08 21:08:30.400 +00:00 [INF] - Using Asp Net server for metrics <6> 2022-06-08 21:08:31.183 +00:00 [INF] - Created persistent store at /tmp/edgeHub <6> 2022-06-08 21:08:31.215 +00:00 [INF] - Started task to cleanup processed and stale messages <6> 2022-06-08 21:08:31.220 +00:00 [INF] - Created new message store <6> 2022-06-08 21:08:31.273 +00:00 [INF] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00 <6> 2022-06-08 21:08:31.476 +00:00 [INF] - Initialized storing twin manager <6> 2022-06-08 21:08:31.490 +00:00 [INF] - Add node: L5/$edgeHub <6> 2022-06-08 21:08:31.491 +00:00 [INF] - Initializing configuration <6> 2022-06-08 21:08:31.502 +00:00 [INF] - New device connection for device L5/$edgeHub <6> 2022-06-08 21:08:31.510 +00:00 [INF] - Client L5/$edgeHub connected to edgeHub, processing existing subscriptions. <4> 2022-06-08 21:08:31.524 +00:00 [WRN] - Error creating cloud connection for client L5/$edgeHub System.InvalidOperationException: No auth chain for the client identity: L5/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-06-08 21:08:31.542 +00:00 [INF] - Error getting cloud connection for device L5/$edgeHub System.InvalidOperationException: No auth chain for the client identity: L5/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-06-08 21:08:31.557 +00:00 [INF] - Processing pending subscriptions for L5/$edgeHub <4> 2022-06-08 21:08:31.563 +00:00 [WRN] - Error creating cloud connection for client L5/$edgeHub System.InvalidOperationException: No auth chain for the client identity: L5/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-06-08 21:08:31.564 +00:00 [INF] - Error getting cloud connection for device L5/$edgeHub System.InvalidOperationException: No auth chain for the client identity: L5/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-06-08 21:08:31.565 +00:00 [INF] - Processing pending subscriptions for L5/$edgeHub, but no cloud proxy was found <6> 2022-06-08 21:08:31.580 +00:00 [INF] - Processing pending subscriptions for L5/$edgeHub <6> 2022-06-08 21:08:31.769 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableMqttBroker":false} <4> 2022-06-08 21:08:31.811 +00:00 [WRN] - Empty edge hub configuration received. Ignoring... <4> 2022-06-08 21:08:31.824 +00:00 [WRN] - Error creating cloud connection for client L5/$edgeHub System.InvalidOperationException: No auth chain for the client identity: L5/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-06-08 21:08:31.824 +00:00 [INF] - Error getting cloud connection for device L5/$edgeHub System.InvalidOperationException: No auth chain for the client identity: L5/$edgeHub at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.ConnectInternal(IIdentity identity, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 183 <6> 2022-06-08 21:08:31.938 +00:00 [INF] - Scheduling server certificate renewal for "2022-07-08T21:05:59.0000821Z". <3> 2022-06-08 21:08:31.967 +00:00 [ERR] - Error getting edge hub config from twin desired properties Microsoft.Azure.Devices.Edge.Util.InvalidSchemaVersionException: EdgeHub config missing SchemaVersion at Microsoft.Azure.Devices.Edge.Hub.Core.Config.EdgeHubConfigParser.GetEdgeHubConfig(String twinJson) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/EdgeHubConfigParser.cs:line 83 at Microsoft.Azure.Devices.Edge.Hub.Core.Config.TwinConfigSource.GetConfigInternal() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/TwinConfigSource.cs:line 102 at Microsoft.Azure.Devices.Edge.Hub.Core.Config.TwinConfigSource.GetConfigInternal() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/TwinConfigSource.cs:line 109 <4> 2022-06-08 21:08:31.968 +00:00 [WRN] - Empty edge hub configuration received. Ignoring... <3> 2022-06-08 21:08:31.969 +00:00 [ERR] - Error initializing edge hub configuration System.InvalidOperationException: Could not obtain twin neither from local store nor from cloud. This happens when there is no upstream connection and this is the first EdgeHub startup, or there is no persistent store to save a previous twin configuration. EdgeHub cannot start without basic configuration stored in twin. Stopping now. at Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater.<>c.b__9_6() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/ConfigUpdater.cs:line 67 at Microsoft.Azure.Devices.Edge.Util.Option`1.Expect[TException](Func`1 exception) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/Option.cs:line 117 at Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater.<>c__DisplayClass9_0.<b__4>d.MoveNext() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/ConfigUpdater.cs:line 73 --- End of stack trace from previous location where exception was thrown --- at Microsoft.Azure.Devices.Edge.Hub.Core.Config.ConfigUpdater.Init(IConfigSource configProvider) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/config/ConfigUpdater.cs:line 56 <3> 2022-06-08 21:08:31.971 +00:00 [ERR] - Error starting protocol heads: Could not obtain twin neither from local store nor from cloud. This happens when there is no upstream connection and this is the first EdgeHub startup, or there is no persistent store to save a previous twin configuration. EdgeHub cannot start without basic configuration stored in twin. Stopping now. <6> 2022-06-08 21:08:31.971 +00:00 [INF] - Stopping the protocol heads... <6> 2022-06-08 21:08:31.972 +00:00 [INF] - Closing protocol heads - (MQTT, AMQP, HTTP) <6> 2022-06-08 21:08:31.975 +00:00 [INF] - Stopping <6> 2022-06-08 21:08:31.975 +00:00 [INF] - Stopped <6> 2022-06-08 21:08:31.980 +00:00 [INF] - Closing HTTP head <6> 2022-06-08 21:08:31.981 +00:00 [INF] - Closed HTTP head <6> 2022-06-08 21:08:31.981 +00:00 [INF] - Protocol heads stopped. <6> 2022-06-08 21:08:31.985 +00:00 [INF] - Stopping <6> 2022-06-08 21:08:31.985 +00:00 [INF] - Stopped <6> 2022-06-08 21:08:31.993 +00:00 [INF] - Shutdown complete. <6> 2022-06-08 21:08:31.994 +00:00 [INF] - Termination requested, initiating shutdown. <6> 2022-06-08 21:08:31.994 +00:00 [INF] - Waiting for cleanup to finish <6> 2022-06-08 21:08:31.994 +00:00 [INF] - Done with cleanup. Shutting down. Jun 08 21:08:32.363 INFO watchdog::child: Edge Hub process has stopped Jun 08 21:08:32.363 INFO watchdog: Successfully stopped Edge Hub process Jun 08 21:08:32.363 INFO watchdog: Stopped Watchdog process ```
APIProxy failes to connect Error EdgeHub with AuthenticationMode = Cloud and NestedEdgeEnabled = False ```
2022-06-08 21:11:50 Starting Edge Hub Jun 08 21:11:50.620 INFO watchdog: Starting Watchdog Jun 08 21:11:50.620 INFO watchdog: Registering shutdown signal listener Jun 08 21:11:50.620 INFO watchdog: MQTT broker is disabled Jun 08 21:11:50.623 INFO watchdog::child: Launched Edge Hub process with pid 9 2022-06-08 21:11:50.681 +00:00 Edge Hub Main() <6> 2022-06-08 21:11:52.231 +00:00 [INF] - Installing certificates [CN=L5CA:05/13/2024 20:12:25] to Root <6> 2022-06-08 21:11:52.289 +00:00 [INF] - Installing certificates [CN=L5CA:05/13/2024 20:12:25],[CN=RootCA:05/21/2032 20:12:25],[CN=L5CA:05/13/2024 20:12:25] to Root <6> 2022-06-08 21:11:52.307 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12 <6> 2022-06-08 21:11:52.537 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableMqttBroker":false} <6> 2022-06-08 21:11:52.808 +00:00 [INF] - Initializing Edge Hub <6> 2022-06-08 21:11:52.809 +00:00 [INF] - █████╗ ███████╗██╗ ██╗██████╗ ███████╗ ██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝ ███████║ ███╔╝ ██║ ██║██████╔╝█████╗ ██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝ ██║ ██║███████╗╚██████╔╝██║ ██║███████╗ ╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝ ██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗ ██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝ ██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗ ██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝ ██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗ ╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝ <6> 2022-06-08 21:11:52.813 +00:00 [INF] - Version - 1.2.4.47309863 (d23e0cafc3a1e4b9741b99cba8077a6df3f015c6) <6> 2022-06-08 21:11:52.814 +00:00 [INF] - OptimizeForPerformance=True <6> 2022-06-08 21:11:52.814 +00:00 [INF] - MessageAckTimeoutSecs=30 <6> 2022-06-08 21:11:52.818 +00:00 [INF] - Loaded server certificate with expiration date of "2022-07-08T21:11:51.0000000+00:00" <6> 2022-06-08 21:11:52.831 +00:00 [INF] - Using Asp Net server for metrics <6> 2022-06-08 21:11:53.851 +00:00 [INF] - Created persistent store at /tmp/edgeHub <6> 2022-06-08 21:11:53.921 +00:00 [INF] - Started task to cleanup processed and stale messages <6> 2022-06-08 21:11:53.932 +00:00 [INF] - Created new message store <6> 2022-06-08 21:11:54.047 +00:00 [INF] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00 <6> 2022-06-08 21:11:54.286 +00:00 [INF] - Initialized storing twin manager <6> 2022-06-08 21:11:54.298 +00:00 [INF] - Initializing configuration <6> 2022-06-08 21:11:54.319 +00:00 [INF] - New device connection for device L5/$edgeHub <6> 2022-06-08 21:11:54.337 +00:00 [INF] - Client L5/$edgeHub connected to edgeHub, processing existing subscriptions. <6> 2022-06-08 21:11:54.387 +00:00 [INF] - Attempting to connect to IoT Hub for client L5/$edgeHub via AMQP... <6> 2022-06-08 21:11:54.614 +00:00 [INF] - Processing pending subscriptions for L5/$edgeHub <6> 2022-06-08 21:11:55.358 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableMqttBroker":false} <4> 2022-06-08 21:11:55.573 +00:00 [WRN] - Empty edge hub configuration received. Ignoring... <6> 2022-06-08 21:11:55.625 +00:00 [INF] - Scheduling server certificate renewal for "2022-07-08T21:09:21.0000767Z". <6> 2022-06-08 21:11:56.167 +00:00 [INF] - Exiting disconnected state <6> 2022-06-08 21:11:56.192 +00:00 [INF] - Device connected to cloud, processing subscriptions for connected clients. <6> 2022-06-08 21:11:56.195 +00:00 [INF] - Processing subscriptions for client L5/$edgeHub on device connected to cloud. <6> 2022-06-08 21:11:56.197 +00:00 [INF] - Skipping L5/$edgeHub for subscription processing, as it is currently being processed. <6> 2022-06-08 21:11:56.202 +00:00 [INF] - Received device connected callback <6> 2022-06-08 21:11:56.245 +00:00 [INF] - Entering connected state <6> 2022-06-08 21:11:56.252 +00:00 [INF] - Cloud connection for L5/$edgeHub is True <6> 2022-06-08 21:11:56.254 +00:00 [INF] - Connection status for L5/$edgeHub changed to ConnectionEstablished <6> 2022-06-08 21:11:56.259 +00:00 [INF] - Client L5/$edgeHub connected to cloud, processing existing subscriptions. <6> 2022-06-08 21:11:56.259 +00:00 [INF] - Skipping L5/$edgeHub for subscription processing, as it is currently being processed. <6> 2022-06-08 21:11:56.261 +00:00 [INF] - Created cloud proxy for client L5/$edgeHub via AMQP, with client operation timeout 20 seconds. <6> 2022-06-08 21:11:56.266 +00:00 [INF] - Initialized cloud proxy 8d9c0e4b-03cc-476f-896d-dae67c918b48 for L5/$edgeHub <6> 2022-06-08 21:11:56.271 +00:00 [INF] - Created cloud connection for client L5/$edgeHub <6> 2022-06-08 21:11:56.666 +00:00 [INF] - Processing pending subscriptions for L5/$edgeHub <6> 2022-06-08 21:11:56.706 +00:00 [INF] - Updated reported properties for L5/$edgeHub <6> 2022-06-08 21:11:57.075 +00:00 [INF] - Created cloud endpoint iothub with max batch size 10 and fan-out factor of 10. <6> 2022-06-08 21:11:57.220 +00:00 [INF] - Obtained edge hub config from module twin <6> 2022-06-08 21:11:57.478 +00:00 [INF] - Set the following 1 route(s) in edge hub <6> 2022-06-08 21:11:57.479 +00:00 [INF] - route: FROM /messages/* INTO $upstream <6> 2022-06-08 21:11:57.480 +00:00 [INF] - Updated message store TTL to 7200 seconds <6> 2022-06-08 21:11:57.482 +00:00 [INF] - Updated the edge hub store and forward configuration <6> 2022-06-08 21:11:57.493 +00:00 [INF] - Started operation Get EdgeHub config <6> 2022-06-08 21:11:57.494 +00:00 [INF] - Initialized edge hub configuration <6> 2022-06-08 21:11:57.496 +00:00 [INF] - Starting protocol heads - (MQTT, AMQP, HTTP) <6> 2022-06-08 21:11:57.499 +00:00 [INF] - Starting MQTT head <6> 2022-06-08 21:11:57.546 +00:00 [INF] - Initializing TLS endpoint on port 8883 for MQTT head. <6> 2022-06-08 21:11:57.646 +00:00 [INF] - Starting AMQP head <6> 2022-06-08 21:11:57.652 +00:00 [INF] - Started MQTT head <6> 2022-06-08 21:11:57.727 +00:00 [INF] - Started AMQP head <6> 2022-06-08 21:11:57.734 +00:00 [INF] - Starting HTTP head <4> 2022-06-08 21:11:57.997 +00:00 [WRN] - Overriding address(es) '"http://+:80"'. Binding to endpoints defined in "UseKestrel()" instead. <6> 2022-06-08 21:11:58.002 +00:00 [INF] - Started HTTP head <6> 2022-06-08 21:11:58.007 +00:00 [INF] - Attempting to connect to IoT Hub for client L5/AzureBlobStorageonIoTEdge via AMQP... <6> 2022-06-08 21:11:58.067 +00:00 [INF] - New token requested by client L5/AzureBlobStorageonIoTEdge, but using existing token as it is usable. <6> 2022-06-08 21:11:58.167 +00:00 [INF] - Cloud connection for L5/AzureBlobStorageonIoTEdge is True <6> 2022-06-08 21:11:58.168 +00:00 [INF] - Connection status for L5/AzureBlobStorageonIoTEdge changed to ConnectionEstablished <6> 2022-06-08 21:11:58.169 +00:00 [INF] - Client L5/AzureBlobStorageonIoTEdge connected to cloud, processing existing subscriptions. <6> 2022-06-08 21:11:58.175 +00:00 [INF] - Created cloud proxy for client L5/AzureBlobStorageonIoTEdge via AMQP, with client operation timeout 20 seconds. <6> 2022-06-08 21:11:58.176 +00:00 [INF] - Initialized cloud proxy 99e9bde9-dcd5-49ed-8a4b-5a3919f3e754 for L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.178 +00:00 [INF] - Created cloud connection for client L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.185 +00:00 [INF] - New cloud connection created for device L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.188 +00:00 [INF] - Authenticated L5/AzureBlobStorageonIoTEdge with IotHub <6> 2022-06-08 21:11:58.199 +00:00 [INF] - Successfully generated identity for clientId L5/AzureBlobStorageonIoTEdge and username l5.saye.org/L5/AzureBlobStorageonIoTEdge/?api-version=2018-06-30&DeviceClientType=.NET%2F1.20.3%20%28.NET%20Core%203.1.21%3B%20Linux%204.15.0-180-generic%20%23189-Ubuntu%20SMP%20Wed%20May%2018%2014%3A13%3A57%20UTC%202022%3B%20X64%29%20iot-edge-blob-storage%2F1.4.1.0%20%28UploadOff%29 <6> 2022-06-08 21:11:58.206 +00:00 [INF] - ClientAuthenticated, L5/AzureBlobStorageonIoTEdge, 4e3b33d3 <6> 2022-06-08 21:11:58.225 +00:00 [INF] - New device connection for device L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.226 +00:00 [INF] - Client L5/AzureBlobStorageonIoTEdge connected to edgeHub, processing existing subscriptions. <6> 2022-06-08 21:11:58.226 +00:00 [INF] - Skipping L5/AzureBlobStorageonIoTEdge for subscription processing, as it is currently being processed. <6> 2022-06-08 21:11:58.247 +00:00 [INF] - Bind device proxy for device L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.247 +00:00 [INF] - Binding message channel for device Id L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.274 +00:00 [INF] - Processing subscriptions TwinResponse for client L5/AzureBlobStorageonIoTEdge. <6> 2022-06-08 21:11:58.276 +00:00 [INF] - Processing pending subscriptions for L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.288 +00:00 [INF] - Set subscriptions from session state for L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.292 +00:00 [INF] - Processing subscriptions TwinResponse, DesiredPropertyUpdates for client L5/AzureBlobStorageonIoTEdge. <6> 2022-06-08 21:11:58.294 +00:00 [INF] - Processing pending subscriptions for L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:58.295 +00:00 [INF] - Set subscriptions from session state for L5/AzureBlobStorageonIoTEdge <6> 2022-06-08 21:11:59.501 +00:00 [INF] - Updated reported properties for L5/$edgeHub <6> 2022-06-08 21:12:00.878 +00:00 [INF] - Attempting to connect to IoT Hub for client L5/IoTEdgeAPIProxy via AMQP... <6> 2022-06-08 21:12:00.925 +00:00 [INF] - New token requested by client L5/IoTEdgeAPIProxy, but using existing token as it is usable. <4> 2022-06-08 21:12:01.011 +00:00 [WRN] - Error creating cloud connection for client L5/IoTEdgeAPIProxy Microsoft.Azure.Devices.Client.Exceptions.UnauthorizedException: error(condition:amqp:unauthorized-access,description:Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key..) ---> Microsoft.Azure.Amqp.AmqpException: Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key.. 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) --- End of inner exception stack trace --- 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) 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() at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 143 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 55 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 186 --- 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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /home/vsts/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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 132 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 107 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ClientTokenCloudConnection.Create(ITokenCredentials tokenCredentials, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, String productInfo, Option`1 modelId) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ClientTokenCloudConnection.cs:line 85 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.Connect(IClientCredentials clientCredentials, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 137 <6> 2022-06-08 21:12:01.031 +00:00 [INF] - Error creating new device connection for device L5/IoTEdgeAPIProxy Microsoft.Azure.Devices.Client.Exceptions.UnauthorizedException: error(condition:amqp:unauthorized-access,description:Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key..) ---> Microsoft.Azure.Amqp.AmqpException: Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key.. 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) --- End of inner exception stack trace --- 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) 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() at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 143 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 55 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 186 --- 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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /home/vsts/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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 132 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 107 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ClientTokenCloudConnection.Create(ITokenCredentials tokenCredentials, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, String productInfo, Option`1 modelId) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ClientTokenCloudConnection.cs:line 85 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.Connect(IClientCredentials clientCredentials, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 137 <4> 2022-06-08 21:12:01.034 +00:00 [WRN] - Error validating token for L5/IoTEdgeAPIProxy with IoTHub Microsoft.Azure.Devices.Client.Exceptions.UnauthorizedException: error(condition:amqp:unauthorized-access,description:Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key..) ---> Microsoft.Azure.Amqp.AmqpException: Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key.. 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) --- End of inner exception stack trace --- 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) 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() at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 143 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 55 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 186 --- 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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /home/vsts/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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 132 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 107 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ClientTokenCloudConnection.Create(ITokenCredentials tokenCredentials, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, String productInfo, Option`1 modelId) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ClientTokenCloudConnection.cs:line 85 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.Connect(IClientCredentials clientCredentials, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 137 <3> 2022-06-08 21:12:01.038 +00:00 [ERR] - Unable to generate identity for clientId L5/IoTEdgeAPIProxy and username l5.saye.org/L5/IoTEdgeAPIProxy/?api-version=2018-06-30 <6> 2022-06-08 21:12:01.039 +00:00 [INF] - ClientNotAuthenticated, Client ID: L5/IoTEdgeAPIProxy; Username: l5.saye.org/L5/IoTEdgeAPIProxy/?api-version=2018-06-30, 0a81a58d <6> 2022-06-08 21:12:06.914 +00:00 [INF] - Attempting to connect to IoT Hub for client L5/video via AMQP... <6> 2022-06-08 21:12:06.968 +00:00 [INF] - New token requested by client L5/video, but using existing token as it is usable. <6> 2022-06-08 21:12:07.092 +00:00 [INF] - Cloud connection for L5/video is True <6> 2022-06-08 21:12:07.094 +00:00 [INF] - Connection status for L5/video changed to ConnectionEstablished <6> 2022-06-08 21:12:07.095 +00:00 [INF] - Client L5/video connected to cloud, processing existing subscriptions. <6> 2022-06-08 21:12:07.097 +00:00 [INF] - Created cloud proxy for client L5/video via AMQP, with client operation timeout 20 seconds. <6> 2022-06-08 21:12:07.099 +00:00 [INF] - Initialized cloud proxy a2e6456d-103e-4a16-be50-6006f2b9fe83 for L5/video <6> 2022-06-08 21:12:07.103 +00:00 [INF] - Created cloud connection for client L5/video <6> 2022-06-08 21:12:07.104 +00:00 [INF] - New cloud connection created for device L5/video <6> 2022-06-08 21:12:07.105 +00:00 [INF] - Authenticated L5/video with IotHub <6> 2022-06-08 21:12:07.107 +00:00 [INF] - Successfully generated identity for clientId L5/video and username ksayecrdemo.azure-devices.net/L5/video/?api-version=2019-10-01&DeviceClientType=azure-iot-device-iothub-py%2F2.7.1%283.7.13%3BLinux%20%23189-Ubuntu%20SMP%20Wed%20May%2018%2014%3A13%3A57%20UTC%202022%3Bx86_64%29 <6> 2022-06-08 21:12:07.108 +00:00 [INF] - ClientAuthenticated, L5/video, 64c1f7fd <6> 2022-06-08 21:12:07.114 +00:00 [INF] - New device connection for device L5/video <6> 2022-06-08 21:12:07.115 +00:00 [INF] - Client L5/video connected to edgeHub, processing existing subscriptions. <6> 2022-06-08 21:12:07.115 +00:00 [INF] - Skipping L5/video for subscription processing, as it is currently being processed. <6> 2022-06-08 21:12:07.124 +00:00 [INF] - Bind device proxy for device L5/video <6> 2022-06-08 21:12:07.127 +00:00 [INF] - Binding message channel for device Id L5/video <6> 2022-06-08 21:12:09.846 +00:00 [INF] - Updated reported properties for L5/$edgeHub <6> 2022-06-08 21:12:31.374 +00:00 [INF] - Attempting to connect to IoT Hub for client L5/IoTEdgeAPIProxy via AMQP... <6> 2022-06-08 21:12:31.424 +00:00 [INF] - New token requested by client L5/IoTEdgeAPIProxy, but using existing token as it is usable. <4> 2022-06-08 21:12:31.484 +00:00 [WRN] - Error creating cloud connection for client L5/IoTEdgeAPIProxy Microsoft.Azure.Devices.Client.Exceptions.UnauthorizedException: error(condition:amqp:unauthorized-access,description:Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key..) ---> Microsoft.Azure.Amqp.AmqpException: Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key.. 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) --- End of inner exception stack trace --- 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) 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() at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 143 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 55 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 186 --- 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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /home/vsts/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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 132 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 107 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ClientTokenCloudConnection.Create(ITokenCredentials tokenCredentials, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, String productInfo, Option`1 modelId) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ClientTokenCloudConnection.cs:line 85 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.Connect(IClientCredentials clientCredentials, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 137 <6> 2022-06-08 21:12:31.492 +00:00 [INF] - Error creating new device connection for device L5/IoTEdgeAPIProxy Microsoft.Azure.Devices.Client.Exceptions.UnauthorizedException: error(condition:amqp:unauthorized-access,description:Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key..) ---> Microsoft.Azure.Amqp.AmqpException: Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key.. 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) --- End of inner exception stack trace --- 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) 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() at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 143 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 55 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 186 --- 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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /home/vsts/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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 132 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 107 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ClientTokenCloudConnection.Create(ITokenCredentials tokenCredentials, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, String productInfo, Option`1 modelId) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ClientTokenCloudConnection.cs:line 85 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.Connect(IClientCredentials clientCredentials, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 137 <4> 2022-06-08 21:12:31.502 +00:00 [WRN] - Error validating token for L5/IoTEdgeAPIProxy with IoTHub Microsoft.Azure.Devices.Client.Exceptions.UnauthorizedException: error(condition:amqp:unauthorized-access,description:Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key..) ---> Microsoft.Azure.Amqp.AmqpException: Put token failed. status-code: 401, status-description: The specified SAS token has an invalid signature. It does not match either the primary or secondary key.. 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) --- End of inner exception stack trace --- 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) 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() at Microsoft.Azure.Devices.Edge.Util.TaskEx.TimeoutAfter(Task task, TimeSpan timeout) in /home/vsts/work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 143 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ModuleClientWrapper.OpenAsync() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ModuleClientWrapper.cs:line 55 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.<>c__DisplayClass30_0.<b__0>d.MoveNext() in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 186 --- 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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 145 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.InvokeFunc[T](Func`1 func, String operation, Boolean useForConnectivityCheck) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ConnectivityAwareClient.cs:line 173 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ConnectivityAwareClient.OpenAsync() in /home/vsts/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 /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 132 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnection.CreateNewCloudProxyAsync(ITokenProvider newTokenProvider) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnection.cs:line 107 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ClientTokenCloudConnection.Create(ITokenCredentials tokenCredentials, Action`2 connectionStatusChangedHandler, ITransportSettings[] transportSettings, IMessageConverterProvider messageConverterProvider, IClientProvider clientProvider, ICloudListener cloudListener, TimeSpan idleTimeout, Boolean closeOnIdleTimeout, TimeSpan operationTimeout, String productInfo, Option`1 modelId) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ClientTokenCloudConnection.cs:line 85 at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.CloudConnectionProvider.Connect(IClientCredentials clientCredentials, Action`2 connectionStatusChangedHandler) in /home/vsts/work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/CloudConnectionProvider.cs:line 137 <3> 2022-06-08 21:12:31.509 +00:00 [ERR] - Unable to generate identity for clientId L5/IoTEdgeAPIProxy and username l5.saye.org/L5/IoTEdgeAPIProxy/?api-version=2018-06-30 <6> 2022-06-08 21:12:31.509 +00:00 [INF] - ClientNotAuthenticated, Client ID: L5/IoTEdgeAPIProxy; Username: l5.saye.org/L5/IoTEdgeAPIProxy/?api-version=2018-06-30, 0d59f7a3 ```