Error getting device scope result from IoTHub for OPC-UA endpoint IoT Device (Unauthorized)

[deanwyns]

Describe the bug
The edge hub is unable to authorize the device against IoT Hub (connected OPC-UA endpoint).

To Reproduce
I am not sure how this is reproduced. IIoT gets into a state where the device is unauthorized.
We are using version 2.7.170.

1. Connect an OPC-UA endpoint (ours has no security policy, so None)
2. Endpoint is Ready and ActivatedAndConnected
3. Publish some nodes
4. No telemetry is received. Check the edgeHub logs and see error.

Expected behavior
OPC-UA endpoint device should connect successfully and send telemetry.

Screenshots
N/A

Desktop (please complete the following information):
Not really applicable but:

• OS: Mac OS
• Browser: Firefox
• Version 81

Edge Hub logs

<6> 2020-10-26 15:14:24.187 +00:00 [INF] - Unable to authenticate client uat2debc6682f391903f31826bcbaefd2571e234e49 with cached service identity uat2debc6682f391903f31826bcbaefd2571e234e49. Resyncing service identity...
<4> 2020-10-26 15:14:24.685 +00:00 [WRN] - Error while refreshing the service identity for uat2debc6682f391903f31826bcbaefd2571e234e49
Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiException: Message: Error getting device scope result from IoTHub, HttpStatusCode: Unauthorized, Content: {"Message":"ErrorCode:IotHubUnauthorizedAccess;Unauthorized","ExceptionMessage":"Tracking ID:9d72d5d2308048c08b7ae7fd31df403b-G:4-TimeStamp:10/26/2020 15:14:24"}
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiClient.GetIdentitiesInScope(Uri uri) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/DeviceScopeApiClient.cs:line 131
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiClient.GetIdentitiesInScopeWithRetry(Uri uri) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/DeviceScopeApiClient.cs:line 99
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ServiceProxy.GetServiceIdentity(String deviceId) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ServiceProxy.cs:line 29
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.RefreshServiceIdentity(String id) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 72

I have tried clearing IoT edge's cache and restarting the daemon but that doesn't help.

[cristipogacean]

I would recommend upgrading to 2.7.199, since we fixed some issues related to device scoping running in the transparent gateway mode for the iotedge modules.

[deanwyns]

Hi

I updated the services to 2.7.199.

NAME             STATUS           DESCRIPTION      CONFIG
discovery        running          Up 13 minutes    mcr.microsoft.com/iotedge/discovery:2.7.199
edgeAgent        running          Up 15 minutes    mcr.microsoft.com/azureiotedge-agent:1.0.9.4
edgeHub          running          Up 14 minutes    mcr.microsoft.com/azureiotedge-hub:1.0.9.4
publisher        running          Up 14 minutes    mcr.microsoft.com/iotedge/opc-publisher:2.7.199
twin             running          Up 14 minutes    mcr.microsoft.com/iotedge/opc-twin:2.7.199

I cleared IoT Edge's cache and restarted, and the edge hub still reports the error:

<6> 2020-10-30 10:06:16.092 +00:00 [INF] - Entering periodic task to reauthenticate connected clients
<6> 2020-10-30 10:06:16.094 +00:00 [INF] - Unable to authenticate client uat2debc6682f391903f31826bcbaefd2571e234e49 with cached service identity uat2debc6682f391903f31826bcbaefd2571e234e49. Resyncing service identity...
<4> 2020-10-30 10:06:16.587 +00:00 [WRN] - Error while refreshing the service identity for uat2debc6682f391903f31826bcbaefd2571e234e49
Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiException: Message: Error getting device scope result from IoTHub, HttpStatusCode: Unauthorized, Content: {"Message":"ErrorCode:IotHubUnauthorizedAccess;Unauthorized","ExceptionMessage":"Tracking ID:0868af54516b45eca8459411685b9ae8-G:14-TimeStamp:10/30/2020 10:06:16"}
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiClient.GetIdentitiesInScope(Uri uri) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/DeviceScopeApiClient.cs:line 131
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiClient.GetIdentitiesInScopeWithRetry(Uri uri) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/DeviceScopeApiClient.cs:line 99
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ServiceProxy.GetServiceIdentity(String deviceId) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ServiceProxy.cs:line 29
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.RefreshServiceIdentity(String id) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 72

Any clue what I can still try?

Thank you !

[deanwyns]

The same problem is now also happening on another device (which is running at a different location):

<6> 2020-11-03 07:18:23.496 +00:00 [INF] - Unable to authenticate client uatac5bd2ead985af14ec8c5974600cc191b3cfc3a6 with cached service identity uatac5bd2ead985af14ec8c5974600cc191b3cfc3a6. Resyncing service identity...
<4> 2020-11-03 07:18:24.298 +00:00 [WRN] - Error while refreshing the service identity for uatac5bd2ead985af14ec8c5974600cc191b3cfc3a6
Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiException: Message: Error getting device scope result from IoTHub, HttpStatusCode: Unauthorized, Content: {"Message":"ErrorCode:IotHubUnauthorizedAccess;Unauthorized","ExceptionMessage":"Tracking ID:da9f966f95d14c49a08a549552d1081c-G:15-TimeStamp:11/03/2020 07:18:24"}
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiClient.GetIdentitiesInScope(Uri uri) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/DeviceScopeApiClient.cs:line 131
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.DeviceScopeApiClient.GetIdentitiesInScopeWithRetry(Uri uri) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/DeviceScopeApiClient.cs:line 99
   at Microsoft.Azure.Devices.Edge.Hub.CloudProxy.ServiceProxy.GetServiceIdentity(String deviceId) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.CloudProxy/ServiceProxy.cs:line 29
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.RefreshServiceIdentity(String id) in /home/vsts/work/1/s/edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 72

I thought maybe it could be the IoT Hub's message limit, but at the moment of the error it's:
Messages used today: 15728
Daily messages quota: 400000
IoT Devices: 117

[karok2m]

@deanwyns, can you please also send us the support bundle from this IoT Edge device ? Preferably, for at least 6 or 12 hours. It will contain the logs of all modules running on this IoT Edge device, so we can understand if OPC Publisher has started publishing telemetry or not.

The warning that you are seeing is most probably cause by a non-child leaf device that is used in OPC Twin module. And while edgeHub shows this error, it also has a fallback mechanism for establishing a connection with those type of devices. So the warning should not cause any major issues to the data delivery pipeline and you should still see telemetry flowing. If it is not, then with the support bundle we can see if OPC Publisher or OPC Twin modules were also reporting any issues.

[marcschier]

Will release in 2.7.2xxx some time early Jan.