[BUG] `UseAzureMonitor` collects too many internal logs about azure-sdk-for-net HOT 14 CLOSED

Here is a minimal repro app: https://github.com/Azure/azure-sdk-for-net/tree/main/sdk/monitor/Azure.Monitor.OpenTelemetry.AspNetCore/tests/Azure.Monitor.OpenTelemetry.AspNetCore.Demo

@TaoChenOSU Did you meant to share a different link? This is a basic app which does not even use any Azure sdk...

No, this is the link I meant to send. If you run it, it prints out a bunch of logs from Azure.Core:

from azure-sdk-for-net.

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

from azure-sdk-for-net.

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @cijothomas @rajkumar-rangaraj @reyang @TimothyMothra @vishweshbankwar.

from azure-sdk-for-net.

Hi @TaoChenOSU,
Yes, our package subscribes to all "Azure.*" traces. This should provide a complete picture of your application.

Are you asking to disable this?

from azure-sdk-for-net.

Hi @TimothyMothra,

Thank you for your quick response!

Yes, I think it'd be nice to be able to disable that since these entities that are producing telemetry may not be of our concern during the prototyping stage. Plus, we can always add Azure.* back via ConfigureOpenTelemetryTracerProvider.

from azure-sdk-for-net.

Hi @TaoChenOSU one follow up question. Sorry, the vocabulary is a little confusing here... I just wanted to quickly clarify which part you're referring to.

• "OpenTelemetry Traces" includes things like Requests and Dependencies. This is configured via the TracerProvider.
• "OpenTelemetry Logs" are the misc everything else. .NET's implementation leverages ILogger, and the configuration includes LogLevel. These go to "Application Insights Traces" table.

When you're describing Azure.*, you're referring to Dependencies, correct (ie: Azure Storage)?
You mentioned "log level" in your original description so I just wanted to double check that we're discussing the same thing. :)

from azure-sdk-for-net.

Hi @TimothyMothra,

I may be wrong, but I believe that when you add the trace from a particular entity, you also opt in to capture the logs it produces. Correct me if I am wrong.

In my case, once I do UseAzureMonitor, I start seeing logs from Azure.Identity showing up on my terminal (our project does have a dependency on it and I am testing the project locally but with telemetry enabled), as well as in ApplicationInsights' traces table.

(I am actually not sure why the logs from Azure.Identity were not showing up when I didn't have UseAzureMonitor. I didn't configure the log level for the package or anything.)

You mentioned OPTL traces, which I think that they are valuable to have in the end-to-end transaction record and in the application map in ApplicationInsights. However, I don't want unexpected logs to start showing up everywhere.

from azure-sdk-for-net.

FYI, this is an example of the logs I get from Azure.Identity when I enable telemetry via UseAzureMonitor. It's showing that it's trying the credential types in the order according to this doc: https://learn.microsoft.com/en-us/dotnet/api/azure.identity.defaultazurecredential?view=azure-dotnet.

I am not very interested in this information, and it buries the logs that are meaningful to me. Now, I know I can set the log level to suppress the logs, but that doesn't feel like a proper solution.

from azure-sdk-for-net.

@TaoChenOSU From the screenshot shared above, the logs you are seeing are not from AzureMonitor, they are not from OpenTelemetry either!
My best guess is - they are coming from ConsoleLoggerProvider that is enabled by default, as part of asp.net core! You can confirm by clearing the default providers using ClearProviders().

It is not clear how enabling AzureMonitor triggered these logs.. If you can share a minimal repro app, it'll be easy to narrow down what is triggering it.. @TimothyMothra's guess that AddSource("Azure.*") is the cause is a good possibility. You can confirm that by removing azuremonitor completely, and enabling OTel yourself with AddSource("Azure.*"). It is possible that Azure.identity emits ILogger logs, when tracing is enabled.

from azure-sdk-for-net.

Hi @cijothomas,

Thanks for your reply!

Here is a minimal repro app: https://github.com/Azure/azure-sdk-for-net/tree/main/sdk/monitor/Azure.Monitor.OpenTelemetry.AspNetCore/tests/Azure.Monitor.OpenTelemetry.AspNetCore.Demo

If you just run the app, you will see a bunch of logs from Azure.Core. But if you remove the line builder.Services.AddOpenTelemetry().UseAzureMonitor();, those logs will not be printed out anymore!

I tried your first suggestion, but it didn't clear out the logs unfortunately.

I also tried enabling OTel without AzureMonitor. This is how I did it:

builder.Services.AddOpenTelemetry()
    .WithTracing(tracing => tracing
        .AddSource("Azure.*")
        .SetResourceBuilder(ResourceBuilder.CreateDefault().AddService(builder.Environment.ApplicationName))
        .AddAspNetCoreInstrumentation()
    );

builder.Logging.AddOpenTelemetry(options =>
{
    options.AddConsoleExporter();
});

This didn't create logs from the Azure.* namespace.

This is really strange, because I'd also expect the logs to be printed out regardless of if I enable telemetry or not.

from azure-sdk-for-net.

Here is a minimal repro app: https://github.com/Azure/azure-sdk-for-net/tree/main/sdk/monitor/Azure.Monitor.OpenTelemetry.AspNetCore/tests/Azure.Monitor.OpenTelemetry.AspNetCore.Demo

@TaoChenOSU Did you meant to share a different link? This is a basic app which does not even use any Azure sdk...

from azure-sdk-for-net.

Thanks @TaoChenOSU ! I think I got some idea now...

Workaround for quickly resolving issue:
builder.Logging.ClearProviders(); // add this line just before UseAzureMonitor() to clear off built-in providers in your dev environment. (one of the built-in provider is what is printing these logs to console)
builder.Services.AddOpenTelemetry().UseAzureMonitor();

From the latest screenshot shared, it looks like LiveMetrics feature (added in recent beta releases, but not in 1.1.0 stable) is calling LiveMetricsService (in the background), and this is executing code path which has ILogger logs. @TimothyMothra can help investigating the root cause here and see what would be a fix to avoid this noise.

I'd assume that you should not face this issue in 1.1.0 release (as live metrics did not exist in that version).

as well as in ApplicationInsights' traces table.

Could you confirm if these extra logs from Azure.Core is ending up in ApplicationInsights TraceTelemetry table? (That might shoot up billing, and you'd want to open an Azure Support Ticket, and refer this issue in that.)

from azure-sdk-for-net.

Thanks @cijothomas!

I downgraded to Azure.Monitor.OpenTelemetry.AspNetCore 1.1.0 and now the Azure.* logs are gone!

And I can confirm that the extra logs do show up in AppInsights' trace table.

from azure-sdk-for-net.

I got more information. This is a side effect of the AzureSdkLogForwarder introduced recently #41373.
This was added to collect extra diagnostic information from other Azure client SDKs.
This feature is documented here: https://learn.microsoft.com/en-us/dotnet/azure/sdk/logging#logging-using-azuremonitoropentelemetryaspnetcore

cc @lmolkova

Problem

This has the side effect of collecting ALL the http events (Posts and Responses) our AzureMonitor SDK generates for sending telemetry (both to AzureMonitor and LiveMetrics).

Workaround

• The easiest workaround is to downgrade to our latest stable Azure.Monitor.OpenTelemetry.AspNetCore 1.1.0.
  This feature is only exposed in our 1.2.0-beta versions.

• Alternatively you can configure logging levels to exclude these events.
  In the screenshot above, the extra logs start with "Azure.Core". This same name can be added to the appsettings.json:
  

from azure-sdk-for-net.