[Profiler] Allow tests for .NET Framework

chrisnas commented 2 months ago

Summary of changes

Record and replay ETW events received by the Datadog agent.

Reason for change

Since ETW events sent by the .NET Framework are proxied by the Datadog agent, it is needed to mock this data exchange in integration tests.

Implementation details

events are recorded by the existing tooling to easily build serialized events files
events are replayed by a new C# tool using classes that will be used by the integration tests

Test coverage

manual for the tooling
new integration tests for .NET framework

Other details

andrewlock commented 2 months ago

Execution-Time Benchmarks Report :stopwatch:

Execution-time results for samples comparing the following branches/commits:

Execution-time benchmarks measure the whole time it takes to execute a program. And are intended to measure the one-off costs. Cases where the execution time results for the PR are worse than latest master results are shown in red. The following thresholds were used for comparing the execution times:

Welch test with statistical test for significance of 5%
Only results indicating a difference greater than 5% and 5 ms are considered.

Note that these results are based on a single point-in-time result for each branch. For full results, see the dashboard.

Graphs show the p99 interval based on the mean and StdDev of the test run, as well as the mean value of the run (shown as a diamond below the graph).

gantt
    title Execution time (ms) FakeDbCommand (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5948) - mean (70ms)  : 67, 72
     .   : milestone, 70,
    master - mean (70ms)  : 67, 73
     .   : milestone, 70,

    section CallTarget+Inlining+NGEN
    This PR (5948) - mean (1,113ms)  : 1094, 1131
     .   : milestone, 1113,
    master - mean (1,115ms)  : 1086, 1144
     .   : milestone, 1115,

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5948) - mean (109ms)  : 107, 112
     .   : milestone, 109,
    master - mean (110ms)  : 105, 114
     .   : milestone, 110,

    section CallTarget+Inlining+NGEN
    This PR (5948) - mean (770ms)  : 754, 786
     .   : milestone, 770,
    master - mean (771ms)  : 753, 789
     .   : milestone, 771,

gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5948) - mean (92ms)  : 89, 95
     .   : milestone, 92,
    master - mean (92ms)  : 89, 95
     .   : milestone, 92,

    section CallTarget+Inlining+NGEN
    This PR (5948) - mean (727ms)  : 711, 743
     .   : milestone, 727,
    master - mean (727ms)  : 712, 742
     .   : milestone, 727,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5948) - mean (189ms)  : 187, 191
     .   : milestone, 189,
    master - mean (189ms)  : 185, 193
     .   : milestone, 189,

    section CallTarget+Inlining+NGEN
    This PR (5948) - mean (1,190ms)  : 1166, 1213
     .   : milestone, 1190,
    master - mean (1,201ms)  : 1172, 1230
     .   : milestone, 1201,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5948) - mean (275ms)  : 270, 280
     .   : milestone, 275,
    master - mean (274ms)  : 269, 278
     .   : milestone, 274,

    section CallTarget+Inlining+NGEN
    This PR (5948) - mean (936ms)  : 919, 954
     .   : milestone, 936,
    master - mean (938ms)  : 918, 958
     .   : milestone, 938,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5948) - mean (263ms)  : 260, 266
     .   : milestone, 263,
    master - mean (263ms)  : 259, 267
     .   : milestone, 263,

    section CallTarget+Inlining+NGEN
    This PR (5948) - mean (922ms)  : 904, 940
     .   : milestone, 922,
    master - mean (923ms)  : 905, 940
     .   : milestone, 923,

datadog-ddstaging[bot] commented 2 months ago

Datadog Report

Branch report: chrisnas/tests_for_framework Commit report: c6022d1 Test service: dd-trace-dotnet

:x: 5 Failed (0 Known Flaky), 164683 Passed, 1270 Skipped, 11h 39m 54.76s Total Time

:x: Failed Tests (5)

ShouldGetAllocationSamplesViaEtw - Datadog.Profiler.IntegrationTests.Allocations.AllocationsProfilerTest - Details

Expand for error
``` The test Samples.Computer01 is running for too long or was lost ```
ShouldGetAllocationSamplesViaEtw - Datadog.Profiler.IntegrationTests.Allocations.AllocationsProfilerTest - Details

Expand for error
``` The test Samples.Computer01 is running for too long or was lost ```
ShouldGetLockContentionSamplesViaEtw - Datadog.Profiler.IntegrationTests.Contention.ContentionProfilerTest - Details

Expand for error
``` The test Samples.Computer01 is running for too long or was lost ```
ShouldGetLockContentionSamplesViaEtw - Datadog.Profiler.IntegrationTests.Contention.ContentionProfilerTest - Details

Expand for error
``` The test Samples.Computer01 is running for too long or was lost ```
ShouldGetGarbageCollectionSamplesViaEtw - Datadog.Profiler.IntegrationTests.GarbageCollections.GarbageCollectionsProfilerTest - Details

Expand for error
``` Actual: Falseilure ```

andrewlock commented 2 months ago

Benchmarks Report for tracer :snail:

Benchmarks for #5948 compared to master:

1 benchmarks are faster, with geometric mean 1.181
1 benchmarks have fewer allocations

The following thresholds were used for comparing the benchmark speeds:

Mann–Whitney U test with statistical test for significance of 5%
Only results indicating a difference greater than 10% and 0.3 ns are considered.

Allocation changes below 0.5% are ignored.

Benchmark details

Benchmarks.Trace.ActivityBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartStopWithChild`|net6.0|7.91μs|42.9ns|235ns|0.0114| 0.00379|0|5.42 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartStopWithChild`|netcoreapp3.1|9.92μs|48.3ns|241ns|0.0151| 0.00504|0|5.62 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartStopWithChild`|net472|16.6μs|57.2ns|221ns|1.03| 0.32|0.0984|6.07 KB| |#5948|`StartStopWithChild`|net6.0|7.74μs|44.2ns|325ns|0.0117| 0.00391|0|5.43 KB| |#5948|`StartStopWithChild`|netcoreapp3.1|9.98μs|51.6ns|258ns|0.0189| 0.00947|0|5.62 KB| |#5948|`StartStopWithChild`|net472|16.7μs|56ns|217ns|1.01| 0.295|0.0902|6.06 KB|

Benchmarks.Trace.AgentWriterBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`WriteAndFlushEnrichedTraces`|net6.0|470μs|141ns|527ns|0| 0|0|2.7 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`WriteAndFlushEnrichedTraces`|netcoreapp3.1|630μs|460ns|1.78μs|0| 0|0|2.7 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`WriteAndFlushEnrichedTraces`|net472|841μs|474ns|1.84μs|0.417| 0|0|3.3 KB| |#5948|`WriteAndFlushEnrichedTraces`|net6.0|489μs|166ns|642ns|0| 0|0|2.7 KB| |#5948|`WriteAndFlushEnrichedTraces`|netcoreapp3.1|643μs|384ns|1.49μs|0| 0|0|2.7 KB| |#5948|`WriteAndFlushEnrichedTraces`|net472|846μs|611ns|2.12μs|0.422| 0|0|3.3 KB|

Benchmarks.Trace.AspNetCoreBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendRequest`|net6.0|195μs|1.13μs|9.01μs|0.152| 0|0|18.45 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendRequest`|netcoreapp3.1|221μs|1.12μs|7.26μs|0.215| 0|0|20.61 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendRequest`|net472|0.0003ns|0.0003ns|0.00108ns|0| 0|0|0 b| |#5948|`SendRequest`|net6.0|193μs|1.08μs|7.23μs|0.18| 0|0|18.45 KB| |#5948|`SendRequest`|netcoreapp3.1|210μs|1.16μs|6.89μs|0.211| 0|0|20.61 KB| |#5948|`SendRequest`|net472|0.000751ns|0.000354ns|0.00137ns|0| 0|0|0 b|

Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed :heavy_check_mark: Fewer allocations :tada: #### Fewer allocations :tada: in #5948 | Benchmark | Base Allocated | Diff Allocated | Change | Change % | |:----------|-----------:|-----------:|--------:|--------:| | Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0 | 41.82 KB | 41.5 KB | -318 B | -0.76%

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`WriteAndFlushEnrichedTraces`|net6.0|570μs|2.48μs|9.26μs|0.566| 0|0|41.82 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`WriteAndFlushEnrichedTraces`|netcoreapp3.1|670μs|1.97μs|7.11μs|0.331| 0|0|41.8 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`WriteAndFlushEnrichedTraces`|net472|879μs|3.88μs|14.5μs|8.25| 2.6|0.434|53.28 KB| |#5948|`WriteAndFlushEnrichedTraces`|net6.0|553μs|2.28μs|9.65μs|0.543| 0|0|41.5 KB| |#5948|`WriteAndFlushEnrichedTraces`|netcoreapp3.1|664μs|1.61μs|5.81μs|0.329| 0|0|41.6 KB| |#5948|`WriteAndFlushEnrichedTraces`|net472|852μs|3.55μs|13.8μs|8.36| 2.64|0.44|53.31 KB|

Benchmarks.Trace.DbCommandBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`ExecuteNonQuery`|net6.0|1.26μs|0.68ns|2.54ns|0.0143| 0|0|1.02 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`ExecuteNonQuery`|netcoreapp3.1|1.73μs|0.85ns|3.29ns|0.0139| 0|0|1.02 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`ExecuteNonQuery`|net472|2.14μs|1.57ns|5.87ns|0.156| 0|0|987 B| |#5948|`ExecuteNonQuery`|net6.0|1.2μs|1.24ns|4.81ns|0.0144| 0|0|1.02 KB| |#5948|`ExecuteNonQuery`|netcoreapp3.1|1.86μs|1.19ns|4.63ns|0.013| 0|0|1.02 KB| |#5948|`ExecuteNonQuery`|net472|2.07μs|2.32ns|8.99ns|0.157| 0|0|987 B|

Benchmarks.Trace.ElasticsearchBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`CallElasticsearch`|net6.0|1.23μs|0.795ns|2.97ns|0.0135| 0|0|976 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`CallElasticsearch`|netcoreapp3.1|1.52μs|0.371ns|1.44ns|0.0133| 0|0|976 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`CallElasticsearch`|net472|2.46μs|2.4ns|9.29ns|0.158| 0|0|995 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`CallElasticsearchAsync`|net6.0|1.28μs|1.05ns|3.92ns|0.0134| 0|0|952 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`CallElasticsearchAsync`|netcoreapp3.1|1.63μs|0.434ns|1.62ns|0.0139| 0|0|1.02 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`CallElasticsearchAsync`|net472|2.62μs|1.77ns|6.63ns|0.166| 0|0|1.05 KB| |#5948|`CallElasticsearch`|net6.0|1.24μs|0.785ns|3.04ns|0.0135| 0|0|976 B| |#5948|`CallElasticsearch`|netcoreapp3.1|1.55μs|0.527ns|1.97ns|0.0132| 0|0|976 B| |#5948|`CallElasticsearch`|net472|2.66μs|0.997ns|3.6ns|0.158| 0|0|995 B| |#5948|`CallElasticsearchAsync`|net6.0|1.24μs|0.637ns|2.38ns|0.013| 0|0|952 B| |#5948|`CallElasticsearchAsync`|netcoreapp3.1|1.65μs|1.63ns|6.11ns|0.0132| 0|0|1.02 KB| |#5948|`CallElasticsearchAsync`|net472|2.64μs|1.67ns|6.45ns|0.166| 0|0|1.05 KB|

Benchmarks.Trace.GraphQLBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`ExecuteAsync`|net6.0|1.31μs|0.802ns|3ns|0.0131| 0|0|952 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`ExecuteAsync`|netcoreapp3.1|1.66μs|1.77ns|6.87ns|0.0129| 0|0|952 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`ExecuteAsync`|net472|1.77μs|1.43ns|5.55ns|0.145| 0|0|915 B| |#5948|`ExecuteAsync`|net6.0|1.27μs|0.613ns|2.29ns|0.0133| 0|0|952 B| |#5948|`ExecuteAsync`|netcoreapp3.1|1.62μs|0.669ns|2.41ns|0.0127| 0|0|952 B| |#5948|`ExecuteAsync`|net472|1.83μs|1.34ns|5.19ns|0.145| 0|0|915 B|

Benchmarks.Trace.HttpClientBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendAsync`|net6.0|4.05μs|2.49ns|9.66ns|0.0305| 0|0|2.22 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendAsync`|netcoreapp3.1|5.02μs|7.35ns|28.5ns|0.0379| 0|0|2.76 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendAsync`|net472|7.8μs|5.51ns|21.3ns|0.496| 0|0|3.15 KB| |#5948|`SendAsync`|net6.0|4.17μs|1.02ns|3.69ns|0.0313| 0|0|2.22 KB| |#5948|`SendAsync`|netcoreapp3.1|5μs|2.28ns|8.55ns|0.0376| 0|0|2.76 KB| |#5948|`SendAsync`|net472|7.8μs|2.26ns|8.75ns|0.496| 0|0|3.15 KB|

Benchmarks.Trace.ILoggerBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|net6.0|1.55μs|1.14ns|4.28ns|0.0228| 0|0|1.64 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|netcoreapp3.1|2.22μs|2.39ns|8.29ns|0.0219| 0|0|1.64 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|net472|2.8μs|1.59ns|6.16ns|0.25| 0|0|1.57 KB| |#5948|`EnrichedLog`|net6.0|1.57μs|0.629ns|2.44ns|0.0228| 0|0|1.64 KB| |#5948|`EnrichedLog`|netcoreapp3.1|2.17μs|0.739ns|2.66ns|0.022| 0|0|1.64 KB| |#5948|`EnrichedLog`|net472|2.69μs|0.846ns|3.28ns|0.249| 0|0|1.57 KB|

Benchmarks.Trace.Log4netBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|net6.0|118μs|218ns|846ns|0| 0|0|4.28 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|netcoreapp3.1|120μs|188ns|703ns|0| 0|0|4.28 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|net472|152μs|174ns|652ns|0.682| 0.227|0|4.46 KB| |#5948|`EnrichedLog`|net6.0|117μs|238ns|924ns|0| 0|0|4.28 KB| |#5948|`EnrichedLog`|netcoreapp3.1|122μs|94.5ns|341ns|0.0614| 0|0|4.28 KB| |#5948|`EnrichedLog`|net472|152μs|134ns|517ns|0.684| 0.228|0|4.46 KB|

Benchmarks.Trace.NLogBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|net6.0|3.05μs|1.03ns|3.97ns|0.0305| 0|0|2.2 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|netcoreapp3.1|4.12μs|1.81ns|6.51ns|0.0291| 0|0|2.2 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|net472|4.88μs|2.73ns|10.6ns|0.321| 0|0|2.02 KB| |#5948|`EnrichedLog`|net6.0|2.93μs|1.1ns|4.26ns|0.0306| 0|0|2.2 KB| |#5948|`EnrichedLog`|netcoreapp3.1|4.11μs|2.26ns|7.83ns|0.0287| 0|0|2.2 KB| |#5948|`EnrichedLog`|net472|4.8μs|1.02ns|3.83ns|0.319| 0|0|2.02 KB|

Benchmarks.Trace.RedisBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendReceive`|net6.0|1.39μs|0.528ns|2.05ns|0.016| 0|0|1.14 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendReceive`|netcoreapp3.1|1.75μs|0.688ns|2.66ns|0.0158| 0|0|1.14 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`SendReceive`|net472|2.1μs|1.24ns|4.79ns|0.183| 0.00104|0|1.16 KB| |#5948|`SendReceive`|net6.0|1.38μs|1.41ns|5.45ns|0.0159| 0|0|1.14 KB| |#5948|`SendReceive`|netcoreapp3.1|1.85μs|1.85ns|6.68ns|0.0157| 0|0|1.14 KB| |#5948|`SendReceive`|net472|2.14μs|1.51ns|5.84ns|0.183| 0|0|1.16 KB|

Benchmarks.Trace.SerilogBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|net6.0|2.81μs|3.25ns|12.6ns|0.0223| 0|0|1.6 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|netcoreapp3.1|3.94μs|1.57ns|6.1ns|0.0216| 0|0|1.65 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`EnrichedLog`|net472|4.37μs|2.2ns|8.24ns|0.323| 0|0|2.04 KB| |#5948|`EnrichedLog`|net6.0|2.75μs|1.04ns|4.04ns|0.0221| 0|0|1.6 KB| |#5948|`EnrichedLog`|netcoreapp3.1|3.98μs|3.04ns|11.4ns|0.0219| 0|0|1.65 KB| |#5948|`EnrichedLog`|net472|4.52μs|1.49ns|5.15ns|0.323| 0|0|2.04 KB|

Benchmarks.Trace.SpanBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartFinishSpan`|net6.0|424ns|0.206ns|0.796ns|0.00803| 0|0|576 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartFinishSpan`|netcoreapp3.1|592ns|0.537ns|2.08ns|0.00764| 0|0|576 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartFinishSpan`|net472|699ns|0.802ns|3.11ns|0.0915| 0|0|578 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartFinishScope`|net6.0|487ns|0.308ns|1.19ns|0.00978| 0|0|696 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartFinishScope`|netcoreapp3.1|759ns|1.24ns|4.47ns|0.00951| 0|0|696 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`StartFinishScope`|net472|880ns|0.891ns|3.45ns|0.104| 0|0|658 B| |#5948|`StartFinishSpan`|net6.0|407ns|0.284ns|1.1ns|0.00819| 0|0|576 B| |#5948|`StartFinishSpan`|netcoreapp3.1|562ns|0.515ns|2ns|0.0076| 0|0|576 B| |#5948|`StartFinishSpan`|net472|691ns|0.517ns|1.86ns|0.0918| 0|0|578 B| |#5948|`StartFinishScope`|net6.0|527ns|0.223ns|0.835ns|0.00981| 0|0|696 B| |#5948|`StartFinishScope`|netcoreapp3.1|735ns|0.453ns|1.76ns|0.00954| 0|0|696 B| |#5948|`StartFinishScope`|net472|928ns|0.578ns|2.16ns|0.105| 0|0|658 B|

Benchmarks.Trace.TraceAnnotationsBenchmark - Faster :tada: Same allocations :heavy_check_mark: #### Faster :tada: in #5948 | Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality | |:----------|-----------:|-----------:|--------:|--------:| | Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0 | 1.181 | 711.37 | 602.50 |

### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`RunOnMethodBegin`|net6.0|711ns|0.29ns|1.12ns|0.00964| 0|0|696 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`RunOnMethodBegin`|netcoreapp3.1|962ns|0.648ns|2.51ns|0.00947| 0|0|696 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/e94a4c3e264667306eab67959328866ed56f5b42)|`RunOnMethodBegin`|net472|1.19μs|1.16ns|4.48ns|0.104| 0|0|658 B| |#5948|`RunOnMethodBegin`|net6.0|602ns|0.413ns|1.55ns|0.00971| 0|0|696 B| |#5948|`RunOnMethodBegin`|netcoreapp3.1|943ns|0.493ns|1.91ns|0.00914| 0|0|696 B| |#5948|`RunOnMethodBegin`|net472|1.17μs|0.957ns|3.71ns|0.104| 0|0|658 B|

andrewlock commented 2 months ago

Throughput/Crank Report :zap:

Throughput results for AspNetCoreSimpleController comparing the following branches/commits:

Cases where throughput results for the PR are worse than latest master (5% drop or greater), results are shown in red.

Note that these results are based on a single point-in-time result for each branch. For full results, see one of the many, many dashboards!

gantt
    title Throughput Linux x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5948) (10.789M)   : 0, 10788919
    master (11.080M)   : 0, 11079748
    benchmarks/2.9.0 (11.081M)   : 0, 11080577

    section Automatic
    This PR (5948) (7.093M)   : 0, 7093114
    master (7.315M)   : 0, 7315317
    benchmarks/2.9.0 (7.732M)   : 0, 7732233

    section Trace stats
    master (7.620M)   : 0, 7620483

    section Manual
    master (10.953M)   : 0, 10953313

    section Manual + Automatic
    This PR (5948) (6.833M)   : 0, 6833346
    master (6.849M)   : 0, 6848847

    section DD_TRACE_ENABLED=0
    master (10.227M)   : 0, 10226857

gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5948) (9.645M)   : 0, 9644669
    master (9.517M)   : 0, 9516897
    benchmarks/2.9.0 (9.798M)   : 0, 9798067

    section Automatic
    This PR (5948) (6.673M)   : 0, 6673057
    master (6.590M)   : 0, 6589925

    section Trace stats
    master (6.791M)   : 0, 6791127

    section Manual
    master (9.449M)   : 0, 9448954

    section Manual + Automatic
    This PR (5948) (6.105M)   : 0, 6105004
    master (6.064M)   : 0, 6064287

    section DD_TRACE_ENABLED=0
    master (8.906M)   : 0, 8906146

gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5948) (9.879M)   : 0, 9878811
    benchmarks/2.9.0 (10.067M)   : 0, 10067315

    section Automatic
    This PR (5948) (6.603M)   : 0, 6602597
    benchmarks/2.9.0 (7.552M)   : 0, 7552193

    section Manual + Automatic
    This PR (5948) (6.241M)   : 0, 6241400

DataDog / dd-trace-dotnet