DataDog / dd-trace-dotnet

.NET Client Library for Datadog APM
https://docs.datadoghq.com/tracing/
Apache License 2.0
437 stars 137 forks source link

[Profiler] Cache Walltime callstacks based on `ucontext_t` #5975

Open gleocadie opened 4 weeks ago

gleocadie commented 4 weeks ago

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

andrewlock commented 4 weeks 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:

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 (5975) - mean (70ms)  : 67, 73
     .   : milestone, 70,
    master - mean (70ms)  : 67, 73
     .   : milestone, 70,

    section CallTarget+Inlining+NGEN
    This PR (5975) - mean (1,089ms)  : 1065, 1113
     .   : milestone, 1089,
    master - mean (1,083ms)  : 1050, 1116
     .   : milestone, 1083,
gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5975) - mean (109ms)  : 105, 113
     .   : milestone, 109,
    master - mean (109ms)  : 105, 112
     .   : milestone, 109,

    section CallTarget+Inlining+NGEN
    This PR (5975) - mean (762ms)  : 741, 783
     .   : milestone, 762,
    master - mean (760ms)  : 736, 783
     .   : milestone, 760,
gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5975) - mean (93ms)  : 90, 96
     .   : milestone, 93,
    master - mean (93ms)  : 89, 96
     .   : milestone, 93,

    section CallTarget+Inlining+NGEN
    This PR (5975) - mean (708ms)  : 692, 723
     .   : milestone, 708,
    master - mean (712ms)  : 691, 734
     .   : milestone, 712,
gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5975) - mean (190ms)  : 188, 193
     .   : milestone, 190,
    master - mean (191ms)  : 187, 194
     .   : milestone, 191,

    section CallTarget+Inlining+NGEN
    This PR (5975) - mean (1,164ms)  : 1140, 1189
     .   : milestone, 1164,
    master - mean (1,160ms)  : 1138, 1181
     .   : milestone, 1160,
gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5975) - mean (275ms)  : 269, 280
     .   : milestone, 275,
    master - mean (276ms)  : 272, 280
     .   : milestone, 276,

    section CallTarget+Inlining+NGEN
    This PR (5975) - mean (924ms)  : 900, 948
     .   : milestone, 924,
    master - mean (924ms)  : 900, 947
     .   : milestone, 924,
gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5975) - mean (265ms)  : 260, 269
     .   : milestone, 265,
    master - mean (265ms)  : 261, 268
     .   : milestone, 265,

    section CallTarget+Inlining+NGEN
    This PR (5975) - mean (910ms)  : 884, 935
     .   : milestone, 910,
    master - mean (906ms)  : 885, 928
     .   : milestone, 906,
datadog-ddstaging[bot] commented 4 weeks ago

Datadog Report

Branch report: gleocadie/reuse-callstack-when-uniwinding-is-useless Commit report: d5ed294 Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 364531 Passed, 2333 Skipped, 16h 37m 29.63s Total Time

andrewlock commented 3 weeks ago

Benchmarks Report for tracer :snail:

Benchmarks for #5975 compared to master:

The following thresholds were used for comparing the benchmark speeds:

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/3800b4e335c10799fcb09e3a0188915341668694)|`StartStopWithChild`|net6.0|7.67μs|42.7ns|290ns|0.0179| 0.00716|0|5.43 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`StartStopWithChild`|netcoreapp3.1|9.96μs|56.2ns|394ns|0.0195| 0.00973|0|5.62 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`StartStopWithChild`|net472|16.2μs|33.9ns|127ns|1.01| 0.295|0.0957|6.07 KB| |#5975|`StartStopWithChild`|net6.0|7.83μs|42.8ns|260ns|0.0157| 0.00784|0|5.43 KB| |#5975|`StartStopWithChild`|netcoreapp3.1|10.2μs|56.2ns|351ns|0.0254| 0.0152|0|5.62 KB| |#5975|`StartStopWithChild`|net472|15.9μs|63.2ns|245ns|1| 0.287|0.0955|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/3800b4e335c10799fcb09e3a0188915341668694)|`WriteAndFlushEnrichedTraces`|net6.0|462μs|314ns|1.13μs|0| 0|0|2.7 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`WriteAndFlushEnrichedTraces`|netcoreapp3.1|631μs|601ns|2.25μs|0| 0|0|2.7 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`WriteAndFlushEnrichedTraces`|net472|831μs|359ns|1.39μs|0.414| 0|0|3.3 KB| |#5975|`WriteAndFlushEnrichedTraces`|net6.0|477μs|448ns|1.74μs|0| 0|0|2.7 KB| |#5975|`WriteAndFlushEnrichedTraces`|netcoreapp3.1|654μs|349ns|1.26μs|0| 0|0|2.7 KB| |#5975|`WriteAndFlushEnrichedTraces`|net472|858μs|533ns|1.85μs|0.414| 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/3800b4e335c10799fcb09e3a0188915341668694)|`SendRequest`|net6.0|204μs|1.18μs|9.92μs|0.208| 0|0|18.45 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`SendRequest`|netcoreapp3.1|228μs|1.32μs|13μs|0.215| 0|0|20.61 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`SendRequest`|net472|0.00158ns|0.000714ns|0.00267ns|0| 0|0|0 b| |#5975|`SendRequest`|net6.0|204μs|1.2μs|11.5μs|0.191| 0|0|18.45 KB| |#5975|`SendRequest`|netcoreapp3.1|228μs|1.34μs|12.9μs|0.213| 0|0|20.61 KB| |#5975|`SendRequest`|net472|0.00203ns|0.000667ns|0.00258ns|0| 0|0|0 b|
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - 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/3800b4e335c10799fcb09e3a0188915341668694)|`WriteAndFlushEnrichedTraces`|net6.0|572μs|3.18μs|21.1μs|0.568| 0|0|41.46 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`WriteAndFlushEnrichedTraces`|netcoreapp3.1|680μs|3.72μs|21.7μs|0.342| 0|0|41.6 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`WriteAndFlushEnrichedTraces`|net472|847μs|4.2μs|18.8μs|8.33| 2.5|0.417|53.32 KB| |#5975|`WriteAndFlushEnrichedTraces`|net6.0|565μs|2.95μs|13.8μs|0.584| 0|0|41.63 KB| |#5975|`WriteAndFlushEnrichedTraces`|netcoreapp3.1|715μs|3.91μs|22.1μs|0.372| 0|0|41.74 KB| |#5975|`WriteAndFlushEnrichedTraces`|net472|872μs|3.79μs|14.7μs|8.08| 2.55|0.425|53.27 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/3800b4e335c10799fcb09e3a0188915341668694)|`ExecuteNonQuery`|net6.0|1.31μs|1.26ns|4.87ns|0.0144| 0|0|1.02 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`ExecuteNonQuery`|netcoreapp3.1|1.81μs|1.31ns|5.09ns|0.0135| 0|0|1.02 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`ExecuteNonQuery`|net472|2.05μs|1.85ns|6.66ns|0.157| 0|0|987 B| |#5975|`ExecuteNonQuery`|net6.0|1.31μs|1.45ns|5.61ns|0.0143| 0|0|1.02 KB| |#5975|`ExecuteNonQuery`|netcoreapp3.1|1.76μs|1.93ns|6.94ns|0.0137| 0|0|1.02 KB| |#5975|`ExecuteNonQuery`|net472|2.1μs|1.87ns|7ns|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/3800b4e335c10799fcb09e3a0188915341668694)|`CallElasticsearch`|net6.0|1.2μs|0.83ns|3.22ns|0.0138| 0|0|976 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`CallElasticsearch`|netcoreapp3.1|1.58μs|0.614ns|2.13ns|0.0133| 0|0|976 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`CallElasticsearch`|net472|2.4μs|0.884ns|3.19ns|0.158| 0|0|995 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`CallElasticsearchAsync`|net6.0|1.22μs|1ns|3.74ns|0.0134| 0|0|952 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`CallElasticsearchAsync`|netcoreapp3.1|1.61μs|1.19ns|4.6ns|0.0137| 0|0|1.02 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`CallElasticsearchAsync`|net472|2.57μs|0.994ns|3.85ns|0.167| 0|0|1.05 KB| |#5975|`CallElasticsearch`|net6.0|1.12μs|0.598ns|2.24ns|0.0137| 0|0|976 B| |#5975|`CallElasticsearch`|netcoreapp3.1|1.54μs|0.528ns|1.98ns|0.0131| 0|0|976 B| |#5975|`CallElasticsearch`|net472|2.39μs|1.65ns|6.39ns|0.158| 0|0|995 B| |#5975|`CallElasticsearchAsync`|net6.0|1.34μs|1.47ns|5.7ns|0.0133| 0|0|952 B| |#5975|`CallElasticsearchAsync`|netcoreapp3.1|1.59μs|0.617ns|2.31ns|0.0135| 0|0|1.02 KB| |#5975|`CallElasticsearchAsync`|net472|2.52μs|1.67ns|6.47ns|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/3800b4e335c10799fcb09e3a0188915341668694)|`ExecuteAsync`|net6.0|1.24μs|0.342ns|1.23ns|0.0131| 0|0|952 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`ExecuteAsync`|netcoreapp3.1|1.67μs|0.738ns|2.86ns|0.0125| 0|0|952 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`ExecuteAsync`|net472|1.83μs|0.815ns|3.15ns|0.145| 0|0|915 B| |#5975|`ExecuteAsync`|net6.0|1.33μs|1.13ns|4.23ns|0.0133| 0|0|952 B| |#5975|`ExecuteAsync`|netcoreapp3.1|1.52μs|0.412ns|1.6ns|0.0122| 0|0|952 B| |#5975|`ExecuteAsync`|net472|1.8μs|1.27ns|4.92ns|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/3800b4e335c10799fcb09e3a0188915341668694)|`SendAsync`|net6.0|4.25μs|2.39ns|8.93ns|0.0298| 0|0|2.22 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`SendAsync`|netcoreapp3.1|5.02μs|1.18ns|4.59ns|0.0376| 0|0|2.76 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`SendAsync`|net472|7.92μs|2.58ns|10ns|0.496| 0|0|3.15 KB| |#5975|`SendAsync`|net6.0|4.12μs|6.33ns|24.5ns|0.0305| 0|0|2.22 KB| |#5975|`SendAsync`|netcoreapp3.1|5.06μs|1.98ns|7.68ns|0.0381| 0|0|2.76 KB| |#5975|`SendAsync`|net472|7.85μs|1.41ns|5.45ns|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/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|net6.0|1.5μs|0.651ns|2.52ns|0.0234| 0|0|1.64 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|netcoreapp3.1|2.28μs|0.98ns|3.53ns|0.0225| 0|0|1.64 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|net472|2.77μs|1.05ns|4.08ns|0.249| 0|0|1.57 KB| |#5975|`EnrichedLog`|net6.0|1.59μs|1.03ns|3.71ns|0.023| 0|0|1.64 KB| |#5975|`EnrichedLog`|netcoreapp3.1|2.3μs|0.618ns|2.14ns|0.0221| 0|0|1.64 KB| |#5975|`EnrichedLog`|net472|2.69μs|1.91ns|7.38ns|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/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|net6.0|115μs|197ns|761ns|0.0577| 0|0|4.28 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|netcoreapp3.1|120μs|119ns|446ns|0| 0|0|4.28 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|net472|149μs|356ns|1.38μs|0.658| 0.219|0|4.46 KB| |#5975|`EnrichedLog`|net6.0|114μs|143ns|556ns|0| 0|0|4.28 KB| |#5975|`EnrichedLog`|netcoreapp3.1|119μs|211ns|817ns|0.0593| 0|0|4.28 KB| |#5975|`EnrichedLog`|net472|147μs|146ns|567ns|0.661| 0.22|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/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|net6.0|2.95μs|0.546ns|1.97ns|0.0312| 0|0|2.2 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|netcoreapp3.1|4.08μs|1.31ns|4.91ns|0.0286| 0|0|2.2 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|net472|4.82μs|1.43ns|5.55ns|0.32| 0|0|2.02 KB| |#5975|`EnrichedLog`|net6.0|3μs|0.842ns|3.26ns|0.0312| 0|0|2.2 KB| |#5975|`EnrichedLog`|netcoreapp3.1|4.27μs|1.36ns|5.07ns|0.0282| 0|0|2.2 KB| |#5975|`EnrichedLog`|net472|4.82μs|2.02ns|7.82ns|0.32| 0|0|2.02 KB|
Benchmarks.Trace.RedisBenchmark - Faster :tada: Same allocations :heavy_check_mark: #### Faster :tada: in #5975 | Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality | |:----------|-----------:|-----------:|--------:|--------:| | Benchmarks.Trace.RedisBenchmark.SendReceive‑net6.0 | 1.124 | 1,391.73 | 1,237.93 | ### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`SendReceive`|net6.0|1.39μs|1.02ns|3.95ns|0.0159| 0|0|1.14 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`SendReceive`|netcoreapp3.1|1.77μs|0.907ns|3.51ns|0.015| 0|0|1.14 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`SendReceive`|net472|2.08μs|0.893ns|3.34ns|0.183| 0.00104|0|1.16 KB| |#5975|`SendReceive`|net6.0|1.24μs|0.191ns|0.688ns|0.016| 0|0|1.14 KB| |#5975|`SendReceive`|netcoreapp3.1|1.74μs|2.98ns|11.5ns|0.0155| 0|0|1.14 KB| |#5975|`SendReceive`|net472|2.2μs|1.36ns|5.26ns|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/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|net6.0|2.87μs|2.37ns|8.55ns|0.0214| 0|0|1.6 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|netcoreapp3.1|3.86μs|3.85ns|14.9ns|0.0211| 0|0|1.65 KB| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`EnrichedLog`|net472|4.31μs|1.72ns|6.65ns|0.324| 0|0|2.04 KB| |#5975|`EnrichedLog`|net6.0|2.77μs|0.908ns|3.52ns|0.0222| 0|0|1.6 KB| |#5975|`EnrichedLog`|netcoreapp3.1|3.89μs|1.24ns|4.8ns|0.0231| 0|0|1.65 KB| |#5975|`EnrichedLog`|net472|4.46μs|2.2ns|8.51ns|0.322| 0|0|2.04 KB|
Benchmarks.Trace.SpanBenchmark - Faster :tada: Same allocations :heavy_check_mark: #### Faster :tada: in #5975 | Benchmark | base/diff | Base Median (ns) | Diff Median (ns) | Modality | |:----------|-----------:|-----------:|--------:|--------:| | Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0 | 1.157 | 465.01 | 401.85 | ### Raw results | Branch | Method | Toolchain | Mean | StdError | StdDev | Gen 0 | Gen 1 | Gen 2 | Allocated | |---------|---------------------------- |-------------- |---------:|---------:|--------:|-------:|------:|------:|----------:| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`StartFinishSpan`|net6.0|465ns|0.283ns|1.09ns|0.00815| 0|0|576 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`StartFinishSpan`|netcoreapp3.1|563ns|0.805ns|3.12ns|0.00764| 0|0|576 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`StartFinishSpan`|net472|639ns|0.718ns|2.78ns|0.0916| 0|0|578 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`StartFinishScope`|net6.0|479ns|0.368ns|1.43ns|0.00976| 0|0|696 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`StartFinishScope`|netcoreapp3.1|726ns|0.776ns|3ns|0.00933| 0|0|696 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`StartFinishScope`|net472|842ns|0.8ns|3.1ns|0.104| 0|0|658 B| |#5975|`StartFinishSpan`|net6.0|401ns|0.277ns|1.07ns|0.00808| 0|0|576 B| |#5975|`StartFinishSpan`|netcoreapp3.1|581ns|0.329ns|1.27ns|0.00784| 0|0|576 B| |#5975|`StartFinishSpan`|net472|679ns|0.63ns|2.44ns|0.0915| 0|0|578 B| |#5975|`StartFinishScope`|net6.0|473ns|0.678ns|2.45ns|0.00986| 0|0|696 B| |#5975|`StartFinishScope`|netcoreapp3.1|745ns|0.389ns|1.45ns|0.00972| 0|0|696 B| |#5975|`StartFinishScope`|net472|847ns|1ns|3.87ns|0.104| 0|0|658 B|
Benchmarks.Trace.TraceAnnotationsBenchmark - 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/3800b4e335c10799fcb09e3a0188915341668694)|`RunOnMethodBegin`|net6.0|645ns|0.308ns|1.19ns|0.00999| 0|0|696 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`RunOnMethodBegin`|netcoreapp3.1|946ns|0.623ns|2.41ns|0.00939| 0|0|696 B| |[master](https://github.com/DataDog/dd-trace-dotnet/tree/3800b4e335c10799fcb09e3a0188915341668694)|`RunOnMethodBegin`|net472|1.07μs|0.767ns|2.97ns|0.104| 0|0|658 B| |#5975|`RunOnMethodBegin`|net6.0|611ns|0.65ns|2.52ns|0.00976| 0|0|696 B| |#5975|`RunOnMethodBegin`|netcoreapp3.1|986ns|1.26ns|4.88ns|0.00951| 0|0|696 B| |#5975|`RunOnMethodBegin`|net472|1.13μs|0.526ns|2.04ns|0.105| 0|0|658 B|
andrewlock commented 3 weeks 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 (5975) (11.232M)   : 0, 11231934
    master (11.149M)   : 0, 11149005
    benchmarks/2.9.0 (11.197M)   : 0, 11196694

    section Automatic
    This PR (5975) (7.502M)   : 0, 7501877
    master (7.293M)   : 0, 7292565
    benchmarks/2.9.0 (7.764M)   : 0, 7763676

    section Trace stats
    master (7.789M)   : 0, 7788853

    section Manual
    master (11.289M)   : 0, 11289176

    section Manual + Automatic
    This PR (5975) (6.901M)   : 0, 6900514
    master (6.886M)   : 0, 6885775

    section DD_TRACE_ENABLED=0
    master (10.291M)   : 0, 10291337
gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5975) (9.553M)   : 0, 9553205
    benchmarks/2.9.0 (9.684M)   : 0, 9683707

    section Automatic
    This PR (5975) (6.498M)   : 0, 6497882

    section Manual + Automatic
    This PR (5975) (6.066M)   : 0, 6066383
gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5975) (10.048M)   : 0, 10047828
    master (10.220M)   : 0, 10219514

    section Automatic
    This PR (5975) (6.869M)   : 0, 6869289
    master (6.882M)   : 0, 6881724

    section Trace stats
    master (7.404M)   : 0, 7403605

    section Manual
    master (10.253M)   : 0, 10252749

    section Manual + Automatic
    This PR (5975) (6.451M)   : 0, 6450568
    master (6.482M)   : 0, 6481560

    section DD_TRACE_ENABLED=0
    master (9.525M)   : 0, 9524930