dd-trace-dotnet icon indicating copy to clipboard operation
dd-trace-dotnet copied to clipboard
verified publisher icon DataDog

[Profiler] Fix bug when create thread lifetime event

Open gleocadie opened this issue 1 year ago • 3 comments

Summary of changes

Fix a bug when creating thread lifetime events.

Reason for change

Currently thread lifetime samples (which contain the event label set to thread start or thread stop) are not attached to any application and feel like the events are lost 😢

Implementation details

  • set AppDomainId field to the thread app domain id.

Test coverage

Other details

gleocadie avatar Jul 03 '24 13:07 gleocadie

Datadog Report

Branch report: gleocadie/fix-thread-lifetime-event Commit report: e79639f Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 349082 Passed, 2072 Skipped, 15h 48m 15.77s Total Time :hourglass: 2 Performance Regressions

:hourglass: Performance Regressions vs Default Branch (2)

  • Baseline_exception - scenarios 3.99s (+124.11ms, +3%) - Details
  • Profiler_liveheap_cpu_walltime - scenarios 4.55s (+208.05ms, +5%) - Details

datadog-ddstaging[bot] avatar Jul 03 '24 13:07 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 (5769) - mean (75ms)  : 64, 87
     .   : milestone, 75,
    master - mean (73ms)  : 63, 82
     .   : milestone, 73,

    section CallTarget+Inlining+NGEN
    This PR (5769) - mean (1,048ms)  : 1027, 1069
     .   : milestone, 1048,
    master - mean (1,046ms)  : 1029, 1064
     .   : milestone, 1046,


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

    section CallTarget+Inlining+NGEN
    This PR (5769) - mean (756ms)  : 733, 778
     .   : milestone, 756,
    master - mean (748ms)  : 729, 766
     .   : milestone, 748,


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

    section CallTarget+Inlining+NGEN
    This PR (5769) - mean (702ms)  : 677, 727
     .   : milestone, 702,
    master - mean (701ms)  : 679, 722
     .   : milestone, 701,


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

    section CallTarget+Inlining+NGEN
    This PR (5769) - mean (1,185ms)  : 1158, 1213
     .   : milestone, 1185,
    master - mean (1,179ms)  : 1153, 1204
     .   : milestone, 1179,


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

    section CallTarget+Inlining+NGEN
    This PR (5769) - mean (964ms)  : 944, 985
     .   : milestone, 964,
    master - mean (970ms)  : 942, 998
     .   : milestone, 970,


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

    section CallTarget+Inlining+NGEN
    This PR (5769) - mean (943ms)  : 918, 968
     .   : milestone, 943,
    master - mean (946ms)  : 922, 970
     .   : milestone, 946,

andrewlock avatar Jul 03 '24 13:07 andrewlock

Benchmarks Report for tracer :snail:

Benchmarks for #5769 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.161
  • 2 benchmarks are slower, with geometric mean 1.144
  • All benchmarks have the same 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 7.69μs 42.6ns 269ns 0.0116 0.00385 0 5.43 KB
master StartStopWithChild netcoreapp3.1 10μs 51.3ns 325ns 0.0149 0.00497 0 5.62 KB
master StartStopWithChild net472 16.3μs 75.1ns 291ns 1.03 0.326 0.103 6.07 KB
#5769 StartStopWithChild net6.0 7.71μs 43.6ns 293ns 0.0155 0.00776 0 5.43 KB
#5769 StartStopWithChild netcoreapp3.1 9.72μs 54.1ns 329ns 0.0142 0.00474 0 5.62 KB
#5769 StartStopWithChild net472 16.7μs 76.3ns 295ns 1.01 0.29 0.083 6.07 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 470μs 147ns 571ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 651μs 133ns 479ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 822μs 258ns 964ns 0.408 0 0 3.3 KB
#5769 WriteAndFlushEnrichedTraces net6.0 480μs 233ns 901ns 0 0 0 2.7 KB
#5769 WriteAndFlushEnrichedTraces netcoreapp3.1 643μs 141ns 529ns 0 0 0 2.7 KB
#5769 WriteAndFlushEnrichedTraces net472 830μs 239ns 863ns 0.411 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 SendRequest net6.0 173μs 213ns 825ns 0.257 0 0 18.45 KB
master SendRequest netcoreapp3.1 189μs 285ns 1.1μs 0.188 0 0 20.61 KB
master SendRequest net472 2.75E‑05ns 2.75E‑05ns 9.91E‑05ns 0 0 0 0 b
#5769 SendRequest net6.0 173μs 209ns 808ns 0.175 0 0 18.45 KB
#5769 SendRequest netcoreapp3.1 193μs 222ns 860ns 0.191 0 0 20.61 KB
#5769 SendRequest net472 0.000988ns 0.000294ns 0.00114ns 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 537μs 256ns 958ns 0.551 0 0 41.61 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 652μs 896ns 3.1μs 0.331 0 0 41.66 KB
master WriteAndFlushEnrichedTraces net472 884μs 2.29μs 8.86μs 8.08 2.55 0.425 53.24 KB
#5769 WriteAndFlushEnrichedTraces net6.0 527μs 215ns 805ns 0.523 0 0 41.48 KB
#5769 WriteAndFlushEnrichedTraces netcoreapp3.1 647μs 573ns 2.15μs 0.327 0 0 41.67 KB
#5769 WriteAndFlushEnrichedTraces net472 856μs 4.15μs 16.6μs 8.45 2.53 0.422 53.26 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.23μs 1.06ns 3.95ns 0.0142 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.71μs 0.449ns 1.68ns 0.0136 0 0 1.02 KB
master ExecuteNonQuery net472 1.94μs 0.708ns 2.74ns 0.156 0 0 987 B
#5769 ExecuteNonQuery net6.0 1.35μs 0.748ns 2.9ns 0.0144 0 0 1.02 KB
#5769 ExecuteNonQuery netcoreapp3.1 1.66μs 0.522ns 1.95ns 0.0133 0 0 1.02 KB
#5769 ExecuteNonQuery net472 2.07μs 2ns 7.76ns 0.156 0 0 987 B
Benchmarks.Trace.ElasticsearchBenchmark - Faster :tada: Same allocations :heavy_check_mark:

Faster :tada: in #5769

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearch‑net6.0 1.161 1,358.75 1,170.42

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net6.0 1.36μs 0.731ns 2.83ns 0.0136 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.5μs 1.02ns 3.95ns 0.0127 0 0 976 B
master CallElasticsearch net472 2.51μs 1.85ns 7.15ns 0.158 0 0 995 B
master CallElasticsearchAsync net6.0 1.26μs 2.23ns 8.35ns 0.0131 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.63μs 0.776ns 3.01ns 0.0137 0 0 1.02 KB
master CallElasticsearchAsync net472 2.71μs 1.15ns 4.45ns 0.166 0 0 1.05 KB
#5769 CallElasticsearch net6.0 1.17μs 0.893ns 3.22ns 0.0135 0 0 976 B
#5769 CallElasticsearch netcoreapp3.1 1.56μs 1.34ns 5.17ns 0.0134 0 0 976 B
#5769 CallElasticsearch net472 2.58μs 1.16ns 4.49ns 0.158 0.00128 0 995 B
#5769 CallElasticsearchAsync net6.0 1.3μs 0.392ns 1.47ns 0.0131 0 0 952 B
#5769 CallElasticsearchAsync netcoreapp3.1 1.6μs 1.36ns 5.28ns 0.0136 0 0 1.02 KB
#5769 CallElasticsearchAsync net472 2.68μs 2.87ns 11.1ns 0.167 0.00135 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 ExecuteAsync net6.0 1.21μs 0.75ns 2.91ns 0.0134 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.71μs 0.88ns 3.41ns 0.0128 0 0 952 B
master ExecuteAsync net472 1.81μs 1.42ns 5.49ns 0.145 0 0 915 B
#5769 ExecuteAsync net6.0 1.19μs 0.331ns 1.24ns 0.0131 0 0 952 B
#5769 ExecuteAsync netcoreapp3.1 1.66μs 0.864ns 3.35ns 0.0125 0 0 952 B
#5769 ExecuteAsync net472 1.74μs 0.571ns 2.21ns 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 SendAsync net6.0 4.19μs 1.03ns 3.99ns 0.0295 0 0 2.22 KB
master SendAsync netcoreapp3.1 5.14μs 2.93ns 11.3ns 0.0358 0 0 2.76 KB
master SendAsync net472 7.65μs 6.75ns 26.2ns 0.498 0 0 3.15 KB
#5769 SendAsync net6.0 4.14μs 1.52ns 5.68ns 0.0312 0 0 2.22 KB
#5769 SendAsync netcoreapp3.1 4.98μs 2.34ns 9.05ns 0.0372 0 0 2.76 KB
#5769 SendAsync net472 7.6μs 3.1ns 12ns 0.498 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 EnrichedLog net6.0 1.59μs 0.773ns 2.99ns 0.0231 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.19μs 0.669ns 2.59ns 0.0217 0 0 1.64 KB
master EnrichedLog net472 2.57μs 2.45ns 8.82ns 0.249 0 0 1.57 KB
#5769 EnrichedLog net6.0 1.43μs 0.596ns 2.31ns 0.0229 0 0 1.64 KB
#5769 EnrichedLog netcoreapp3.1 2.14μs 1.14ns 4.25ns 0.0225 0 0 1.64 KB
#5769 EnrichedLog net472 2.51μs 1.13ns 4.39ns 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 EnrichedLog net6.0 115μs 281ns 1.09μs 0.0572 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 118μs 171ns 641ns 0.0588 0 0 4.28 KB
master EnrichedLog net472 149μs 115ns 445ns 0.67 0.223 0 4.46 KB
#5769 EnrichedLog net6.0 114μs 98.1ns 380ns 0.0569 0 0 4.28 KB
#5769 EnrichedLog netcoreapp3.1 118μs 63.3ns 237ns 0 0 0 4.28 KB
#5769 EnrichedLog net472 147μs 162ns 627ns 0.658 0.219 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 EnrichedLog net6.0 2.89μs 11.7ns 46.9ns 0.0316 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.14μs 7.49ns 29ns 0.0289 0 0 2.2 KB
master EnrichedLog net472 4.77μs 1.22ns 4.73ns 0.321 0 0 2.02 KB
#5769 EnrichedLog net6.0 3.03μs 1.15ns 4.46ns 0.0304 0 0 2.2 KB
#5769 EnrichedLog netcoreapp3.1 4.1μs 1.12ns 4.05ns 0.0287 0 0 2.2 KB
#5769 EnrichedLog net472 4.88μs 1.04ns 4.01ns 0.321 0 0 2.02 KB
Benchmarks.Trace.RedisBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5769

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.RedisBenchmark.SendReceive‑net6.0 1.121 1,228.39 1,377.61

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net6.0 1.23μs 0.673ns 2.61ns 0.016 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.7μs 0.833ns 3.22ns 0.0154 0 0 1.14 KB
master SendReceive net472 2.05μs 1.92ns 7.42ns 0.183 0 0 1.16 KB
#5769 SendReceive net6.0 1.38μs 0.96ns 3.72ns 0.0158 0 0 1.14 KB
#5769 SendReceive netcoreapp3.1 1.66μs 0.828ns 3.21ns 0.0151 0 0 1.14 KB
#5769 SendReceive net472 2μs 0.723ns 2.51ns 0.183 0.001 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 EnrichedLog net6.0 2.55μs 0.8ns 3.1ns 0.0224 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.95μs 3.66ns 14.2ns 0.0216 0 0 1.65 KB
master EnrichedLog net472 4.33μs 1.24ns 4.66ns 0.322 0 0 2.04 KB
#5769 EnrichedLog net6.0 2.69μs 0.977ns 3.65ns 0.0229 0 0 1.6 KB
#5769 EnrichedLog netcoreapp3.1 3.77μs 2.96ns 11.5ns 0.0226 0 0 1.65 KB
#5769 EnrichedLog net472 4.38μs 2.21ns 8.28ns 0.324 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - Slower :warning: Same allocations :heavy_check_mark:

Slower :warning: in #5769

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net472 1.167 570.03 665.19

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 443ns 0.117ns 0.452ns 0.00805 0 0 576 B
master StartFinishSpan netcoreapp3.1 632ns 0.309ns 1.2ns 0.00777 0 0 576 B
master StartFinishSpan net472 570ns 0.444ns 1.72ns 0.0917 0 0 578 B
master StartFinishScope net6.0 538ns 0.173ns 0.668ns 0.0097 0 0 696 B
master StartFinishScope netcoreapp3.1 758ns 0.334ns 1.25ns 0.00937 0 0 696 B
master StartFinishScope net472 845ns 0.472ns 1.83ns 0.104 0 0 658 B
#5769 StartFinishSpan net6.0 407ns 0.135ns 0.521ns 0.00811 0 0 576 B
#5769 StartFinishSpan netcoreapp3.1 571ns 0.141ns 0.546ns 0.00769 0 0 576 B
#5769 StartFinishSpan net472 665ns 0.616ns 2.39ns 0.0916 0 0 578 B
#5769 StartFinishScope net6.0 534ns 0.153ns 0.592ns 0.00963 0 0 696 B
#5769 StartFinishScope netcoreapp3.1 749ns 1.2ns 4.66ns 0.00964 0 0 696 B
#5769 StartFinishScope net472 827ns 0.555ns 2.15ns 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 RunOnMethodBegin net6.0 637ns 0.725ns 2.81ns 0.00964 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 871ns 1.5ns 5.81ns 0.00943 0 0 696 B
master RunOnMethodBegin net472 1.08μs 0.228ns 0.852ns 0.104 0 0 658 B
#5769 RunOnMethodBegin net6.0 660ns 0.183ns 0.685ns 0.00958 0 0 696 B
#5769 RunOnMethodBegin netcoreapp3.1 931ns 0.378ns 1.46ns 0.00936 0 0 696 B
#5769 RunOnMethodBegin net472 1.06μs 0.426ns 1.59ns 0.104 0 0 658 B

andrewlock avatar Jul 03 '24 14:07 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 (5769) (11.977M)   : 0, 11976988
    master (11.881M)   : 0, 11880597
    benchmarks/2.9.0 (11.915M)   : 0, 11914657

    section Automatic
    This PR (5769) (8.123M)   : 0, 8123028
    master (8.047M)   : 0, 8046727
    benchmarks/2.9.0 (8.513M)   : 0, 8513066

    section Trace stats
    master (8.464M)   : 0, 8463773

    section Manual
    This PR (5769) (10.296M)   : 0, 10296373
    master (10.247M)   : 0, 10246957

    section Manual + Automatic
    This PR (5769) (7.680M)   : 0, 7680251
    master (7.578M)   : 0, 7577515

    section Version Conflict
    master (6.707M)   : 0, 6707065


gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5769) (9.567M)   : 0, 9566743
    benchmarks/2.9.0 (9.711M)   : 0, 9711350

    section Automatic
    This PR (5769) (6.556M)   : 0, 6555613

    section Manual
    This PR (5769) (8.439M)   : 0, 8438932

    section Manual + Automatic
    This PR (5769) (6.199M)   : 0, 6199117


gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (5769) (9.725M)   : 0, 9724502
    master (10.099M)   : 0, 10099485

    section Automatic
    This PR (5769) (6.823M)   : 0, 6823494
    master (7.144M)   : 0, 7143660

    section Trace stats
    master (7.418M)   : 0, 7418021

    section Manual
    This PR (5769) (8.697M)   : 0, 8697266
    master (8.900M)   : 0, 8899902

    section Manual + Automatic
    This PR (5769) (6.678M)   : 0, 6678045
    master (6.862M)   : 0, 6861859

    section Version Conflict
    master (6.305M)   : 0, 6305249

andrewlock avatar Jul 05 '24 15:07 andrewlock