[Performance] added SpanAttributes.Add(string,object) method for deferred string-ification

[Aaronontheweb]

Changes

This is a performance fix aimed at making it possible to defer string-ification of complex types until the Activity is being processed by the OTel pipeline.

This type of performance work is possible when working directly on System.Diagnostics.ActivityTagsCollection, but not when working with OpenTelemetry.Api.Trace.SpanAttributes.

Merge requirement checklist

• CONTRIBUTING guidelines followed (nullable enabled, static analysis, etc.)
• Unit tests added/updated
• Appropriate CHANGELOG.md files updated for non-trivial changes
• Changes in public API reviewed (if applicable)

[Aaronontheweb]

Not sure if this needs a CHANGELOG.md addition - let me know if that's the case.

[codecov]

Codecov Report

Merging #4672 (55b9a52) into main (67bd46d) will decrease coverage by 0.03%.
The diff coverage is 100.00%.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #4672      +/-   ##
==========================================
- Coverage   85.08%   85.05%   -0.03%     
==========================================
  Files         314      314              
  Lines       12725    12727       +2     
==========================================
- Hits        10827    10825       -2     
- Misses       1898     1902       +4     

Impacted Files	Coverage Δ
src/OpenTelemetry.Api/Trace/SpanAttributes.cs	100.00% <100.00%> (ø)

... and 2 files with indirect coverage changes

[cijothomas]

what is the use case for this? Though Activity allow object type, OTel only allows a specific set of types here, which is already supported in this class.

[Aaronontheweb]

In this case, it was to be able to have an object rendered into a string out of band with the hot path being traced. I'm on mobile now so I can't provide a code sample, but you can already accomplish this by passing an IEnumerable of KV<string,object> into the constructor.

Exposing this method eliminates the need to do that and writes to the underlying collection.

[martinjt]

Having looked at the spec, it doesn't preclude SDKs from having this method, just that the others MUST exist. I don't see a reason that the .NET SDK can't have extra stuff that isn't in the base spec?

[utpilla]

I don't think we should be adding this overload for the following reasons:

1. You don't need a new API to defer the ToString() call. You should be able to use the existing SpanAttributes ctor that takes in an IEnumerable<KeyValuePair<string, object>> to directly pass in a complex type. Could you talk more about why this option wouldn't work for you?
2. Just because .NET's Activity API deviates from the spec by allowing an arbitrary object as an attribute value, doesn't mean we should give up on keeping the Span and related APIs conform to the spec.
3. What's the amount of perf improvement expected by this? Does the magnitude of perf improvement justify adding the new public API?

[alanwest]

If I were to base my opinion solely on the spec, I do not think we should add this overload to Add.

While the motivation for this PR is performance, my reason for approving it is not.

I approve for two reasons:

1. API consistency
   • As @Aaronontheweb highlights, I agree that since the constructor accepts a collection of KeyValuePair<string, object>s, it is awkward that there is no Add(string, object) method.
2. Historical decisions we have made with regards to handling span attributes
   • The Activity API allows for arbitrary object valued attributes.
   • We made the decision awhile ago that SDK components would export arbitrary object valued attributes, transforming them as necessary to a spec supported type (e.g., to a string).

However, with regards to performance, we discussed in today's meeting wanting to see some benchmarks. I agree benchmarks could be useful, particularly for any other users of the shim API.

[Aaronontheweb]

Since multiple comments have asked for benchmarks.

While working on our commercial library built on top of the OTEL API we conducted extensive performance testing, and "deferred stringification" was the most significant performance impact we made. Full post is here: https://petabridge.com/blog/phobos-2.4-opentelemetry-optimizations/

Original Code

Simplified this some, but this is what our span creation looks like around the hot path

private TelemetrySpan CreateActiveSpan(object underlyingMsg, SpanContext? context = null,
    Baggage baggage = default, bool followFromActiveSpan = true, long? startTimeUtcTicks = null)
{
    var startTime = startTimeUtcTicks != null
        ? new DateTimeOffset(startTimeUtcTicks.Value, TimeSpan.Zero)
        : DateTimeOffset.UtcNow;

    TelemetrySpan sp = null;
    if (context == null)
    {
        sp = Tracer.StartRootSpan(underlyingMsg.GetType().GetOperationName(),
            SpanKind.Consumer, InitialAttributes, startTime: startTime);
            
        Tracer.WithSpan(sp); // mark the current span as active
    }
    else
    {
        sp = Tracer.StartActiveSpan(underlyingMsg.GetType().GetOperationName(),
            SpanKind.Consumer, parentContext: context.Value, InitialAttributes, startTime: startTime);
    }

    if (startTimeUtcTicks != null)
    {
        sp.AddEvent("waiting", startTime);
    }
    var attributes = new SpanAttributes();
    attributes.Add("content", underlyingMsg.ToString());
    sp.AddEvent("message", attributes);

    return sp;
}

Original benchmark values

BenchmarkDotNet v0.13.6, Windows 11 (10.0.22621.1992/22H2/2022Update/SunValley2)
12th Gen Intel Core i7-1260P, 1 CPU, 16 logical and 12 physical cores
.NET SDK 7.0.302
  [Host]     : .NET 7.0.5 (7.0.523.17405), X64 RyuJIT AVX2
  DefaultJob : .NET 7.0.5 (7.0.523.17405), X64 RyuJIT AVX2

Method	MessageKind	Mean	Error	StdDev	Req/sec	Gen0	Allocated
CreateNewRootSpan	Primitive	119.1 ns	2.17 ns	2.03 ns	8,399,591.08	0.0246	232 B
CreateChildSpan	Primitive	123.8 ns	2.47 ns	2.42 ns	8,076,859.69	0.0246	232 B
CreateChildSpanWithBaggage	Primitive	122.3 ns	2.18 ns	2.04 ns	8,179,444.13	0.0246	232 B
CreateNewRootSpan	Class	164.4 ns	2.80 ns	2.62 ns	6,081,681.47	0.0348	328 B
CreateChildSpan	Class	170.2 ns	1.94 ns	1.72 ns	5,873,753.13	0.0348	328 B
CreateChildSpanWithBaggage	Class	169.6 ns	3.17 ns	2.97 ns	5,896,706.30	0.0348	328 B
CreateNewRootSpan	Record	222.3 ns	4.48 ns	5.50 ns	4,497,668.25	0.0730	688 B
CreateChildSpan	Record	222.9 ns	4.27 ns	4.75 ns	4,485,591.41	0.0730	688 B
CreateChildSpanWithBaggage	Record	226.7 ns	2.80 ns	2.48 ns	4,411,065.79	0.0730	688 B

As you can see - both the memory allocation in the hot path AND the end to end latency changes with the type of message being processed:

• Primitive is just a string - and its object.ToString() call is a no-op;
• Class is a simple class that uses an overridden object.ToString() implementation that uses string interpolation to print out all of the field values.
• Record is a record implementation of the same structure as the class, but uses record's built-in ToString() method which is rather expensive (relies on StringBuilders et al internally.)

New code

This code uses the existing public OTEL APIs - I allocate an additional IEnumerable<KeyValuePair<string, object>> and pass these into the CTOR of SpanAttributes. However, there's at least two areas where we pass in InitialSpanAttributes to a TelemeterySpan where adding a AddAttribute(string, object) would benefit even more. Plus adding that method allows me to eliminate an additional enumerator:

// rest of  CreateActiveSpan method
static IEnumerable<KeyValuePair<string, object>> CreateSpanAttributes(object msg)
{
    yield return new KeyValuePair<string, object>("content", msg);
}

var attributes = new SpanAttributes(CreateSpanAttributes(underlyingMsg));
sp.AddEvent("message", attributes);

return sp;

Updated benchmark values

BenchmarkDotNet v0.13.6, Windows 11 (10.0.22621.1992/22H2/2022Update/SunValley2)
12th Gen Intel Core i7-1260P, 1 CPU, 16 logical and 12 physical cores
.NET SDK 7.0.302
  [Host]     : .NET 7.0.5 (7.0.523.17405), X64 RyuJIT AVX2
  DefaultJob : .NET 7.0.5 (7.0.523.17405), X64 RyuJIT AVX2

Method	MessageKind	Mean	Error	StdDev	Req/sec	Gen0	Allocated
CreateNewRootSpan	Primitive	152.0 ns	2.58 ns	2.42 ns	6,580,292.48	0.0322	304 B
CreateChildSpan	Primitive	149.7 ns	1.98 ns	1.85 ns	6,681,595.57	0.0322	304 B
CreateChildSpanWithBaggage	Primitive	150.3 ns	2.71 ns	2.53 ns	6,653,843.06	0.0322	304 B
CreateNewRootSpan	Class	150.1 ns	2.74 ns	2.29 ns	6,660,638.95	0.0322	304 B
CreateChildSpan	Class	149.1 ns	2.38 ns	2.11 ns	6,704,915.73	0.0322	304 B
CreateChildSpanWithBaggage	Class	151.2 ns	2.87 ns	2.69 ns	6,613,827.37	0.0322	304 B
CreateNewRootSpan	Record	147.8 ns	2.80 ns	2.62 ns	6,766,604.10	0.0322	304 B
CreateChildSpan	Record	147.0 ns	2.75 ns	2.57 ns	6,801,670.75	0.0322	304 B
CreateChildSpanWithBaggage	Record	149.7 ns	2.87 ns	2.95 ns	6,678,899.59	0.0322	304 B

Default memory allocations go up for the primitive case, but otherwise the hot-path's memory consumption and latency is now consistent regardless of the input data type - this is because the expensive operation of rendering the string now happens out-of-band inside the OTEL processing / export pipeline instead.

If you'd like me to add a version of this benchmark to this PR, I'd be happy to do it - but these are our numbers demonstrating that the techique of deferring string-ification is conducive to better performance. Adding the overload I've included in this PR will make it easier to do that.

[utpilla]

Since multiple comments have asked for benchmarks.

We would ideally like to see two minimal benchmarks (code and results) which ONLY target the creation of SpanAttributes and NOT the creation of Span:

• one which creates the SpanAttributes using the existing ctor
• one which creates the SpanAttributes using the proposed API

I allocate an additional IEnumerable<KeyValuePair<string, object>> and pass these into the CTOR of SpanAttributes.

This should be a one-time allocation. You don't need to allocate this repeatedly on the hot-path. For your example, you could probably get better results by creating an array or a list and reusing it.

private KeyValuePair<string, object>[] initialAttributes = new KeyValuePair<string, object>[1] { new("content", "TBD") };

private TelemetrySpan CreateActiveSpan(object underlyingMsg, SpanContext? context = null,
    Baggage baggage = default, bool followFromActiveSpan = true, long? startTimeUtcTicks = null)
{
 
    // rest of  CreateActiveSpan method

    initialAttributes[0] = new KeyValuePair<string, object>("content", underlyingMsg);
    var attributes = new SpanAttributes(initialAttributes);

    attributes.Add("content", underlyingMsg.ToString());

    sp.AddEvent("message", attributes);

    return sp;
}

However, there's at least two areas where we pass in InitialSpanAttributes to a TelemeterySpan where adding a AddAttribute(string, object) would benefit even more.

Could you elaborate more on these scenarios which cannot be achieved using the existing APIs?

[Aaronontheweb]

No, has to be allocated every time as this value is dynamic per-call

Edit: Ah, I see what you mean - I'll check that out.

I'll add a benchmark

[github-actions]

This PR was marked stale due to lack of activity and will be closed in 7 days. Commenting or Pushing will instruct the bot to automatically remove the label. This bot runs once per day.

[github-actions]

Closed as inactive. Feel free to reopen if this PR is still being worked on.