Use of AAD authentication with Microsoft.Extensions.Azure can cause continuous trace loop due to lack of token caching

[maskati]

NuGet packages:

• Microsoft.ApplicationInsights.AspNetCore 2.20.0
• Microsoft.Extensions.Azure 1.1.1 (brings in Azure.Core and Azure.Identity)
  Runtime version: net6.0
  Hosting environment: Azure Web App with managed identity and associated Application Insights

Describe the bug

Application Insights trace logs are filling up with the following four traces when using AAD authenticated configuration in combination with with Microsoft.Extensions.Azure for dependency injection of Azure SDK clients:

1. Azure.Identity: ManagedIdentityCredential.GetToken invoked. Scopes: [ https://monitor.azure.com//.default ]...
2. Azure.Core: Request [00000000-0000-0000-0000-000000000000] GET http://127.0.0.1:41252/MSI/token/...
3. Azure.Core: Response [00000000-0000-0000-0000-000000000000] 200 OK (00.0s)...
4. Azure.Identity: ManagedIdentityCredential.GetToken succeeded. Scopes: [ https://monitor.azure.com//.default ]...

It seems that the Application Insights SDK is actually requesting a new token from TokenCredential for every telemetry transmission, and is also logging the logs related to requesting this token. This is resulting in a continuous loop of transmitting token acquisition trace logs related to the previous transmission of token acquisition trace logs. This is caused by AzureEventSourceLogForwarder in Microsoft.Extensions.Azure forwarding Azure SDK logs to .NET logs and Application Insights.

A related but somewhat separate issue is that the current implementation does no token caching, which places unnecessary pressure on the application and managed identity infrastructure. The original feature request #2190 states:

Azure.Identity implementation provides caching for most scenarios.
Our own caching - under discussion. Guidance was to rely on Azure.Identity implementation.

However the most common scenario of using managed identities does not implement caching. See for example Azure/azure-sdk-for-net#24046 or ManagedIdentityCredential.GetToken:

You may call this method directly, but you must also handle token caching and token refreshing.

Azure SDK client libraries mostly cache tokens through the common request pipeline. For example App Configuration uses BearerTokenAuthenticationPolicy which implements caching.

To Reproduce

dotnet new web
dotnet add package Microsoft.ApplicationInsights.AspNetCore -v 2.20.0
dotnet add package Microsoft.Extensions.Azure -v 1.1.1

Program.cs

using Azure.Identity;
using Microsoft.ApplicationInsights.Extensibility;
using Microsoft.Extensions.Azure;
using Microsoft.Extensions.Logging.ApplicationInsights;

var builder = WebApplication.CreateBuilder(args);
builder.Logging.AddFilter<ApplicationInsightsLoggerProvider>("", LogLevel.Information); // app insights default to log information level logs
builder.Services.Configure<TelemetryConfiguration>(config => config.SetAzureTokenCredential(new DefaultAzureCredential()));
builder.Services.AddApplicationInsightsTelemetry();

// use AddAzureClients for DI registration of Azure SDK clients
// https://docs.microsoft.com/fi-fi/dotnet/azure/sdk/dependency-injection#register-client
// When the AddAzureClients extension method is called, the AzureEventSourceLogForwarder service is registered.
// The AzureEventSourceLogForwarder service enables you to use the standard ASP.NET Core logging configuration for logging.
// https://docs.microsoft.com/en-us/dotnet/azure/sdk/logging#map-to-aspnet-core-logging
builder.Services.AddAzureClients(_ => { }); // TryAddSingleton<AzureEventSourceLogForwarder>()

var app = builder.Build();

// simulate what various Azure client factories do on construction
// for example if we had registered AddServiceBusClient, which would then be constructed by AzureClientFactory, which would call AzureEventSourceLogForwarder.Start()
// https://github.com/Azure/azure-sdk-for-net/blob/502161f5ad3c721f8aba00d0afb477be0d77f187/sdk/extensions/Microsoft.Extensions.Azure/src/Internal/AzureClientFactory.cs#L46
var azureEventSourceLogForwarder = app.Services.GetRequiredService<AzureEventSourceLogForwarder>();
azureEventSourceLogForwarder.Start();

app.MapGet("/", () => "Hello World!");
app.Run();

[TimothyMothra]

Hello @maskati, Thank you for the details.

I'll need more time to investigate AzureEventSourceLogForwarder, the Application Insights SDK is not expected to log the token acquisition traffic.

Regarding caching, the fix is not expected to come from this library.
As mentioned in #2190, the guidance we were provided was to depend on Azure.Identity's implementation to provide caching.

[maskati]

the guidance we were provided was to depend on Azure.Identity's implementation to provide caching

@TimothyMothra my underatanding is that Azure.Identity does not currently implement caching, rather some credential providers happen to do so (e.g. MSAL based ones) Azure/azure-sdk-for-net#24045 (comment):

Sounds like you are using the Managed Identity credential. Since this is not a credential that is implemented with MSAL, there is no caching for this currently.

Azure.Identity might at some point implement general caching if MSAL exposes such implementation Azure/azure-sdk-for-net#25361:

MSAL's cache implements some fairly complex logic that we do not ever intend to duplicate in Azure.Identity

The issue is that App Insights generates a large volume of authenticated requests, with each request acquiring a new token. In the case of managed identity this hits the MSI endpoint with a token request for each telemetry item.

Most Azure SDK clients (Storage, App Config etc.) implement token cache, for example using BearerAuthenticationTokenPolicy. Is there a reason App Insights is different?

[TimothyMothra]

Most Azure SDK clients (Storage, App Config etc.) implement token cache, for example using BearerAuthenticationTokenPolicy. Is there a reason App Insights is different?

The Azure SDKs share a common implementation for HttpClient. Adopting this is out of scope for this repo.

The recommendation is to wait for Azure.Identity to deliver caching. Please upvote these issues on their repo to help them prioritize this.
See also this comment in Azure/azure-sdk-for-net#25361 (comment)

We're also working on a caching strategy for ManagedIdentityCredential involving improved support from MSAL. I don't have an exact timeframe to share, but it is on the radar for sure.

[maskati]

Ok thanks for the update on token caching @TimothyMothra. It might be useful to document that when using AAD authentication you should limit logging of Azure.Core and Azure.Identity category logs through the Application Insights logging provider to Warning level or higher.

Regarding the original issue of trace loops due to token acquisition, how does App Insights currently prevent telemetry transmission over http from triggering traces on the telemetry transmission itself (http transmission trace loops)?

[TimothyMothra]

how does App Insights currently prevent telemetry transmission over http from triggering traces

All of our outbound HTTP calls are wrapped with SdkInternalOperationsMonitor:

ApplicationInsights-dotnet/BASE/src/ServerTelemetryChannel/Implementation/TransmissionSender.cs

Lines 194 to 196 in 87c2019

	private async Task StartSending(Transmission transmission)
	{
	SdkInternalOperationsMonitor.Enter();

[a99cl208]

@TimothyMothra the ManagedIdentityCredential uses caching since Azure.Identity 1.8.0. It would be great if you can move to this dependency for 1.22.0.

[pharring]

Microsoft.ApplicationInsights doesn't depend on Azure.Identity. It relies on a TokenCredential passed by the application. The burden, therefore, is on the application to provide a TokenCredential with caching.

[maskati]

Would this be resolved by a documentation update e.g. ”when using Application Insights with AAD authentication it is recommended to provide a TokenCredential implementing caching. For ManagedIdentityCredential this can be achieved by using Azure.Identity version 1.8.0 or greater.”?

[pharring]

@TimothyMothra, what do you think of #2720 to address this in code?

[a99cl208]

Ok I this. My issue in fact is that the App Insights lib + Az.Identity one installed in the Azure functions are using 1.5.0 so its really a mess when you have a lot of logs to send using AAD auth since there is no cache. I will therefore open a ticket on the Az function Git referencing this issue. Thanks.

[adstep]

I'm running Azure.Identity 1.8.2 and Microsoft.ApplicationInsights.AspNetCore 2.21.0 and it still seems to be spinning requesting. It completely kills the performance of my app. Is anyone else seeing this?

Seeing a lot of exceptions that look like this:

[github-actions]

This issue is stale because it has been open 300 days with no activity. Remove stale label or this will be closed in 7 days. Commenting will instruct the bot to automatically remove the label.