[BUG] Erroneous warning logs when performing CreateIfNotExistsAsync

[drauch]

Describe the bug
The following code logs a warning:

var serviceCollection = new ServiceCollection();
serviceCollection.AddLogging(b => b.AddConsole());
serviceCollection.AddAzureClients(ab => ab.AddBlobServiceClient("UseDevelopmentStorage=true"));
var serviceProvider = serviceCollection.BuildServiceProvider();

var client = serviceProvider.GetRequiredService<BlobServiceClient>();
var container = client.GetBlobContainerClient(Guid.NewGuid().ToString());
await container.CreateIfNotExistsAsync();
await container.CreateIfNotExistsAsync(); // here

Expected behavior
No warning is logged, we're not doing anything out of the ordinary which should trigger a warning for our operators.

Actual behavior (include Exception or Stack Trace)
It logs a warning, sample:

warn: Azure-Core[8]
      Error response [e5d2b146-8b40-47dc-8e0a-f12a623487d4] 409 The specified container already exists. (00.0s)
      Server:Windows-Azure-Blob/1.0,Microsoft-HTTPAPI/2.0
      x-ms-request-id:01ffe3d0-ee47-44d7-a35d-9303d108d19e
      x-ms-version:2020-04-08
      x-ms-error-code:ContainerAlreadyExists
      Date:Wed, 31 Mar 2021 07:31:06 GMT
      Content-Length:230
      Content-Type:application/xml

To Reproduce
See example above.

Environment:

• Name and version of the Library package used: Azure.Storage.Blobs 12.8.1 (but earlier versions as well)
• Hosting platform or OS and .NET runtime version: up-to-date Windows 10 at least in NET Framework 4.8 and .NET Core 3.1
• IDE and version : up-to-date Visual Studio 2019

[drauch]

Possible fix: It should be a info log only.

[jsquire]

Hi @drauch. Thank you for reaching out and we regret that you're experiencing difficulties. This is a known and, unfortunately, expected behavior at present. In these cases, the behavior is due to Application Insights capturing the REST traffic and interpreting the response code as an error, though it is expected by the SDK which does not consider it a failure. Unfortunately, the service result is an implementation detail which the SDK does not control and cannot influence, but one that is leaking out for AI monitoring.

We agree that it isn't our preferred experience for developers using the SDK. We're working with the Azure Monitor team to understand our options for making this better while still being compliant with the OpenTelemetry specification.

@pakrym may have more insight to share.

[jsquire]

//cc: @tg-msft

This is another example of the behavior first discussed in #9908

[fschmied]

In these cases, the behavior is due to Application Insights capturing the REST traffic and interpreting the response code as an error

@jsquire Is there any way for an Azure SDK client to work around this problem? E.g., by hooking into the Application Insights pipeline somehow? Note however that we're seeing this not just in telemetry sent to Azure Application Insights, but also as a local log message (via Microsoft.Extensions.Logging).

[jsquire]

I'll need to defer to @pakrym for the authoritative answer. Unfortunately, I don't know the Microsoft.Extensions.Logging framework well enough to speak definitively.

My assumption is that the extensions hook the active ETW log sources for content. If that is the case, you could opt out of logging HTTP calls entirely:

var options = new BlobClientOptions
{
    Diagnostics =
    {
        IsLoggingEnabled = false
    }
}

You may (or may not) be able to configure the listener used by the logging extensions to perform manual filtering of the ETW events as they're captured, before the application logs are emitted.

[pakrym]

Hey @fschmied, this is a known problem that's caused by client architecture. At the point where the HTTP request is logged (or a distributed tracing span started) the pipeline doesn't know how the client would interpret it.

We are looking into it long-term but.

As for a workaround you can look into adding ApplicationInsights ITelemetryProcessor that would change the status of the telemetry span. (https://docs.microsoft.com/en-us/azure/azure-monitor/app/api-filtering-sampling#create-a-telemetry-processor-c)

[pakrym]

Thinking about it, we can do something short-term as well. #20064 and microsoft/ApplicationInsights-dotnet#2200

[ghost]

Hi @drauch. 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.

[ghost]

Hi @drauch, 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.