[BUG] Thread starvation in Azure extensions for DataProtection

[yaroslavlsd]

Library name and version

Azure.Identity.dll 1.12.0+75fb76... 1.1200.24.31701

Describe the bug

We have Azure Web App service on stage environment based on .net 8 and reproducing thread starvation due to Azure.Extensions.AspNetCore.DataProtection.
Unfortunately I can't provide a dump, just because I forgot to do it.

We are using

• Microsoft.AspNetCore.DataProtection (azure keyvault & azure blob storage) for auth cookie.
• Azure cients with ExcludeManagedIdentityCredential": false and all other credentials are excluded for all azure clients

Expected behavior

Works without thread starvation.

My points:

1. Looks like it stuck forever in loading keys from azure storage, possible inside in AzureBlobXmlRepository.
2. Asp.net should detect long requests and give result, at least log error etc. Link1 Link2
3. Looks like UseRequestTimeouts does not help here since it will wait result forever also.
4. Asp.net should not process new request if dont have resources. Link1

Actual behavior

1. Reproducing thread starvation due to Azure.Extensions.AspNetCore.DataProtection.
2. Requests hang forever

Related links to this problem.

• Creating two instances of DefaultAzureCredential causes requests using the credential to never complete
• Azure.Extensions.AspNetCore.DataProtection.Keys Heavy load causes blocked threads
• 8.0.5 Change - Improve usage of Type.GetType when activating types in data protection

Reproduction Steps

Code for registering data protection services

    public static IServiceCollection AddDataProtectionFromConfiguration(
        this IServiceCollection serviceDescriptors_, 
        IConfiguration configuration_)
    {
        serviceDescriptors_.Configure<KeyManagementOptions>(configuration_.GetRequiredSection(DataProtectionConfigurationSections.KEY_MANAGEMENT));

        IDataProtectionBuilder dataProtectionBuilder = serviceDescriptors_.AddDataProtection(configuration_.Bind);

        AuthenticatedEncryptorConfiguration encryptorConfiguration = new();
        configuration_.GetRequiredSection(DataProtectionConfigurationSections.KEY_MANAGEMENT_ALGORITHMS).Bind(encryptorConfiguration);
        dataProtectionBuilder.UseCryptographicAlgorithms(encryptorConfiguration);

        var keyVaultOptions = configuration_.GetRequiredSection(DataProtectionConfigurationSections.KEY_VAULT).Get<KeyVaultDataProtectionOptions>()!;
        if (keyVaultOptions.Enabled)
        {
            var credential = new DefaultAzureCredential(keyVaultOptions.Credential);
            dataProtectionBuilder.ProtectKeysWithAzureKeyVault(new Uri(keyVaultOptions.KeyIdentifier), credential);
        }

        var blobsConfiguration = configuration_.GetRequiredSection(DataProtectionConfigurationSections.BLOB_STORAGE);
        var blobStorageOptions = blobsConfiguration.Get<BlobStorageOptions>()!;
        if (blobStorageOptions.Enabled)
        {
            serviceDescriptors_.AddAzureClients(clientBuilder =>
            {
                var credential = new DefaultAzureCredential(blobStorageOptions.Credential);
                clientBuilder
                    .AddBlobServiceClient(blobsConfiguration.GetRequiredSection(DataProtectionConfigurationSections.AZURE_CONNECTION_SUBSECTION))
                    .WithCredential(credential)
                    ;
            });

            dataProtectionBuilder.PersistKeysToAzureBlobStorage((serviceProvider) =>
            {
                return serviceProvider
                    .GetRequiredService<BlobServiceClient>()
                    .GetBlobContainerClient(blobStorageOpftions.ContainerName)
                    .GetBlobClient(blobStorageOptions.BlobName);
            });
        }

        return serviceDescriptors_;
    }

Logs

We can provide more logs in direct communication.

Last succeeded request for this behaviour.

Looks like we are validating encrypted auth cookie request.
For last succeeded request (where we have Existing cached key ring is expired log) we have next logs

--CONTINUE--

2024-07-18 10:41:28.435 +00:00 [Information] Microsoft.AspNetCore.Cors.Infrastructure.CorsService => SpanId:32c0228a778d652b, TraceId:fdc2d24122958bd709302f8b246e24d7, ParentId:0000000000000000 => RequestPath:[redacted] RequestId:4000257e-0000-db00-b63f-84710c7967bb:
CORS policy execution successful.
2024-07-18 10:41:28.441 +00:00 [Debug] Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider => SpanId:32c0228a778d652b, TraceId:fdc2d24122958bd709302f8b246e24d7, ParentId:0000000000000000 => RequestPath:[redacted] RequestId:4000257e-0000-db00-b63f-84710c7967bb:
Existing cached key ring is expired. Refreshing.
2024-07-18 10:41:28.497 +00:00 [Information] Azure.Identity => SpanId:02f70354d5a1d0d2, TraceId:fdc2d24122958bd709302f8b246e24d7, ParentId:dfa2c7e091c7545e => RequestPath:[redacted] RequestId:4000257e-0000-db00-b63f-84710c7967bb:
DefaultAzureCredential.GetToken invoked. Scopes: [ https://storage.azure.com/.default ] ParentRequestId: 7d717c75-7a46-4666-a968-1c4db4b8d34f
2024-07-18 10:41:28.533 +00:00 [Information] Azure.Identity => SpanId:02f70354d5a1d0d2, TraceId:fdc2d24122958bd709302f8b246e24d7, ParentId:dfa2c7e091c7545e => RequestPath:[redacted] RequestId:4000257e-0000-db00-b63f-84710c7967bb:
ManagedIdentityCredential.GetToken invoked. Scopes: [ https://storage.azure.com/.default ] ParentRequestId: 7d717c75-7a46-4666-a968-1c4db4b8d34f
False MSAL 4.61.3.0 MSAL.NetCore .NET 8.0.5 Microsoft Windows 10.0.20348 [2024-07-18 10:41:29Z - ca4d36d6-2a05-490e-be3d-e434e25ed1f0] MSAL MSAL.NetCore with assembly version '4.61.3.0'. CorrelationId(ca4d36d6-2a05-490e-be3d-e434e25ed1f0)
2024-07-18 10:41:29.366 +00:00 [Information] Azure.Identity => SpanId:6294de95aa763653, TraceId:fdc2d24122958bd709302f8b246e24d7, ParentId:e7de5b548e59707b => RequestPath:[redacted] RequestId:4000257e-0000-db00-b63f-84710c7967bb:
False MSAL 4.61.3.0 MSAL.NetCore .NET 8.0.5 Microsoft Windows 10.0.20348 [2024-07-18 10:41:29Z - ca4d36d6-2a05-490e-be3d-e434e25ed1f0] === AcquireTokenForClientParameters ===
SendX5C: False
ForceRefresh: False

--CONTINUE--

Hanged request 1.

Looks like here we are creating encrypted auth cookie response.

--CONTINUE--

2024-07-20 09:41:06.278 +00:00 [Debug] Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider => SpanId:72d050fdab0d874c, TraceId:da82c5991211c4752350cdb006de9ea7, ParentId:0000000000000000 => InternalTraceId:1996DC21-FAD1-0000-0000-E6976594FA5B => RequestPath:[redacted] RequestId:400053e7-0000-db00-b63f-84710c7967bb => [redacted]:
Existing cached key ring is expired. Refreshing.

--END--

Hanged request 2.

--CONTINUE--

2024-07-24 10:09:10.450 +00:00 [Information] Microsoft.AspNetCore.Cors.Infrastructure.CorsService => SpanId:9c5a31fc1f4c5641, TraceId:0ed50ad12e1fecb6c599c1be21dc1348, ParentId:0000000000000000 => RequestPath:[redacted] RequestId:40004af2-0000-dc00-b63f-84710c7967bb:
CORS policy execution successful.
2024-07-24 10:09:10.510 +00:00 [Debug] Microsoft.AspNetCore.DataProtection.DecryptorTypeForwardingActivator => SpanId:9c5a31fc1f4c5641, TraceId:0ed50ad12e1fecb6c599c1be21dc1348, ParentId:0000000000000000 => RequestPath:[redacted] RequestId:40004af2-0000-dc00-b63f-84710c7967bb:
Forwarded activator type request from Azure.Extensions.AspNetCore.DataProtection.Keys.AzureKeyVaultXmlDecryptor, Azure.Extensions.AspNetCore.DataProtection.Keys, Version=1.2.3.0, Culture=neutral, PublicKeyToken=92742159e12e44c8 to Azure.Extensions.AspNetCore.DataProtection.Keys.AzureKeyVaultXmlDecryptor, Azure.Extensions.AspNetCore.DataProtection.Keys, Culture=neutral

--END--

Environment

• OS version: Microsoft Windows NT 10.0.20348.0
• 64 bit system: True
• 64 bit process: False
• Processor count: 1
• CLR version: 4.0.30319.42000
• 8.0.5 runtime installed by Azure on 7/16/2024 4:35 AM UTC.
• App deployed and single instance started on 2024-07-16 16:19:44.128 +00:00 and still runs until problem detected.

Lib versions in artifact for this deploy

• Azure.Core.dll - 1.40.0+242d8a... 1.4000.24.30605
• Azure.Identity.dll - 1.12.0+75fb76... 1.1200.24.31701
• Azure.Security.KeyVault.Keys - 4.2.0+1a4ecd4... 4.200.21.31503
• Azure.Security.KeyVault.Secrets.dll - 4.2.0+1a4ecd4... 4.200.21.31503
• Azure.Extensions.AspNetCore.DataProtection.Blobs - 1.3.4+831c24c... 1.300.424.21702
• Azure.Extensions.AspNetCore.DataProtection.Keys - 1.2.3+a3a24ef... 1.200.324.11302

On 27.07.2024 we are using latest stable version for all Microsoft libs.

[github-actions]

Thank you for your feedback. Tagging and routing to the team member best able to assist.

[jsquire]

@yaroslavlsd : Looking over your dependencies, you've got a reference to Azure.Core v1.40.0, which has a known race condition that can lead to stalls in certain edge cases. Azure.Identity and the Azure Storage packages are known to hit this case more frequently than most packages. Once new versions of these libraries are released, they will include an updated reference. To mitigate until that time, please add a direct reference in your application to Azure.Core v1.41.0+, which will hoist the version used by Identity and the other Azure SDK packages.

Details are discussed in the Azure.Core changelog.

[github-actions]

Hi @yaroslavlsd. Thank you for opening this issue and giving us the opportunity to assist. We believe that this has been addressed. If you feel that further discussion is needed, please add a comment with the text "/unresolve" to remove the "issue-addressed" label and continue the conversation.

[github-actions]

Hi @yaroslavlsd, since you haven’t asked that we /unresolve the issue, we’ll close this out. If you believe further discussion is needed, please add a comment /unresolve to reopen the issue.