edgeHub stops after 2 minutes (DeviceScopeIdentitiesCache.ServiceIdentityStore.ReadCacheFromStore Timeout)

[felixmondelo]

Current Behavior

After restart edgeHub module, 2 minutes later an TimeoutException happens with this detail:

[ERR] - Stopping with exception
System.TimeoutException: Operation timed out
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.<>c.<.cctor>b__27_0() in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 114
   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 149
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.ServiceIdentityStore.ReadCacheFromStore(IKeyValueStore`2 encryptedStore, String actorDeviceId) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 500
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.Create(IServiceIdentityHierarchy serviceIdentityHierarchy, IServiceProxy serviceProxy, IKeyValueStore`2 encryptedStorage, TimeSpan refreshRate, TimeSpan refreshDelay, TimeSpan initializationRefreshDelay) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 93
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.CommonModule.<Load>b__28_15(IComponentContext c) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/CommonModule.cs:line 336
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__36_10(IComponentContext c) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 245
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__36_12(IComponentContext c) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 284
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<>c.<<Load>b__36_26>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 488

Steps to Reproduce

Provide a detailed set of steps to reproduce the bug.

1. iotedge restart edgeHub

Context (Environment)

Output of iotedge check

Details

Configuration checks (aziot-identity-service)
---------------------------------------------
√ keyd configuration is well-formed - OK
√ certd configuration is well-formed - OK
√ tpmd configuration is well-formed - OK
√ identityd configuration is well-formed - OK
√ daemon configurations up-to-date with config.toml - OK
√ identityd config toml file specifies a valid hostname - OK
√ aziot-identity-service package is up-to-date - OK
√ host time is close to reference time - OK
√ preloaded certificates are valid - OK
√ keyd is running - OK
√ certd is running - OK
√ identityd is running - OK
√ read all preloaded certificates from the Certificates Service - OK
√ read all preloaded key pairs from the Keys Service - OK
√ check all EST server URLs utilize HTTPS - OK
√ ensure all preloaded certificates match preloaded private keys with the same ID - OK

Connectivity checks (aziot-identity-service)
--------------------------------------------
√ host can connect to and perform TLS handshake with iothub AMQP port - OK
√ host can connect to and perform TLS handshake with iothub HTTPS / WebSockets port - OK
√ host can connect to and perform TLS handshake with iothub MQTT port - OK

Configuration checks
--------------------
√ aziot-edged configuration is well-formed - OK
√ configuration up-to-date with config.toml - OK
√ container engine is installed and functional - OK
√ configuration has correct URIs for daemon mgmt endpoint - OK
√ aziot-edge package is up-to-date - OK
√ container time is close to host time - OK
√ DNS server - OK
√ production readiness: logs policy - OK
√ 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
√ 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
    skipping because of not required in this configuration
√ 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
    skipping because of not required in this configuration
35 check(s) succeeded.

Device Information

• Host OS [e.g. Ubuntu 22.04, Windows Server IoT 2019]: Ubuntu 20.04.6 LTS
• Architecture [e.g. amd64, arm32, arm64]: amd64
• Container OS [e.g. Linux containers, Windows containers]: Linux

Runtime Versions

• aziot-edged [run iotedge version]: 1.5.16
• Edge Agent [image tag (e.g. 1.0.0)]: 1.5.20.125716445 (803fa5bb813a97e384db61410adda48be4fb8839)
• Edge Hub [image tag (e.g. 1.0.0)]: 1.5.20.125716445 (803fa5bb813a97e384db61410adda48be4fb8839)
• Docker/Moby [run docker version]: 28.0.3-1

Logs

edge-hub logs

[ERR] - Stopping with exception
System.TimeoutException: Operation timed out
   at Microsoft.Azure.Devices.Edge.Util.TaskEx.<>c.<.cctor>b__27_0() in /mnt/vss/_work/1/s/edge-util/src/Microsoft.Azure.Devices.Edge.Util/TaskEx.cs:line 114
   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 149
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.ServiceIdentityStore.ReadCacheFromStore(IKeyValueStore`2 encryptedStore, String actorDeviceId) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 500
   at Microsoft.Azure.Devices.Edge.Hub.Core.DeviceScopeIdentitiesCache.Create(IServiceIdentityHierarchy serviceIdentityHierarchy, IServiceProxy serviceProxy, IKeyValueStore`2 encryptedStorage, TimeSpan refreshRate, TimeSpan refreshDelay, TimeSpan initializationRefreshDelay) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Core/DeviceScopeIdentitiesCache.cs:line 93
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.CommonModule.<Load>b__28_15(IComponentContext c) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/CommonModule.cs:line 336
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__36_10(IComponentContext c) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 245
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<Load>b__36_12(IComponentContext c) in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 284
   at Microsoft.Azure.Devices.Edge.Hub.Service.Modules.RoutingModule.<>c.<<Load>b__36_26>d.MoveNext() in /mnt/vss/_work/1/s/edge-hub/core/src/Microsoft.Azure.Devices.Edge.Hub.Service/modules/RoutingModule.cs:line 488

[felixmondelo]

I changed the edgeHub directory to a new one and everything started working again.

It surely has to do with updating the versions of the edgeAgent and the edgeHub; in several issues, they suggested deleting the local storage of the edgeHub as a mitigation.