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

Add support for writing managed logs to stdout

Open andrewlock opened this issue 2 years ago • 7 comments

Summary of changes

Adds ~support~ experimental setting for writing managed logs to stdout/console

Reason for change

For testing in particular, this simplifies various things

Implementation details

Added a new sink

Test coverage

Basic coverage

Other details

Currently writes logs in the same format as the file logs. This means it likely isn't massively useful for customers (who will generally want JSON/custom templates) etc, but that isn't the target for now

APMSVLS-57 (@lucaspimentel)

andrewlock avatar Dec 27 '23 12:12 andrewlock

Datadog Report

Branch report: andrew/console-logs Commit report: d08b225

:x: dd-trace-dotnet: 1 Failed (0 Known Flaky), 0 New Flaky, 19314 Passed, 662 Skipped, 29m 31.73s Wall Time

:x: Failed Tests (1)

  • IntegrationDisabled - Datadog.Trace.ClrProfiler.IntegrationTests.TraceAnnotationsVersionMismatchBeforeFeatureTests - Details

    Expand for error
    xpected exit code: 0, actual exit code: -1073740791.
    

datadog-ddstaging[bot] avatar Dec 27 '23 13:12 datadog-ddstaging[bot]

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 (5005) - mean (70ms)  : 64, 77
     .   : milestone, 70,
    master - mean (71ms)  : 63, 80
     .   : milestone, 71,

    section CallTarget+Inlining+NGEN
    This PR (5005) - mean (1,030ms)  : 1009, 1051
     .   : milestone, 1030,
    master - mean (1,018ms)  : 1001, 1034
     .   : milestone, 1018,

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5005) - mean (106ms)  : 103, 110
     .   : milestone, 106,
    master - mean (106ms)  : 102, 110
     .   : milestone, 106,

    section CallTarget+Inlining+NGEN
    This PR (5005) - mean (732ms)  : 712, 753
     .   : milestone, 732,
    master - mean (721ms)  : 699, 744
     .   : milestone, 721,

gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5005) - mean (90ms)  : 88, 93
     .   : milestone, 90,
    master - mean (90ms)  : 83, 96
     .   : milestone, 90,

    section CallTarget+Inlining+NGEN
    This PR (5005) - mean (698ms)  : 676, 721
     .   : milestone, 698,
    master - mean (692ms)  : 671, 714
     .   : milestone, 692,

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

    section CallTarget+Inlining+NGEN
    This PR (5005) - mean (1,128ms)  : 1102, 1155
     .   : milestone, 1128,
    master - mean (1,126ms)  : 1098, 1154
     .   : milestone, 1126,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5005) - mean (272ms)  : 268, 277
     .   : milestone, 272,
    master - mean (273ms)  : 267, 278
     .   : milestone, 273,

    section CallTarget+Inlining+NGEN
    This PR (5005) - mean (1,078ms)  : 1055, 1100
     .   : milestone, 1078,
    master - mean (1,083ms)  : 1058, 1108
     .   : milestone, 1083,

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

    section CallTarget+Inlining+NGEN
    This PR (5005) - mean (1,052ms)  : 1025, 1080
     .   : milestone, 1052,
    master - mean (1,047ms)  : 1023, 1071
     .   : milestone, 1047,

andrewlock avatar Dec 27 '23 13:12 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 (5005) (10.807M)   : 0, 10806950
    master (11.071M)   : 0, 11070623
    benchmarks/2.9.0 (10.850M)   : 0, 10849500

    section Automatic
    This PR (5005) (7.507M)   : 0, 7507022
    master (7.621M)   : 0, 7621454
    benchmarks/2.9.0 (7.823M)   : 0, 7822730

    section Trace stats
    This PR (5005) (7.829M)   : 0, 7829101
    master (7.915M)   : 0, 7914703

    section Manual
    This PR (5005) (9.528M)   : 0, 9527526
    master (9.656M)   : 0, 9656230

    section Manual + Automatic
    This PR (5005) (7.075M)   : 0, 7075430
    master (7.357M)   : 0, 7357268

    section Version Conflict
    This PR (5005) (6.430M)   : crit ,0, 6430135
    master (6.783M)   : 0, 6783047

gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5005) (9.217M)   : 0, 9216690
    master (9.471M)   : 0, 9471361
    benchmarks/2.9.0 (9.680M)   : 0, 9679996

    section Automatic
    This PR (5005) (6.655M)   : 0, 6655007
    master (6.618M)   : 0, 6618111

    section Trace stats
    This PR (5005) (6.883M)   : 0, 6883431
    master (6.926M)   : 0, 6925986

    section Manual
    This PR (5005) (8.147M)   : 0, 8147497
    master (8.211M)   : 0, 8210732

    section Manual + Automatic
    This PR (5005) (6.124M)   : 0, 6124420
    master (6.248M)   : 0, 6247903

    section Version Conflict
    This PR (5005) (5.532M)   : 0, 5531541
    master (5.788M)   : 0, 5788282

gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5005) (10.874M)   : 0, 10874231
    master (10.761M)   : 0, 10760960
    benchmarks/2.9.0 (10.863M)   : 0, 10863181

    section Automatic
    This PR (5005) (7.636M)   : 0, 7635848
    master (7.646M)   : 0, 7646171
    benchmarks/2.9.0 (8.130M)   : 0, 8129748

    section Trace stats
    This PR (5005) (7.912M)   : 0, 7912116
    master (7.986M)   : 0, 7985757

    section Manual
    This PR (5005) (9.667M)   : 0, 9667210
    master (9.414M)   : 0, 9413937

    section Manual + Automatic
    This PR (5005) (7.313M)   : 0, 7312567
    master (7.309M)   : 0, 7309209

    section Version Conflict
    This PR (5005) (6.627M)   : 0, 6626744
    master (6.536M)   : 0, 6536418

gantt
    title Throughput Linux x64 (ASM) (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    master (7.290M)   : 0, 7289762
    benchmarks/2.9.0 (7.835M)   : 0, 7834738

    section No attack
    master (1.970M)   : 0, 1969964
    benchmarks/2.9.0 (3.201M)   : 0, 3200714

    section Attack
    master (1.572M)   : 0, 1571978
    benchmarks/2.9.0 (2.469M)   : 0, 2468672

    section Blocking
    master (3.262M)   : 0, 3262059

    section IAST default
    master (6.494M)   : 0, 6494125

    section IAST full
    master (5.795M)   : 0, 5794600

    section Base vuln
    master (0.933M)   : 0, 933398

    section IAST vuln
    master (0.871M)   : 0, 871187

andrewlock avatar Dec 27 '23 15:12 andrewlock

Benchmarks Report :snail:

Benchmarks for #5005 compared to master:

  • 2 benchmarks are faster, with geometric mean 1.155
  • 2 benchmarks are slower, with geometric mean 1.137
  • 2 benchmarks have fewer allocations
  • 2 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.9μs 48ns 280ns 0.0303 0.013 0.00433 7.48 KB
master StartStopWithChild netcoreapp3.1 10.9μs 60.3ns 372ns 0.0264 0.0106 0 7.58 KB
master StartStopWithChild net472 17.1μs 34.8ns 135ns 1.34 0.358 0.119 7.95 KB
#5005 StartStopWithChild net6.0 8.66μs 49.2ns 337ns 0.0206 0.00824 0 7.48 KB
#5005 StartStopWithChild netcoreapp3.1 10.4μs 50ns 212ns 0.0248 0.00991 0 7.57 KB
#5005 StartStopWithChild net472 17.1μs 44.2ns 171ns 1.34 0.352 0.117 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 450μs 324ns 1.17μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 616μs 197ns 736ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 777μs 383ns 1.48μs 0.386 0 0 3.3 KB
#5005 WriteAndFlushEnrichedTraces net6.0 463μs 176ns 682ns 0 0 0 2.7 KB
#5005 WriteAndFlushEnrichedTraces netcoreapp3.1 630μs 265ns 991ns 0 0 0 2.7 KB
#5005 WriteAndFlushEnrichedTraces net472 775μs 417ns 1.61μs 0.386 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 43.3μs 114ns 441ns 0.0219 0 0 1.77 KB
master AllCycleSimpleBody netcoreapp3.1 46.5μs 63.5ns 238ns 0 0 0 1.74 KB
master AllCycleSimpleBody net472 51μs 44.4ns 172ns 0.278 0 0 1.81 KB
master AllCycleMoreComplexBody net6.0 215μs 233ns 904ns 0.108 0 0 9.25 KB
master AllCycleMoreComplexBody netcoreapp3.1 243μs 191ns 714ns 0.122 0 0 9.14 KB
master AllCycleMoreComplexBody net472 239μs 86.9ns 325ns 1.43 0 0 9.32 KB
master ObjectExtractorSimpleBody net6.0 132ns 0.087ns 0.314ns 0.00395 0 0 280 B
master ObjectExtractorSimpleBody netcoreapp3.1 188ns 0.0637ns 0.247ns 0.0037 0 0 272 B
master ObjectExtractorSimpleBody net472 164ns 0.168ns 0.629ns 0.0446 0 0 281 B
master ObjectExtractorMoreComplexBody net6.0 2.82μs 1.06ns 4.1ns 0.0536 0 0 3.78 KB
master ObjectExtractorMoreComplexBody netcoreapp3.1 3.63μs 0.71ns 2.66ns 0.049 0 0 3.69 KB
master ObjectExtractorMoreComplexBody net472 3.4μs 1.11ns 4.16ns 0.603 0.00512 0 3.8 KB
#5005 AllCycleSimpleBody net6.0 43.7μs 46.3ns 179ns 0.022 0 0 1.77 KB
#5005 AllCycleSimpleBody netcoreapp3.1 47.6μs 67.3ns 252ns 0 0 0 1.74 KB
#5005 AllCycleSimpleBody net472 50.3μs 108ns 417ns 0.265 0 0 1.81 KB
#5005 AllCycleMoreComplexBody net6.0 215μs 95.9ns 372ns 0.106 0 0 9.25 KB
#5005 AllCycleMoreComplexBody netcoreapp3.1 225μs 243ns 909ns 0.112 0 0 9.14 KB
#5005 AllCycleMoreComplexBody net472 237μs 104ns 401ns 1.42 0 0 9.32 KB
#5005 ObjectExtractorSimpleBody net6.0 129ns 0.0456ns 0.171ns 0.00391 0 0 280 B
#5005 ObjectExtractorSimpleBody netcoreapp3.1 181ns 0.0933ns 0.361ns 0.00373 0 0 272 B
#5005 ObjectExtractorSimpleBody net472 150ns 0.113ns 0.437ns 0.0446 0 0 281 B
#5005 ObjectExtractorMoreComplexBody net6.0 2.8μs 1.87ns 7.23ns 0.0535 0 0 3.78 KB
#5005 ObjectExtractorMoreComplexBody netcoreapp3.1 3.58μs 1.29ns 4.99ns 0.0505 0 0 3.69 KB
#5005 ObjectExtractorMoreComplexBody net472 3.52μs 2.29ns 8.26ns 0.602 0.00528 0 3.8 KB
Benchmarks.Trace.Asm.AppSecWafBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5005

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.Asm.AppSecWafBenchmark.RunWaf(args: NestedMap (10))‑net6.0 1.133 49,221.06 55,752.15

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunWaf(args=NestedMap (10)) net6.0 49.2μs 20.7ns 74.5ns 0.222 0 0 16.06 KB
master RunWaf(args=NestedMap (10)) netcoreapp3.1 70.9μs 333ns 1.29μs 0.212 0 0 16.06 KB
master RunWaf(args=NestedMap (10)) net472 98.1μs 521ns 2.95μs 2.56 0.0947 0 16.14 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 117μs 52.2ns 188ns 0.301 0 0 22.41 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 134μs 72.6ns 262ns 0.286 0 0 22.36 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net472 172μs 857ns 3.64μs 3.56 0.166 0 22.7 KB
master RunWaf(args=NestedMap (100)) net6.0 96.8μs 26.7ns 103ns 0.436 0 0 32.76 KB
master RunWaf(args=NestedMap (100)) netcoreapp3.1 131μs 681ns 3.47μs 0.405 0 0 33.33 KB
master RunWaf(args=NestedMap (100)) net472 189μs 891ns 3.45μs 5.32 0.367 0 33.67 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) net6.0 165μs 58.8ns 220ns 0.493 0 0 39.1 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) netcoreapp3.1 209μs 1.01μs 3.9μs 0.528 0 0 39.63 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) net472 271μs 202ns 783ns 6.38 0.521 0 40.23 KB
master RunWaf(args=NestedMap (20)) net6.0 102μs 570ns 3.56μs 0.423 0 0 32.18 KB
master RunWaf(args=NestedMap (20)) netcoreapp3.1 137μs 109ns 424ns 0.433 0 0 32.3 KB
master RunWaf(args=NestedMap (20)) net472 186μs 931ns 4.06μs 5.16 0.362 0 32.63 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 172μs 847ns 3.88μs 0.523 0 0 38.53 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 209μs 1.15μs 6.59μs 0.498 0 0 38.6 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net472 264μs 248ns 959ns 6.17 0.536 0 39.2 KB
#5005 RunWaf(args=NestedMap (10)) net6.0 55.7μs 73.6ns 285ns 0.22 0 0 16.06 KB
#5005 RunWaf(args=NestedMap (10)) netcoreapp3.1 69.2μs 47.6ns 172ns 0.212 0 0 16.06 KB
#5005 RunWaf(args=NestedMap (10)) net472 97μs 491ns 2.3μs 2.53 0.0938 0 16.14 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 118μs 46.6ns 181ns 0.29 0 0 22.41 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 133μs 98.6ns 355ns 0.268 0 0 22.36 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [22]) net472 165μs 187ns 724ns 3.58 0.166 0 22.7 KB
#5005 RunWaf(args=NestedMap (100)) net6.0 96.2μs 104ns 402ns 0.439 0 0 32.76 KB
#5005 RunWaf(args=NestedMap (100)) netcoreapp3.1 136μs 309ns 1.2μs 0.408 0 0 33.33 KB
#5005 RunWaf(args=NestedMap (100)) net472 188μs 680ns 2.63μs 5.35 0.369 0 33.67 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [23]) net6.0 178μs 1.03μs 7.9μs 0.535 0 0 39.1 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [23]) netcoreapp3.1 213μs 437ns 1.69μs 0.532 0 0 39.63 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [23]) net472 270μs 1.26μs 4.87μs 6.28 0.401 0 40.23 KB
#5005 RunWaf(args=NestedMap (20)) net6.0 95.4μs 28.4ns 110ns 0.428 0 0 32.18 KB
#5005 RunWaf(args=NestedMap (20)) netcoreapp3.1 133μs 129ns 482ns 0.408 0 0 32.3 KB
#5005 RunWaf(args=NestedMap (20)) net472 188μs 849ns 3.29μs 5.18 0.363 0 32.63 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 177μs 107ns 414ns 0.503 0 0 38.53 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 206μs 542ns 1.96μs 0.417 0 0 38.6 KB
#5005 RunWafWithAttack(args=Neste(...)tack) [22]) net472 260μs 284ns 1.1μs 6.17 0.514 0 39.2 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 115ns 447ns 0.257 0 0 18.25 KB
master SendRequest netcoreapp3.1 194μs 209ns 783ns 0.193 0 0 20.41 KB
master SendRequest net472 0.000212ns 0.000113ns 0.000421ns 0 0 0 0 b
#5005 SendRequest net6.0 169μs 218ns 844ns 0.253 0 0 18.25 KB
#5005 SendRequest netcoreapp3.1 193μs 331ns 1.28μs 0.192 0 0 20.41 KB
#5005 SendRequest net472 0.000688ns 0.000272ns 0.00102ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed :heavy_check_mark: Fewer allocations :tada:

Fewer allocations :tada: in #5005

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0 41.63 KB 41.4 KB -231 B -0.55%
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑netcoreapp3.1 42 KB 41.59 KB -413 B -0.98%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 557μs 2.68μs 11.1μs 0.539 0 0 41.63 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 655μs 879ns 3.29μs 0.329 0 0 42 KB
master WriteAndFlushEnrichedTraces net472 855μs 4.12μs 16.5μs 8.39 2.52 0.419 53.22 KB
#5005 WriteAndFlushEnrichedTraces net6.0 535μs 257ns 961ns 0.527 0 0 41.4 KB
#5005 WriteAndFlushEnrichedTraces netcoreapp3.1 653μs 796ns 3.08μs 0.324 0 0 41.59 KB
#5005 WriteAndFlushEnrichedTraces net472 898μs 2.98μs 11.6μs 8.42 2.66 0.443 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 ExecuteNonQuery net6.0 1.15μs 0.619ns 2.4ns 0.0104 0 0 768 B
master ExecuteNonQuery netcoreapp3.1 1.46μs 1.85ns 7.15ns 0.0101 0 0 768 B
master ExecuteNonQuery net472 1.83μs 0.849ns 3.18ns 0.115 0 0 730 B
#5005 ExecuteNonQuery net6.0 1.06μs 0.332ns 1.24ns 0.0106 0 0 768 B
#5005 ExecuteNonQuery netcoreapp3.1 1.52μs 3.99ns 15.4ns 0.0105 0 0 768 B
#5005 ExecuteNonQuery net472 1.87μs 0.733ns 2.74ns 0.115 0 0 730 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.12μs 0.596ns 2.31ns 0.0129 0 0 936 B
master CallElasticsearch netcoreapp3.1 1.58μs 2.1ns 8.15ns 0.0127 0 0 936 B
master CallElasticsearch net472 2.6μs 0.659ns 2.55ns 0.152 0 0 955 B
master CallElasticsearchAsync net6.0 1.27μs 0.62ns 2.4ns 0.0127 0 0 912 B
master CallElasticsearchAsync netcoreapp3.1 1.65μs 0.752ns 2.71ns 0.0134 0 0 984 B
master CallElasticsearchAsync net472 2.73μs 1.85ns 6.68ns 0.161 0 0 1.01 KB
#5005 CallElasticsearch net6.0 1.17μs 0.226ns 0.846ns 0.0129 0 0 936 B
#5005 CallElasticsearch netcoreapp3.1 1.53μs 0.993ns 3.58ns 0.0123 0 0 936 B
#5005 CallElasticsearch net472 2.61μs 0.514ns 1.92ns 0.151 0.0013 0 955 B
#5005 CallElasticsearchAsync net6.0 1.21μs 0.613ns 2.38ns 0.0128 0 0 912 B
#5005 CallElasticsearchAsync netcoreapp3.1 1.57μs 0.811ns 3.03ns 0.0135 0 0 984 B
#5005 CallElasticsearchAsync net472 2.76μs 1.3ns 5.03ns 0.16 0.00138 0 1.01 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.34μs 1.44ns 5.58ns 0.0126 0 0 912 B
master ExecuteAsync netcoreapp3.1 1.54μs 0.328ns 1.23ns 0.0123 0 0 912 B
master ExecuteAsync net472 1.89μs 0.291ns 1.09ns 0.139 0 0 875 B
#5005 ExecuteAsync net6.0 1.25μs 1.29ns 4.98ns 0.0126 0 0 912 B
#5005 ExecuteAsync netcoreapp3.1 1.7μs 0.407ns 1.47ns 0.012 0 0 912 B
#5005 ExecuteAsync net472 1.8μs 0.863ns 3.34ns 0.138 0.000905 0 875 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.12μs 2.35ns 8.78ns 0.0288 0 0 2.1 KB
master SendAsync netcoreapp3.1 4.92μs 2.16ns 8.35ns 0.0345 0 0 2.63 KB
master SendAsync net472 7.67μs 2.76ns 10.7ns 0.525 0 0 3.31 KB
#5005 SendAsync net6.0 3.95μs 2.06ns 7.99ns 0.0296 0 0 2.1 KB
#5005 SendAsync netcoreapp3.1 4.87μs 1.53ns 5.93ns 0.0342 0 0 2.63 KB
#5005 SendAsync net472 7.67μs 2.62ns 10.1ns 0.523 0 0 3.31 KB
Benchmarks.Trace.Iast.StringAspectsBenchmark - Same speed :heavy_check_mark: More allocations :warning:

More allocations :warning: in #5005

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark(parameters: System.Collections.Generic.List`1[System.String])‑net472 57.34 KB 73.73 KB 16.38 KB 28.57%
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatBenchmark(parameters: System.Collections.Generic.List`1[System.String])‑net472 58.37 KB 59.82 KB 1.45 KB 2.48%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StringConcatBenchmark(parameters=Syste(...)ring] [48]) net6.0 53.7μs 279ns 1.42μs 0 0 0 43.44 KB
master StringConcatBenchmark(parameters=Syste(...)ring] [48]) netcoreapp3.1 54.2μs 298ns 1.69μs 0 0 0 42.64 KB
master StringConcatBenchmark(parameters=Syste(...)ring] [48]) net472 38.6μs 211ns 1.18μs 0 0 0 58.37 KB
master StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) net6.0 100μs 2.89μs 28.9μs 0 0 0 43.29 KB
master StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) netcoreapp3.1 102μs 3.25μs 31.9μs 0 0 0 42.64 KB
master StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) net472 64.3μs 295ns 1.47μs 0 0 0 57.34 KB
#5005 StringConcatBenchmark(parameters=Syste(...)ring] [48]) net6.0 51.7μs 233ns 871ns 0 0 0 43.44 KB
#5005 StringConcatBenchmark(parameters=Syste(...)ring] [48]) netcoreapp3.1 59.8μs 682ns 6.72μs 0 0 0 42.64 KB
#5005 StringConcatBenchmark(parameters=Syste(...)ring] [48]) net472 38.5μs 159ns 552ns 0 0 0 59.82 KB
#5005 StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) net6.0 97.1μs 2.78μs 27.8μs 0 0 0 43.29 KB
#5005 StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) netcoreapp3.1 115μs 3.13μs 31.3μs 0 0 0 42.64 KB
#5005 StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) net472 68.1μs 515ns 4.8μs 0 0 0 73.73 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.4μs 1.17ns 4.38ns 0.0221 0 0 1.57 KB
master EnrichedLog netcoreapp3.1 2.33μs 1.17ns 4.39ns 0.0211 0 0 1.57 KB
master EnrichedLog net472 2.52μs 2.21ns 7.95ns 0.238 0 0 1.5 KB
#5005 EnrichedLog net6.0 1.38μs 0.652ns 2.44ns 0.0221 0 0 1.57 KB
#5005 EnrichedLog netcoreapp3.1 2.27μs 0.501ns 1.81ns 0.0214 0 0 1.57 KB
#5005 EnrichedLog net472 2.57μs 3.02ns 11.7ns 0.238 0 0 1.5 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 116μs 140ns 525ns 0.0582 0 0 4.21 KB
master EnrichedLog netcoreapp3.1 119μs 248ns 960ns 0 0 0 4.21 KB
master EnrichedLog net472 147μs 151ns 584ns 0.658 0.219 0 4.39 KB
#5005 EnrichedLog net6.0 112μs 59.5ns 223ns 0 0 0 4.21 KB
#5005 EnrichedLog netcoreapp3.1 120μs 142ns 549ns 0.06 0 0 4.21 KB
#5005 EnrichedLog net472 150μs 119ns 446ns 0.673 0.224 0 4.39 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.15μs 1.13ns 4.39ns 0.0297 0 0 2.13 KB
master EnrichedLog netcoreapp3.1 4.09μs 1.47ns 5.7ns 0.0275 0 0 2.13 KB
master EnrichedLog net472 5.02μs 1.58ns 6.13ns 0.308 0 0 1.95 KB
#5005 EnrichedLog net6.0 3.04μs 1.92ns 7.18ns 0.0291 0 0 2.13 KB
#5005 EnrichedLog netcoreapp3.1 4.28μs 2.5ns 9.69ns 0.0277 0 0 2.13 KB
#5005 EnrichedLog net472 4.91μs 1.85ns 7.17ns 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.31μs 0.772ns 2.89ns 0.0157 0 0 1.1 KB
master SendReceive netcoreapp3.1 1.71μs 0.771ns 2.99ns 0.0145 0 0 1.1 KB
master SendReceive net472 2.1μs 0.942ns 3.52ns 0.177 0 0 1.12 KB
#5005 SendReceive net6.0 1.29μs 0.914ns 3.42ns 0.0155 0 0 1.1 KB
#5005 SendReceive netcoreapp3.1 1.68μs 1.45ns 5.61ns 0.0144 0 0 1.1 KB
#5005 SendReceive net472 2.18μs 2.5ns 9.7ns 0.177 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.68μs 0.7ns 2.62ns 0.0214 0 0 1.53 KB
master EnrichedLog netcoreapp3.1 3.87μs 3.34ns 12.9ns 0.0212 0 0 1.58 KB
master EnrichedLog net472 4.25μs 1.36ns 5.27ns 0.31 0 0 1.97 KB
#5005 EnrichedLog net6.0 2.82μs 0.773ns 2.89ns 0.0213 0 0 1.53 KB
#5005 EnrichedLog netcoreapp3.1 3.88μs 1.7ns 5.89ns 0.0195 0 0 1.58 KB
#5005 EnrichedLog net472 4.4μs 1.7ns 6.35ns 0.312 0 0 1.97 KB
Benchmarks.Trace.SpanBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5005

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net472 1.142 754.19 861.40

Faster :tada: in #5005

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0 1.173 660.92 563.58
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑netcoreapp3.1 1.138 919.53 808.26

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 534ns 0.223ns 0.866ns 0.00751 0 0 536 B
master StartFinishSpan netcoreapp3.1 749ns 0.251ns 0.97ns 0.00706 0 0 536 B
master StartFinishSpan net472 754ns 0.257ns 0.996ns 0.0853 0 0 538 B
master StartFinishScope net6.0 661ns 0.186ns 0.719ns 0.00901 0 0 656 B
master StartFinishScope netcoreapp3.1 921ns 1.08ns 4.2ns 0.00872 0 0 656 B
master StartFinishScope net472 965ns 0.737ns 2.85ns 0.098 0 0 618 B
#5005 StartFinishSpan net6.0 555ns 0.169ns 0.633ns 0.00759 0 0 536 B
#5005 StartFinishSpan netcoreapp3.1 707ns 0.171ns 0.664ns 0.00714 0 0 536 B
#5005 StartFinishSpan net472 862ns 0.414ns 1.6ns 0.0852 0 0 538 B
#5005 StartFinishScope net6.0 564ns 0.354ns 1.37ns 0.00921 0 0 656 B
#5005 StartFinishScope netcoreapp3.1 808ns 0.283ns 1.1ns 0.00887 0 0 656 B
#5005 StartFinishScope net472 996ns 0.173ns 0.668ns 0.0981 0 0 618 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 RunOnMethodBegin net6.0 630ns 0.185ns 0.716ns 0.00918 0 0 656 B
master RunOnMethodBegin netcoreapp3.1 919ns 0.4ns 1.5ns 0.00878 0 0 656 B
master RunOnMethodBegin net472 1.17μs 0.309ns 1.16ns 0.098 0 0 618 B
#5005 RunOnMethodBegin net6.0 682ns 0.668ns 2.59ns 0.0092 0 0 656 B
#5005 RunOnMethodBegin netcoreapp3.1 916ns 0.338ns 1.31ns 0.00894 0 0 656 B
#5005 RunOnMethodBegin net472 1.17μs 0.31ns 1.2ns 0.0981 0 0 618 B

andrewlock avatar Dec 27 '23 18:12 andrewlock