[BUG] Elastic APM OpenTelemetry Error: An item with the same key has already been added. Key: error.type

[aodpi]

APM Agent version

The version of the Elastic.Apm nuget package used
1.25.0

Environment

Operating system and version:

Microsoft Windows 11

.NET Framework/Core name and version (e.g. .NET 4.6.2, NET Core 3.1.100) :

NET Core 7.0.13

Application Target Framework(s) (e.g. net462, netcoreapp3.1):

net7.0

Describe the bug

When starting an app with an elastic apm agent configured and using asp.net core dataprotection with azure key vault I get an error
that I think is related to the Elastic APM agent itself. It seems that the OpenTelemetry ActivityListener is trying to add duplicate keys in a dictionary triggering this Exception. Because of this the entire application is unusable.

Error details

Exception: Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider An error occurred while reading the key ring. System.ArgumentException: An item with the same key has already been added. Key: error.type

Exception StackTrace:

System.ArgumentException: An item with the same key has already been added. Key: error.type
   at System.Collections.Generic.Dictionary`2.TryInsert(TKey key, TValue value, InsertionBehavior behavior)
   at System.Collections.Generic.Dictionary`2.AddRange(IEnumerable`1 collection)
   at Elastic.Apm.OpenTelemetry.ElasticActivityListener.<get_ActivityStopped>b__21_0(Activity activity)
   at System.Diagnostics.SynchronizedList`1.EnumWithAction(Action`2 action, Object arg)
   at System.Diagnostics.Activity.Stop()
   at System.Diagnostics.Activity.Dispose()
   at Azure.Core.Pipeline.DiagnosticScope.ActivityAdapter.Dispose()
   at Azure.Core.Pipeline.DiagnosticScope.Dispose()
   at Azure.Core.Pipeline.RequestActivityPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
   at Azure.Core.Pipeline.ResponseBodyPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
   at Azure.Core.Pipeline.BearerTokenAuthenticationPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
   at Azure.Core.Pipeline.RedirectPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
   at Azure.Core.Pipeline.RetryPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
   at Azure.Core.Pipeline.RetryPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
   at Azure.Core.Pipeline.HttpPipeline.SendRequestAsync(Request request, CancellationToken cancellationToken)
   at Azure.Security.KeyVault.Keys.Cryptography.KeyResolver.GetKeyAsync(Uri keyId, CancellationToken cancellationToken)
   at Azure.Security.KeyVault.Keys.Cryptography.KeyResolver.ResolveAsync(Uri keyId, CancellationToken cancellationToken)
   at Azure.Security.KeyVault.Keys.Cryptography.KeyResolver.Azure.Core.Cryptography.IKeyEncryptionKeyResolver.ResolveAsync(String keyId, CancellationToken cancellationToken)
   at Azure.Extensions.AspNetCore.DataProtection.Keys.AzureKeyVaultXmlEncryptor.EncryptAsync(XElement plaintextElement)
   at Azure.Extensions.AspNetCore.DataProtection.Keys.AzureKeyVaultXmlEncryptor.Encrypt(XElement plaintextElement)
   at Microsoft.AspNetCore.DataProtection.XmlEncryption.XmlEncryptionExtensions.EncryptIfNecessary(IXmlEncryptor encryptor, XElement element)
   at Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager.Microsoft.AspNetCore.DataProtection.KeyManagement.Internal.IInternalXmlKeyManager.CreateNewKey(Guid keyId, DateTimeOffset creationDate, DateTimeOffset activationDate, DateTimeOffset expirationDate)
   at Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager.CreateNewKey(DateTimeOffset activationDate, DateTimeOffset expirationDate)
   at Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider.CreateCacheableKeyRingCore(DateTimeOffset now, IKey keyJustAdded)
   at Microsoft.AspNetCore.DataProtection.KeyManagement.KeyRingProvider.GetCurrentKeyRingCore(DateTime utcNow, Boolean forceRefresh)

I tried reproducing this error by getting the agent source and debugging the code. The data that was being added was:

Origin of the error

The source ode reference: ElasticActivityListener.cs line 157

The data that was added to the dictionary (duplicate error.key Key)

To Reproduce

1. Install and configure your elastic .net core agent (Using package Elastic.Apm.NetCoreAll)
2. Have DataProtection configured with EfCore storage and AzureKeyVault encription
3. Try to start your application and notice the error.

This is not related to Azure Key Vault only. Similar behavior was noticed when using Service bus to create a subscription for a topic.

Expected behavior

It's not clear why those keys are duplicated. Maybe they should be checked first before adding.

Actual behavior

The asp.net core request pipeline keeps crashing.

[ThomasHeijtink]

Was this problem solved in version 1.25.1? Or was that for another bug fix? One of main concerns here is that in interferes with normal code execution. A package like this should never alter the application flow. There should be a global catch to prevent the normal operations from failing and produce a logging error elsewhere.

[aodpi]

I've tested this out with version 1.25.1 and it still reproduces. unfortunately it was not fixed. I ended up setting "OpenTelemetryBridgeEnabled": false in my APM configuration, with this set to false everything works as expected.

[zhangpengchen]

We encountered the same issue since last Friday, Elastic.Apm.NetCoreAll version 1.25.1

The error message:
An item with the same key has already been added. Key: error.type

The stack trace:

at System.Collections.Generic.Dictionary`2.TryInsert(TKey key, TValue value, InsertionBehavior behavior)\r\n   at System.Collections.Generic.Dictionary`2.AddRange(IEnumerable`1 collection)\r\n   at Elastic.Apm.OpenTelemetry.ElasticActivityListener.UpdateSpan(Activity activity, Span span)\r\n   at Elastic.Apm.OpenTelemetry.ElasticActivityListener.<get_ActivityStopped>b__21_0(Activity activity)\r\n   at System.Diagnostics.ActivitySource.<>c.<NotifyActivityStop>b__25_0(ActivityListener listener, Object obj)\r\n   at System.Diagnostics.SynchronizedList`1.EnumWithAction(Action`2 action, Object arg)\r\n   at System.Diagnostics.Activity.Stop()\r\n   at System.Diagnostics.Activity.Dispose()\r\n   at Azure.Core.Pipeline.DiagnosticScope.ActivityAdapter.Dispose()\r\n

The source code reference:

apm-agent-dotnet/src/Elastic.Apm/OpenTelemetry/ElasticActivityListener.cs

Line 192 in c3525df

span.Otel.Attributes = new Dictionary<string, object>(activity.TagObjects);

An issue was reported and fixed two weeks ago in azure-sdk-for-net, but has not yet been released.
OTel: Fix duplicated attributes and suppression Azure/azure-sdk-for-net#40027
RequestActivityPolicy adds error.type twice

According to lmolkova Activity.TagObjects are not guaranteed to be unique and this code will keep breaking in other cases:
Azure/azure-sdk-for-net#40172 (comment)

[ThomasHeijtink]

@zhangpengchen thanks for the update and reference. Although I agree this might fix this problem. But it doesn't solve the fact that a telemetry function of the app can break the normal app flow. This shouldn't be the case. This exception should have been caught and logged as error.

[Nekon0me]

I faced the similar issue but in my case exception was suppressed and I can found them only during dump analyzing.

Well, this exceptions don't affect any business functions and stability, but at in several hours of work thousands of them appears and I'm afraid it's affect performance.

Elastic.Apm.NetCoreAll 1.25.1
.Net 6.0