Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We鈥檒l occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Trace Exporters] Remove enumeration helper and use new net7 enumeration APIs #3580

Merged
merged 13 commits into from
Aug 18, 2022

Conversation

CodeBlanch
Copy link
Member

@CodeBlanch CodeBlanch commented Aug 16, 2022

馃コ

Also updated OtlpExporter to send "dropped counts" when attributes limits are being used. CHANGELOG note added for that.

@CodeBlanch CodeBlanch requested a review from a team as a code owner August 16, 2022 19:49
<Compile Include="$(RepoRoot)\src\OpenTelemetry.Api\Internal\Guard.cs" Link="Includes\Guard.cs" />
<Compile Include="$(RepoRoot)\src\OpenTelemetry\Internal\EnvironmentVariableHelper.cs" Link="Includes\EnvironmentVariableHelper.cs" />
<Compile Include="$(RepoRoot)\src\OpenTelemetry\Internal\OpenTelemetrySdkEventSource.cs" Link="Includes\OpenTelemetrySdkEventSource.cs" />
<Compile Include="$(RepoRoot)\src\OpenTelemetry\Internal\PeriodicExportingMetricReaderHelper.cs" Link="Includes\PeriodicExportingMetricReaderHelper.cs" />
<Compile Include="$(RepoRoot)\src\OpenTelemetry\Internal\PooledList.cs" Link="Includes\PooledList.cs" />
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@alanwest FYI I removed the pool usage from OtlpExpoter. We were writing to the pool and then copying onto the span DTO thing. Didn't seem to be adding a whole lot of value and taking time to do the copy. What would be much better is to pool the repeated field instances. Not sure if that is possible. TODO 馃槃

@codecov
Copy link

codecov bot commented Aug 16, 2022

Codecov Report

Merging #3580 (0acdb33) into main (245c2b3) will decrease coverage by 0.05%.
The diff coverage is 99.32%.

Impacted file tree graph

@@            Coverage Diff             @@
##             main    #3580      +/-   ##
==========================================
- Coverage   87.43%   87.37%   -0.06%     
==========================================
  Files         278      277       -1     
  Lines       10088     9931     -157     
==========================================
- Hits         8820     8677     -143     
+ Misses       1268     1254      -14     
Impacted Files Coverage 螖
....Jaeger/Implementation/JaegerActivityExtensions.cs 95.83% <97.14%> (+0.21%) 猬嗭笍
...Telemetry.Api/Internal/ActivityHelperExtensions.cs 100.00% <100.00%> (酶)
src/OpenTelemetry.Api/Internal/StatusHelper.cs 100.00% <100.00%> (酶)
...metryProtocol/Implementation/ActivityExtensions.cs 96.15% <100.00%> (+1.64%) 猬嗭笍
...plementation/ZipkinActivityConversionExtensions.cs 99.14% <100.00%> (+0.02%) 猬嗭笍
...ZPages/Implementation/ZPagesExporterEventSource.cs 56.25% <0.00%> (-6.25%) 猬囷笍
src/OpenTelemetry/Internal/PooledList.cs 94.00% <0.00%> (-6.00%) 猬囷笍
...tpListener/Internal/PrometheusCollectionManager.cs 78.04% <0.00%> (-2.44%) 猬囷笍
... and 6 more

@@ -11,6 +11,5 @@

<ItemGroup>
<PackageReference Include="System.Diagnostics.DiagnosticSource" Version="$(SystemDiagnosticSourcePkgVer)" />
<PackageReference Include="System.Reflection.Emit.Lightweight" Version="$(SystemReflectionEmitLightweightPkgVer)" />
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

馃コ

@@ -83,7 +83,7 @@ public void Equality()
Assert.True(link1.Equals(link3));
}

[Fact]
[Fact(Skip = "ActivityLink.Equals is broken in DS7 preview: https://github.com/dotnet/runtime/issues/74026")]
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

馃檲 馃檳 馃檴

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

FYI dotnet/dotnet-api-docs#8316

We discussed it internally and essentially no one is sure what it means for two ActivityLinks to be equal so we're going to leave it broken/undefined.


PooledList<ZipkinAnnotation>.Add(ref this.Annotations, new ZipkinAnnotation(activityEvent.Timestamp.ToEpochMicroseconds(), activityEvent.Name));
do
Copy link
Member

@alanwest alanwest Aug 17, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I love a good do/while... though maybe use gotos here instead? :trollface:

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The funny thing is goto, while, do/while none of that really exists it is all jumps at the end of the day 馃ぃ PS: I did it this way to avoid having to check this.Created each time an item is processed in the inner loop.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's all just 1s and 0s at the end of the day... And even then 1s and 0s are a fiction. What's the meaning of life? How can we even be sure that this.Created?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@alanwest I guess we would know it all when this.Disposed 馃榾

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should start OpenTelemetry Quantum SIG. Stuff doesn't exist until you observe it, right?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should start OpenTelemetry Quantum SIG.

I'm in, happy to sponsor it 馃槅

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm in, happy to sponsor it 馃槅

Can you get Scott Bakula to co-sponsor?

p7894024_b_h9_aa

Copy link
Member

@alanwest alanwest left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice work driving this through both on the OTel side and .NET side of things! 馃帀

I assume the benchmarks would be roughly the same before/after this PR?

@CodeBlanch
Copy link
Member Author

CodeBlanch commented Aug 18, 2022

@alanwest Let me run the benchmarks to make sure no allocations snuck in and I'll post the results. Should also be faster (might not be measurable) just due to tighter loops without a call through the enumeration helper + check for bool result to see if enumeration should break.

@CodeBlanch
Copy link
Member Author

Jaeger benchmarks:

(What this benchmark tests is that Jaeger reserves its memory and then reuses it for subsequent calls. Allocations should stay flat no matter the number of export calls.)

Before

Method NumberOfBatches NumberOfSpans Mean Error StdDev Allocated
JaegerExporter_Batching 1 10000 30.81 ms 0.066 ms 0.062 ms 16 KB
JaegerExporter_Batching 10 10000 301.86 ms 1.151 ms 1.021 ms 18 KB
JaegerExporter_Batching 100 10000 3,073.62 ms 46.019 ms 40.795 ms 18 KB

After

Method NumberOfBatches NumberOfSpans Mean Error StdDev Allocated
JaegerExporter_Batching 1 10000 29.88 ms 0.142 ms 0.126 ms 16 KB
JaegerExporter_Batching 10 10000 297.06 ms 1.300 ms 1.153 ms 18 KB
JaegerExporter_Batching 100 10000 3,021.04 ms 19.152 ms 14.952 ms 18 KB

@CodeBlanch
Copy link
Member Author

Zipkin benchmarks:

(I am offended by how greedy Zipkin is with its allocations! 馃槺 This can be improved, which I will take as a TODO. The important thing is, no change as a result of this PR.)

Before

Method NumberOfBatches NumberOfSpans Mean Error StdDev Median Completed Work Items Lock Contentions Gen 0 Gen 1 Allocated
ZipkinExporter_Batching 1 10000 42.51 ms 0.747 ms 0.699 ms 42.61 ms 4.0000 - 142.8571 - 2 MB
ZipkinExporter_Batching 10 10000 406.07 ms 8.039 ms 17.646 ms 412.61 ms 14.0000 - 1000.0000 - 17 MB
ZipkinExporter_Batching 100 10000 4,132.82 ms 10.160 ms 9.503 ms 4,128.53 ms 104.0000 - 14000.0000 1000.0000 169 MB

After

Method NumberOfBatches NumberOfSpans Mean Error StdDev Completed Work Items Lock Contentions Gen 0 Gen 1 Allocated
ZipkinExporter_Batching 1 10000 37.42 ms 0.134 ms 0.118 ms 4.0714 - 142.8571 - 2 MB
ZipkinExporter_Batching 10 10000 368.16 ms 2.066 ms 1.832 ms 13.0000 - 1000.0000 - 17 MB
ZipkinExporter_Batching 100 10000 3,653.48 ms 17.635 ms 14.726 ms 103.0000 - 14000.0000 1000.0000 169 MB

@CodeBlanch
Copy link
Member Author

CodeBlanch commented Aug 18, 2022

OTLP benchmarks:

(Some nice gains here* but the memory usage is still extremely high. By the way, it is not fair to compare the time of this benchmark against Jaeger or Zipkin above. OtlpExporter is not faster. The OtlpExporter benchmark mocks the whole call into Protobuf which owns the serialization phase. Jaeger and Zipkin benchmarks actually measure the serialization too. Safe to say OtlpExporter is slower and it likely also uses more memory than what the benchmark sees!)

Before

Method NumberOfBatches NumberOfSpans Mean Error StdDev Median Gen 0 Gen 1 Gen 2 Allocated
OtlpExporter_Batching 1 10000 36.73 ms 0.699 ms 1.902 ms 35.98 ms 2076.9231 1153.8462 384.6154 22 MB
OtlpExporter_Batching 10 10000 366.33 ms 7.284 ms 15.042 ms 364.83 ms 21000.0000 12000.0000 4000.0000 217 MB
OtlpExporter_Batching 100 10000 4,017.00 ms 71.843 ms 59.992 ms 4,014.98 ms 224000.0000 133000.0000 44000.0000 2,167 MB

After

Method NumberOfBatches NumberOfSpans Mean Error StdDev Gen 0 Gen 1 Gen 2 Allocated
OtlpExporter_Batching 1 10000 21.05 ms 0.258 ms 0.242 ms 1531.2500 781.2500 343.7500 18 MB
OtlpExporter_Batching 10 10000 221.46 ms 3.872 ms 7.176 ms 16000.0000 8000.0000 2000.0000 182 MB
OtlpExporter_Batching 100 10000 2,086.82 ms 26.596 ms 24.878 ms 153000.0000 77000.0000 37000.0000 1,824 MB

* The perf gains are due to the removal of PooledList<T> usage from OtlpExporter. PooledList<T> is not necessarily bad but how Protobuf was interacting with it was causing a lot of waste. This...

    public sealed class RepeatedField<T>
    {
        public void AddRange(IEnumerable<T> values)
        {
            ProtoPreconditions.CheckNotNull(values, nameof(values));

            // Optimization 1: If the collection we're adding is already a RepeatedField<T>,
            // we know the values are valid.
            var otherRepeatedField = values as RepeatedField<T>;
            if (otherRepeatedField != null)
            {
                EnsureSize(count + otherRepeatedField.count);
                Array.Copy(otherRepeatedField.array, 0, array, count, otherRepeatedField.count);
                count += otherRepeatedField.count;
                return;
            }

            // Optimization 2: The collection is an ICollection, so we can expand
            // just once and ask the collection to copy itself into the array.
            var collection = values as ICollection;
            if (collection != null)
            {
                var extraCount = collection.Count;
                // For reference types and nullable value types, we need to check that there are no nulls
                // present. (This isn't a thread-safe approach, but we don't advertise this is thread-safe.)
                // We expect the JITter to optimize this test to true/false, so it's effectively conditional
                // specialization.
                if (default(T) == null)
                {
                    // TODO: Measure whether iterating once to check and then letting the collection copy
                    // itself is faster or slower than iterating and adding as we go. For large
                    // collections this will not be great in terms of cache usage... but the optimized
                    // copy may be significantly faster than doing it one at a time.
                    foreach (var item in collection)
                    {
                        if (item == null)
                        {
                            throw new ArgumentException("Sequence contained null element", nameof(values));
                        }
                    }
                }
                EnsureSize(count + extraCount);
                collection.CopyTo(array, count);
                count += extraCount;
                return;
            }

            // We *could* check for ICollection<T> as well, but very very few collections implement
            // ICollection<T> but not ICollection. (HashSet<T> does, for one...)

            // Fall back to a slower path of adding items one at a time.
            foreach (T item in values)
            {
                Add(item);
            }
        }
    }

Issues...

  • IEnumerable<T> boxes the struct PooledList<T> and its enumerator. Leads to allocations.
  • In the ICollection path Protobuf enumerates the source to look for null entries. That is a lot of CPU waste because we have already validated everything added.
  • Just universally speaking, adding things to one array and copying them to another array is going to be slower than adding them to the final array directly 馃槃

@CodeBlanch CodeBlanch merged commit 409b61d into open-telemetry:main Aug 18, 2022
@CodeBlanch CodeBlanch deleted the enumeration-api-updates branch August 18, 2022 22:02
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants