dd-trace-dotnet icon indicating copy to clipboard operation
dd-trace-dotnet copied to clipboard

Trace context propagation on SQS receive

Open vandonr opened this issue 1 year ago • 4 comments

Summary of changes

In the SQS instrumentation, we were injecting the trace context in the headers, but we didn't read it on receive. A span was created at the beginning of the receive method, and closed at the end. We cannot keep this behavior with trace propagation, because:

  • we need one span per message, because one span cannot have several parents
  • we need to keep the span open so that it covers any processing (and an eventual produce) that happens afterwards, otherwise the trace propagation is useless since it'll only show the consume span alone.

As such, this is a breaking change because it replaces a single span with the duration of the consume call that stays in the consume trace, with a span that goes in the produce trace, and covers everything happening afterwards.

Also, since SQS allows consuming several messages at once, we don't have any good options there, and only the last consume span will carry the "processing" spans.

Reason for change

bridging gaps in implementation

Implementation details

took example on the Kafka consume instrumentation, we might want to use a setting to control whether the spans stay open or not (see the doc)

Test coverage

will do

vandonr avatar Feb 07 '24 13:02 vandonr

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 (5159) - mean (74ms)  : 66, 83
     .   : milestone, 74,
    master - mean (74ms)  : 66, 82
     .   : milestone, 74,

    section CallTarget+Inlining+NGEN
    This PR (5159) - mean (989ms)  : 963, 1015
     .   : milestone, 989,
    master - mean (985ms)  : 963, 1007
     .   : milestone, 985,

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

    section CallTarget+Inlining+NGEN
    This PR (5159) - mean (712ms)  : 682, 743
     .   : milestone, 712,
    master - mean (718ms)  : 696, 740
     .   : milestone, 718,

gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5159) - mean (94ms)  : 91, 98
     .   : milestone, 94,
    master - mean (97ms)  : 93, 100
     .   : milestone, 97,

    section CallTarget+Inlining+NGEN
    This PR (5159) - mean (670ms)  : 654, 687
     .   : milestone, 670,
    master - mean (679ms)  : 647, 710
     .   : milestone, 679,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5159) - mean (188ms)  : 185, 192
     .   : milestone, 188,
    master - mean (186ms)  : 180, 192
     .   : milestone, 186,

    section CallTarget+Inlining+NGEN
    This PR (5159) - mean (1,067ms)  : 1047, 1086
     .   : milestone, 1067,
    master - mean (1,052ms)  : 1027, 1078
     .   : milestone, 1052,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5159) - mean (271ms)  : 267, 275
     .   : milestone, 271,
    master - mean (270ms)  : 265, 275
     .   : milestone, 270,

    section CallTarget+Inlining+NGEN
    This PR (5159) - mean (1,058ms)  : 1037, 1079
     .   : milestone, 1058,
    master - mean (1,059ms)  : 1038, 1081
     .   : milestone, 1059,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5159) - mean (261ms)  : 257, 264
     .   : milestone, 261,
    master - mean (259ms)  : 254, 264
     .   : milestone, 259,

    section CallTarget+Inlining+NGEN
    This PR (5159) - mean (1,001ms)  : 981, 1022
     .   : milestone, 1001,
    master - mean (992ms)  : 966, 1018
     .   : milestone, 992,

andrewlock avatar Feb 07 '24 14:02 andrewlock

Benchmarks Report :snail:

Benchmarks for #5159 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.164
  • 2 benchmarks are slower, with geometric mean 1.184
  • 1 benchmarks have more 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 StartStopWithChild net6.0 8.69μs 47ns 270ns 0.0217 0.00866 0 7.49 KB
master StartStopWithChild netcoreapp3.1 10.6μs 55.2ns 259ns 0.0265 0.0106 0 7.58 KB
master StartStopWithChild net472 17.1μs 47.2ns 183ns 1.33 0.342 0.111 7.95 KB
#5159 StartStopWithChild net6.0 8.65μs 48.9ns 339ns 0.0255 0.0127 0 7.49 KB
#5159 StartStopWithChild netcoreapp3.1 10.7μs 60.2ns 408ns 0.033 0.0165 0 7.58 KB
#5159 StartStopWithChild net472 17.2μs 49.7ns 192ns 1.31 0.326 0.0945 7.96 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 WriteAndFlushEnrichedTraces net6.0 446μs 222ns 800ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 636μs 116ns 417ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 774μs 307ns 1.15μs 0.386 0 0 3.3 KB
#5159 WriteAndFlushEnrichedTraces net6.0 455μs 383ns 1.48μs 0 0 0 2.7 KB
#5159 WriteAndFlushEnrichedTraces netcoreapp3.1 648μs 199ns 773ns 0 0 0 2.7 KB
#5159 WriteAndFlushEnrichedTraces net472 777μs 399ns 1.55μs 0.388 0 0 3.3 KB
Benchmarks.Trace.Asm.AppSecBodyBenchmark - 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 AllCycleSimpleBody net6.0 38.8μs 10.5ns 39.2ns 0.0194 0 0 2.36 KB
master AllCycleSimpleBody netcoreapp3.1 42.6μs 51.7ns 200ns 0.0211 0 0 2.34 KB
master AllCycleSimpleBody net472 44.7μs 12.1ns 43.6ns 0.38 0 0 2.41 KB
master AllCycleMoreComplexBody net6.0 201μs 93.4ns 349ns 0.1 0 0 9.84 KB
master AllCycleMoreComplexBody netcoreapp3.1 214μs 248ns 961ns 0.106 0 0 9.73 KB
master AllCycleMoreComplexBody net472 230μs 89.1ns 333ns 1.5 0 0 9.91 KB
master ObjectExtractorSimpleBody net6.0 141ns 0.12ns 0.464ns 0.00396 0 0 280 B
master ObjectExtractorSimpleBody netcoreapp3.1 207ns 0.193ns 0.746ns 0.00375 0 0 272 B
master ObjectExtractorSimpleBody net472 167ns 0.118ns 0.456ns 0.0446 0 0 281 B
master ObjectExtractorMoreComplexBody net6.0 3.02μs 1.21ns 4.52ns 0.0531 0 0 3.78 KB
master ObjectExtractorMoreComplexBody netcoreapp3.1 4.18μs 1.8ns 6.96ns 0.0501 0 0 3.69 KB
master ObjectExtractorMoreComplexBody net472 3.75μs 3.94ns 15.3ns 0.603 0.00563 0 3.8 KB
#5159 AllCycleSimpleBody net6.0 39.1μs 27.8ns 108ns 0.0194 0 0 2.36 KB
#5159 AllCycleSimpleBody netcoreapp3.1 41.5μs 32.1ns 116ns 0.0207 0 0 2.34 KB
#5159 AllCycleSimpleBody net472 44.7μs 15.7ns 60.9ns 0.378 0 0 2.41 KB
#5159 AllCycleMoreComplexBody net6.0 201μs 126ns 487ns 0.1 0 0 9.84 KB
#5159 AllCycleMoreComplexBody netcoreapp3.1 214μs 152ns 587ns 0.106 0 0 9.73 KB
#5159 AllCycleMoreComplexBody net472 227μs 68.8ns 266ns 1.48 0 0 9.91 KB
#5159 ObjectExtractorSimpleBody net6.0 140ns 0.0705ns 0.273ns 0.00392 0 0 280 B
#5159 ObjectExtractorSimpleBody netcoreapp3.1 208ns 0.157ns 0.586ns 0.00368 0 0 272 B
#5159 ObjectExtractorSimpleBody net472 164ns 0.139ns 0.502ns 0.0446 0 0 281 B
#5159 ObjectExtractorMoreComplexBody net6.0 3.01μs 2.27ns 8.49ns 0.0522 0 0 3.78 KB
#5159 ObjectExtractorMoreComplexBody netcoreapp3.1 4.03μs 1.43ns 5.34ns 0.0505 0 0 3.69 KB
#5159 ObjectExtractorMoreComplexBody net472 3.75μs 1.85ns 6.67ns 0.602 0.00563 0 3.8 KB
Benchmarks.Trace.Asm.AppSecWafBenchmark - 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 RunWaf(args=NestedMap (10)) net6.0 53.9μs 49ns 177ns 0.215 0 0 16.66 KB
master RunWaf(args=NestedMap (10)) netcoreapp3.1 72.8μs 177ns 663ns 0.216 0 0 16.65 KB
master RunWaf(args=NestedMap (10)) net472 97.1μs 32.8ns 114ns 2.62 0.0972 0 16.73 KB
master RunWafTwice(args=NestedMap (10)) net6.0 57.8μs 27.6ns 95.7ns 0.22 0 0 17.33 KB
master RunWafTwice(args=NestedMap (10)) netcoreapp3.1 75.8μs 418ns 2.58μs 0.231 0 0 17.31 KB
master RunWafTwice(args=NestedMap (10)) net472 106μs 47.8ns 172ns 2.74 0.105 0 17.42 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 104μs 62.3ns 241ns 0.256 0 0 19.49 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 122μs 386ns 1.5μs 0.235 0 0 19.44 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net472 149μs 49.5ns 179ns 3.11 0.148 0 19.72 KB
master RunWaf(args=NestedMap (100)) net6.0 101μs 25.4ns 141ns 0.453 0 0 33.35 KB
master RunWaf(args=NestedMap (100)) netcoreapp3.1 136μs 354ns 1.37μs 0.456 0 0 33.92 KB
master RunWaf(args=NestedMap (100)) net472 193μs 958ns 3.95μs 5.37 0.377 0 34.26 KB
master RunWafTwice(args=NestedMap (100)) net6.0 113μs 32.8ns 114ns 0.473 0 0 34.02 KB
master RunWafTwice(args=NestedMap (100)) netcoreapp3.1 142μs 775ns 4.1μs 0.417 0 0 34.58 KB
master RunWafTwice(args=NestedMap (100)) net472 204μs 502ns 1.95μs 5.51 0.394 0 34.96 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) net6.0 153μs 76.5ns 296ns 0.456 0 0 36.18 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) netcoreapp3.1 191μs 885ns 3.54μs 0.485 0 0 36.71 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) net472 245μs 101ns 376ns 5.87 0.489 0 37.26 KB
master RunWaf(args=NestedMap (20)) net6.0 106μs 30.6ns 114ns 0.422 0 0 32.78 KB
master RunWaf(args=NestedMap (20)) netcoreapp3.1 135μs 680ns 3.19μs 0.391 0 0 32.89 KB
master RunWaf(args=NestedMap (20)) net472 188μs 87.5ns 339ns 5.26 0.376 0 33.23 KB
master RunWafTwice(args=NestedMap (20)) net6.0 107μs 41.2ns 143ns 0.415 0 0 33.45 KB
master RunWafTwice(args=NestedMap (20)) netcoreapp3.1 141μs 740ns 3.7μs 0.402 0 0 33.55 KB
master RunWafTwice(args=NestedMap (20)) net472 202μs 700ns 2.71μs 5.35 0.396 0 33.92 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 161μs 910ns 6.17μs 0.464 0 0 35.61 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 190μs 271ns 1.05μs 0.471 0 0 35.68 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net472 245μs 91.3ns 354ns 5.73 0.487 0 36.22 KB
#5159 RunWaf(args=NestedMap (10)) net6.0 57.4μs 48.8ns 189ns 0.231 0 0 16.66 KB
#5159 RunWaf(args=NestedMap (10)) netcoreapp3.1 68.3μs 376ns 2.19μs 0.214 0 0 16.65 KB
#5159 RunWaf(args=NestedMap (10)) net472 97.5μs 65.3ns 253ns 2.63 0.0974 0 16.73 KB
#5159 RunWafTwice(args=NestedMap (10)) net6.0 57.1μs 33.2ns 124ns 0.225 0 0 17.33 KB
#5159 RunWafTwice(args=NestedMap (10)) netcoreapp3.1 71.6μs 107ns 426ns 0.214 0 0 17.31 KB
#5159 RunWafTwice(args=NestedMap (10)) net472 106μs 60.9ns 236ns 2.75 0.106 0 17.42 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 106μs 597ns 4.22μs 0.27 0 0 19.49 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 123μs 236ns 913ns 0.247 0 0 19.44 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [22]) net472 155μs 733ns 2.93μs 3.08 0.15 0 19.72 KB
#5159 RunWaf(args=NestedMap (100)) net6.0 106μs 572ns 3.19μs 0.457 0 0 33.35 KB
#5159 RunWaf(args=NestedMap (100)) netcoreapp3.1 135μs 708ns 3.47μs 0.408 0 0 33.92 KB
#5159 RunWaf(args=NestedMap (100)) net472 188μs 73ns 283ns 5.36 0.376 0 34.27 KB
#5159 RunWafTwice(args=NestedMap (100)) net6.0 104μs 74.8ns 326ns 0.468 0 0 34.02 KB
#5159 RunWafTwice(args=NestedMap (100)) netcoreapp3.1 144μs 779ns 4.47μs 0.429 0 0 34.58 KB
#5159 RunWafTwice(args=NestedMap (100)) net472 198μs 116ns 448ns 5.53 0.395 0 34.96 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [23]) net6.0 155μs 96.5ns 374ns 0.486 0 0 36.18 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [23]) netcoreapp3.1 187μs 211ns 729ns 0.464 0 0 36.71 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [23]) net472 253μs 684ns 2.65μs 5.88 0.49 0 37.26 KB
#5159 RunWaf(args=NestedMap (20)) net6.0 106μs 538ns 2.35μs 0.465 0 0 32.78 KB
#5159 RunWaf(args=NestedMap (20)) netcoreapp3.1 136μs 633ns 2.53μs 0.412 0 0 32.89 KB
#5159 RunWaf(args=NestedMap (20)) net472 192μs 877ns 3.4μs 5.22 0.373 0 33.23 KB
#5159 RunWafTwice(args=NestedMap (20)) net6.0 105μs 59ns 221ns 0.421 0 0 33.45 KB
#5159 RunWafTwice(args=NestedMap (20)) netcoreapp3.1 142μs 720ns 3.53μs 0.42 0 0 33.55 KB
#5159 RunWafTwice(args=NestedMap (20)) net472 203μs 823ns 3.19μs 5.33 0.395 0 33.92 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 162μs 877ns 4.8μs 0.48 0 0 35.61 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 189μs 306ns 1.15μs 0.468 0 0 35.68 KB
#5159 RunWafWithAttack(args=Neste(...)tack) [22]) net472 243μs 43.5ns 157ns 5.73 0.487 0 36.22 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 SendRequest net6.0 172μs 100ns 375ns 0.172 0 0 18.26 KB
master SendRequest netcoreapp3.1 193μs 494ns 1.91μs 0.191 0 0 20.42 KB
master SendRequest net472 0.000226ns 0.00013ns 0.000467ns 0 0 0 0 b
#5159 SendRequest net6.0 171μs 223ns 865ns 0.172 0 0 18.26 KB
#5159 SendRequest netcoreapp3.1 189μs 260ns 974ns 0.188 0 0 20.42 KB
#5159 SendRequest net472 0.0226ns 0.00489ns 0.0189ns 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 WriteAndFlushEnrichedTraces net6.0 541μs 1.33μs 5.13μs 0.548 0 0 41.53 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 653μs 1.1μs 4.26μs 0.324 0 0 41.78 KB
master WriteAndFlushEnrichedTraces net472 798μs 3.97μs 17.3μs 8.17 2.45 0.408 53.22 KB
#5159 WriteAndFlushEnrichedTraces net6.0 538μs 1.58μs 6.14μs 0.523 0 0 41.7 KB
#5159 WriteAndFlushEnrichedTraces netcoreapp3.1 649μs 526ns 2.04μs 0.324 0 0 41.75 KB
#5159 WriteAndFlushEnrichedTraces net472 803μs 3.11μs 12μs 8.36 2.39 0.398 53.26 KB
Benchmarks.Trace.DbCommandBenchmark - Faster :tada: Same allocations :heavy_check_mark:

Faster :tada: in #5159

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑net6.0 1.164 1,207.87 1,037.63

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net6.0 1.21μs 0.52ns 1.95ns 0.0103 0 0 776 B
master ExecuteNonQuery netcoreapp3.1 1.49μs 0.734ns 2.84ns 0.00958 0 0 776 B
master ExecuteNonQuery net472 1.84μs 0.653ns 2.53ns 0.116 0 0 738 B
#5159 ExecuteNonQuery net6.0 1.04μs 0.525ns 2.03ns 0.011 0 0 776 B
#5159 ExecuteNonQuery netcoreapp3.1 1.53μs 0.744ns 2.88ns 0.00989 0 0 776 B
#5159 ExecuteNonQuery net472 1.82μs 1.5ns 5.82ns 0.117 0 0 738 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 CallElasticsearch net6.0 1.13μs 0.547ns 2.05ns 0.0131 0 0 944 B
master CallElasticsearch netcoreapp3.1 1.56μs 1.34ns 5.2ns 0.0125 0 0 944 B
master CallElasticsearch net472 2.52μs 1.19ns 4.61ns 0.152 0 0 963 B
master CallElasticsearchAsync net6.0 1.3μs 0.792ns 2.96ns 0.0125 0 0 920 B
master CallElasticsearchAsync netcoreapp3.1 1.54μs 1.27ns 4.39ns 0.013 0 0 992 B
master CallElasticsearchAsync net472 2.54μs 1.1ns 4.26ns 0.161 0 0 1.02 KB
#5159 CallElasticsearch net6.0 1.25μs 0.37ns 1.38ns 0.0133 0 0 944 B
#5159 CallElasticsearch netcoreapp3.1 1.56μs 2.41ns 9.01ns 0.0131 0 0 944 B
#5159 CallElasticsearch net472 2.48μs 1.65ns 6.18ns 0.152 0 0 963 B
#5159 CallElasticsearchAsync net6.0 1.28μs 1.13ns 4.37ns 0.0128 0 0 920 B
#5159 CallElasticsearchAsync netcoreapp3.1 1.67μs 0.671ns 2.51ns 0.0133 0 0 992 B
#5159 CallElasticsearchAsync net472 2.6μs 1.1ns 4.25ns 0.161 0 0 1.02 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 ExecuteAsync net6.0 1.31μs 0.743ns 2.78ns 0.013 0 0 920 B
master ExecuteAsync netcoreapp3.1 1.59μs 1.03ns 3.84ns 0.0127 0 0 920 B
master ExecuteAsync net472 1.83μs 1.12ns 4.35ns 0.14 0 0 883 B
#5159 ExecuteAsync net6.0 1.25μs 0.565ns 2.19ns 0.013 0 0 920 B
#5159 ExecuteAsync netcoreapp3.1 1.6μs 0.545ns 2.04ns 0.0121 0 0 920 B
#5159 ExecuteAsync net472 1.81μs 1.02ns 3.82ns 0.14 0 0 883 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 SendAsync net6.0 4.02μs 1.47ns 5.5ns 0.0285 0 0 2.1 KB
master SendAsync netcoreapp3.1 4.9μs 1.45ns 5.23ns 0.0343 0 0 2.64 KB
master SendAsync net472 7.7μs 27.2ns 94.3ns 0.525 0 0 3.31 KB
#5159 SendAsync net6.0 4.2μs 1.75ns 6.3ns 0.0298 0 0 2.1 KB
#5159 SendAsync netcoreapp3.1 4.99μs 3.93ns 15.2ns 0.0353 0 0 2.64 KB
#5159 SendAsync net472 7.81μs 3.95ns 15.3ns 0.524 0 0 3.31 KB
Benchmarks.Trace.Iast.StringAspectsBenchmark - Same speed :heavy_check_mark: More allocations :warning:

More allocations :warning: in #5159

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark‑netcoreapp3.1 202.51 KB 213.74 KB 11.23 KB 5.55%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StringConcatBenchmark net6.0 61.8μs 985ns 9.55μs 0 0 0 43.44 KB
master StringConcatBenchmark netcoreapp3.1 55.8μs 460ns 4.46μs 0 0 0 42.64 KB
master StringConcatBenchmark net472 37.9μs 72.5ns 261ns 0 0 0 59.26 KB
master StringConcatAspectBenchmark net6.0 251μs 4.07μs 39.1μs 0 0 0 203.98 KB
master StringConcatAspectBenchmark netcoreapp3.1 284μs 1.63μs 12.1μs 0 0 0 202.51 KB
master StringConcatAspectBenchmark net472 239μs 2.84μs 26.9μs 0 0 0 221.18 KB
#5159 StringConcatBenchmark net6.0 58.7μs 637ns 6.34μs 0 0 0 43.44 KB
#5159 StringConcatBenchmark netcoreapp3.1 54.3μs 298ns 2.45μs 0 0 0 42.64 KB
#5159 StringConcatBenchmark net472 38.2μs 102ns 383ns 0 0 0 59.26 KB
#5159 StringConcatAspectBenchmark net6.0 262μs 4.66μs 44.4μs 0 0 0 204.02 KB
#5159 StringConcatAspectBenchmark netcoreapp3.1 296μs 1.08μs 4.44μs 0 0 0 213.74 KB
#5159 StringConcatAspectBenchmark net472 225μs 1.12μs 4.61μs 0 0 0 221.18 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 EnrichedLog net6.0 1.51μs 2.18ns 8.17ns 0.0223 0 0 1.58 KB
master EnrichedLog netcoreapp3.1 2.26μs 3.22ns 12.1ns 0.0218 0 0 1.58 KB
master EnrichedLog net472 2.73μs 5.02ns 19.5ns 0.239 0 0 1.51 KB
#5159 EnrichedLog net6.0 1.44μs 0.572ns 2.21ns 0.0224 0 0 1.58 KB
#5159 EnrichedLog netcoreapp3.1 2.17μs 0.66ns 2.47ns 0.0207 0 0 1.58 KB
#5159 EnrichedLog net472 2.64μs 1.67ns 6.45ns 0.239 0 0 1.51 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 EnrichedLog net6.0 112μs 98.2ns 368ns 0.0562 0 0 4.22 KB
master EnrichedLog netcoreapp3.1 117μs 111ns 416ns 0.0582 0 0 4.22 KB
master EnrichedLog net472 148μs 43.7ns 169ns 0.662 0.221 0 4.4 KB
#5159 EnrichedLog net6.0 113μs 132ns 494ns 0 0 0 4.22 KB
#5159 EnrichedLog netcoreapp3.1 116μs 82.9ns 321ns 0 0 0 4.22 KB
#5159 EnrichedLog net472 148μs 60.9ns 228ns 0.661 0.22 0 4.4 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 EnrichedLog net6.0 3.12μs 1.04ns 3.75ns 0.0297 0 0 2.14 KB
master EnrichedLog netcoreapp3.1 4.06μs 1.28ns 4.61ns 0.0284 0 0 2.14 KB
master EnrichedLog net472 4.84μs 1.42ns 5.31ns 0.309 0 0 1.95 KB
#5159 EnrichedLog net6.0 2.88μs 0.898ns 3.36ns 0.0288 0 0 2.14 KB
#5159 EnrichedLog netcoreapp3.1 4.14μs 1.05ns 3.94ns 0.0288 0 0 2.14 KB
#5159 EnrichedLog net472 4.77μs 1.39ns 5.19ns 0.309 0 0 1.95 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 SendReceive net6.0 1.39μs 0.775ns 3ns 0.0152 0 0 1.11 KB
master SendReceive netcoreapp3.1 1.79μs 0.61ns 2.28ns 0.0152 0 0 1.11 KB
master SendReceive net472 2.18μs 3.19ns 12.4ns 0.178 0 0 1.12 KB
#5159 SendReceive net6.0 1.43μs 0.663ns 2.48ns 0.0157 0 0 1.11 KB
#5159 SendReceive netcoreapp3.1 1.79μs 0.573ns 2.15ns 0.0144 0 0 1.11 KB
#5159 SendReceive net472 2.16μs 1.27ns 4.57ns 0.178 0 0 1.12 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 EnrichedLog net6.0 2.77μs 0.611ns 2.37ns 0.0221 0 0 1.54 KB
master EnrichedLog netcoreapp3.1 3.98μs 2.2ns 8.52ns 0.0199 0 0 1.58 KB
master EnrichedLog net472 4.44μs 2.24ns 8.66ns 0.312 0 0 1.97 KB
#5159 EnrichedLog net6.0 2.69μs 1.11ns 4.31ns 0.0215 0 0 1.54 KB
#5159 EnrichedLog netcoreapp3.1 3.9μs 1.84ns 7.12ns 0.0214 0 0 1.58 KB
#5159 EnrichedLog net472 4.38μs 2.33ns 9.04ns 0.313 0 0 1.97 KB
Benchmarks.Trace.SpanBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5159

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0 1.140 438.19 499.41

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 438ns 0.141ns 0.545ns 0.00757 0 0 544 B
master StartFinishSpan netcoreapp3.1 689ns 0.606ns 2.27ns 0.00731 0 0 544 B
master StartFinishSpan net472 772ns 0.464ns 1.8ns 0.0867 0 0 546 B
master StartFinishScope net6.0 534ns 0.177ns 0.687ns 0.00941 0 0 664 B
master StartFinishScope netcoreapp3.1 871ns 0.243ns 0.941ns 0.00885 0 0 664 B
master StartFinishScope net472 988ns 0.431ns 1.67ns 0.0994 0 0 626 B
#5159 StartFinishSpan net6.0 499ns 0.153ns 0.594ns 0.00769 0 0 544 B
#5159 StartFinishSpan netcoreapp3.1 729ns 0.32ns 1.15ns 0.00732 0 0 544 B
#5159 StartFinishSpan net472 766ns 0.383ns 1.48ns 0.0867 0 0 546 B
#5159 StartFinishScope net6.0 536ns 0.129ns 0.484ns 0.00938 0 0 664 B
#5159 StartFinishScope netcoreapp3.1 807ns 0.39ns 1.51ns 0.00883 0 0 664 B
#5159 StartFinishScope net472 889ns 0.406ns 1.57ns 0.0993 0 0 626 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5159

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0 1.229 580.05 713.02

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net6.0 580ns 0.129ns 0.499ns 0.00935 0 0 664 B
master RunOnMethodBegin netcoreapp3.1 998ns 0.369ns 1.43ns 0.00893 0 0 664 B
master RunOnMethodBegin net472 1.05μs 0.569ns 2.2ns 0.0993 0 0 626 B
#5159 RunOnMethodBegin net6.0 713ns 0.289ns 1.12ns 0.00935 0 0 664 B
#5159 RunOnMethodBegin netcoreapp3.1 923ns 1.1ns 4.25ns 0.00904 0 0 664 B
#5159 RunOnMethodBegin net472 1.12μs 0.579ns 2.24ns 0.0992 0 0 626 B

andrewlock avatar Feb 07 '24 15:02 andrewlock

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 (5159) (11.377M)   : 0, 11377105
    master (11.441M)   : 0, 11441140
    benchmarks/2.9.0 (10.834M)   : 0, 10833884

    section Automatic
    This PR (5159) (7.746M)   : 0, 7745734
    master (7.668M)   : 0, 7667570
    benchmarks/2.9.0 (7.842M)   : 0, 7841734

    section Trace stats
    This PR (5159) (8.095M)   : 0, 8095156
    master (8.166M)   : 0, 8166448

    section Manual
    This PR (5159) (9.537M)   : 0, 9537225
    master (9.973M)   : 0, 9972807

    section Manual + Automatic
    This PR (5159) (7.189M)   : 0, 7188588
    master (7.456M)   : 0, 7456170

    section Version Conflict
    This PR (5159) (6.679M)   : 0, 6679331
    master (6.593M)   : 0, 6592685

gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5159) (9.536M)   : 0, 9535739
    master (9.813M)   : 0, 9813336
    benchmarks/2.9.0 (9.534M)   : 0, 9534497

    section Automatic
    This PR (5159) (6.620M)   : 0, 6619985
    master (6.742M)   : 0, 6741806

    section Trace stats
    This PR (5159) (6.861M)   : 0, 6861448
    master (6.893M)   : 0, 6893482

    section Manual
    This PR (5159) (8.071M)   : 0, 8071013
    master (8.334M)   : 0, 8333838

    section Manual + Automatic
    This PR (5159) (6.078M)   : 0, 6077928
    master (6.182M)   : 0, 6182245

    section Version Conflict
    This PR (5159) (5.625M)   : 0, 5624517
    master (5.596M)   : 0, 5595993

gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5159) (10.336M)   : 0, 10335661
    master (10.323M)   : 0, 10322809
    benchmarks/2.9.0 (10.178M)   : 0, 10178311

    section Automatic
    This PR (5159) (7.226M)   : 0, 7225691
    master (7.283M)   : 0, 7282890
    benchmarks/2.9.0 (7.446M)   : 0, 7445613

    section Trace stats
    This PR (5159) (7.633M)   : 0, 7633394
    master (7.607M)   : 0, 7607163

    section Manual
    This PR (5159) (8.863M)   : 0, 8862965
    master (9.021M)   : 0, 9021167

    section Manual + Automatic
    This PR (5159) (7.048M)   : 0, 7047862
    master (6.996M)   : 0, 6995693

    section Version Conflict
    This PR (5159) (6.436M)   : 0, 6436467
    master (6.440M)   : 0, 6439981

gantt
    title Throughput Linux x64 (ASM) (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    master (7.406M)   : 0, 7405870
    benchmarks/2.9.0 (7.752M)   : 0, 7751668

    section No attack
    master (1.828M)   : 0, 1827667
    benchmarks/2.9.0 (3.208M)   : 0, 3207733

    section Attack
    master (1.448M)   : 0, 1447929
    benchmarks/2.9.0 (2.458M)   : 0, 2457864

    section Blocking
    master (3.108M)   : 0, 3108020

    section IAST default
    master (6.401M)   : 0, 6400808

    section IAST full
    master (5.548M)   : 0, 5547501

    section Base vuln
    master (0.959M)   : 0, 959432

    section IAST vuln
    master (0.829M)   : 0, 829471

andrewlock avatar Feb 07 '24 18:02 andrewlock

Datadog Report

Branch report: vandonr/fix Commit report: 8c8a3e8 Test service: dd-trace-dotnet

:x: 54 Failed (0 Known Flaky), 309855 Passed, 1584 Skipped, 41m 16.66s Wall Time

:x: Failed Tests (54)

This report shows up to 5 failed tests.

  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.AWS.AwsSqsTests - Details

    Expand for error
    esult: False
    pan: {TraceId: 6465987959507131952, SpanId: 10571448108291069525, Name: aws.sqs.process, Resource: SQS.ReceiveMessage, Service: Samples.AWS.SQS}
    rrors:
     tag "aws.requestId" was expected to be present
     tag "http.method" was expected to be present
     tag "http.status_code" was expected to be present
     tag "http.url" was expected to be present
    xpected: True
    ctual:   False
    
  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.AWS.AwsSqsTests - Details

    Expand for error
    esult: False
    pan: {TraceId: 10386200809501191775, SpanId: 3354494531851482264, Name: sqs.request, Resource: SQS.ReceiveMessage, Service: Samples.AWS.SQS-aws-sqs}
    rrors:
     tag "aws.requestId" was expected to be present
     tag "http.method" was expected to be present
     tag "http.status_code" was expected to be present
     tag "http.url" was expected to be present
    xpected: True
    ctual:   False
    
  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.AWS.AwsSqsTests - Details

    Expand for error
    esult: False
    pan: {TraceId: 153190630327995036, SpanId: 14277808652665317408, Name: sqs.request, Resource: SQS.ReceiveMessage, Service: Samples.AWS.SQS-aws-sqs}
    rrors:
     tag "aws.requestId" was expected to be present
     tag "http.method" was expected to be present
     tag "http.status_code" was expected to be present
     tag "http.url" was expected to be present
    xpected: True
    ctual:   False
    
  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.AWS.AwsSqsTests - Details

    Expand for error
    esult: False
    pan: {TraceId: 2683667946166911789, SpanId: 7101174795195852272, Name: aws.sqs.process, Resource: SQS.ReceiveMessage, Service: Samples.AWS.SQS}
    rrors:
     tag "aws.requestId" was expected to be present
     tag "http.method" was expected to be present
     tag "http.status_code" was expected to be present
     tag "http.url" was expected to be present
    xpected: True
    ctual:   False
    
  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.AWS.AwsSqsTests - Details

    Expand for error
    esult: False
    pan: {TraceId: 5487197527506413412, SpanId: 677052317705066469, Name: sqs.request, Resource: SQS.ReceiveMessage, Service: Samples.AWS.SQS-aws-sqs}
    rrors:
     tag "aws.requestId" was expected to be present
     tag "http.method" was expected to be present
     tag "http.status_code" was expected to be present
     tag "http.url" was expected to be present
    xpected: True
    ctual:   False
    

datadog-ddstaging[bot] avatar Feb 19 '24 13:02 datadog-ddstaging[bot]