Skip to content

[Profiler] Provide the thread id that blocked another thread#5959

Merged
gleocadie merged 1 commit into
masterfrom
gleocadie/add-lock-holder-contention
Aug 29, 2024
Merged

[Profiler] Provide the thread id that blocked another thread#5959
gleocadie merged 1 commit into
masterfrom
gleocadie/add-lock-holder-contention

Conversation

@gleocadie

@gleocadie gleocadie commented Aug 28, 2024 •
edited
Loading

Copy link
Copy Markdown
Collaborator

Summary of changes

Provides the thread id of that owns a lock object.

Reason for change

New feature.

Implementation details

The ContentionStart event contains information about the contented lock and the thread that owns it. Remember the OS Thread Id of the thread that owns the lock object and use it when creating a sample.

Test coverage

Add asserts on the existing tests.

Other details

@datadog-ddstaging

datadog-ddstaging Bot commented Aug 28, 2024 •
edited
Loading

Copy link
Copy Markdown

Datadog Report

Branch report: gleocadie/add-lock-holder-contention
Commit report: e723bbb
Test service: dd-trace-dotnet

✅ 0 Failed, 362436 Passed, 2328 Skipped, 15h 56m 53.4s Total Time
⌛ 1 Performance Regression

⌛ Performance Regressions vs Default Branch (1)

  • Profiler_contention_cpu_walltime - scenarios 2.53s (+214.64ms, +9%) - Details

@andrewlock

andrewlock commented Aug 28, 2024 •
edited
Loading

Copy link
Copy Markdown
Member

Execution-Time Benchmarks Report ⏱️

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).

@gleocadie
gleocadie force-pushed the gleocadie/add-lock-holder-contention branch from f4cfa4f to 5551ad1 Compare August 28, 2024 18:09
@andrewlock

andrewlock commented Aug 28, 2024 •
edited
Loading

Copy link
Copy Markdown
Member

Benchmarks Report for tracer 🐌

Benchmarks for #5959 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.127
  • 1 benchmarks are slower, with geometric mean 1.125
  • 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 ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartStopWithChild net6.0 7.67μs 40ns 188ns 0.0189 0.00756 0 5.43 KB
master StartStopWithChild netcoreapp3.1 9.82μs 51.7ns 264ns 0.0189 0.00945 0 5.62 KB
master StartStopWithChild net472 15.9μs 47.4ns 184ns 1.02 0.305 0.0937 6.06 KB
#5959 StartStopWithChild net6.0 7.95μs 44.4ns 310ns 0.0156 0.00781 0 5.42 KB
#5959 StartStopWithChild netcoreapp3.1 10.2μs 57ns 351ns 0.0245 0.00982 0 5.62 KB
#5959 StartStopWithChild net472 16μs 56.2ns 218ns 1.03 0.317 0.0952 6.08 KB
Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 481μs 455ns 1.76μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 634μs 358ns 1.34μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 842μs 537ns 2.08μs 0.417 0 0 3.3 KB
#5959 WriteAndFlushEnrichedTraces net6.0 466μs 231ns 863ns 0 0 0 2.7 KB
#5959 WriteAndFlushEnrichedTraces netcoreapp3.1 634μs 196ns 734ns 0 0 0 2.7 KB
#5959 WriteAndFlushEnrichedTraces net472 837μs 607ns 2.35μs 0.417 0 0 3.3 KB
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net6.0 189μs 1.05μs 6.57μs 0.183 0 0 18.45 KB
master SendRequest netcoreapp3.1 212μs 1.18μs 7.36μs 0.203 0 0 20.61 KB
master SendRequest net472 0.000145ns 9.9E‑05ns 0.00037ns 0 0 0 0 b
#5959 SendRequest net6.0 182μs 783ns 3.23μs 0.183 0 0 18.45 KB
#5959 SendRequest netcoreapp3.1 199μs 888ns 3.2μs 0.198 0 0 20.61 KB
#5959 SendRequest net472 0.000926ns 0.000568ns 0.00212ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 557μs 1.82μs 6.56μs 0.558 0 0 41.56 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 682μs 3.65μs 19.3μs 0.334 0 0 41.59 KB
master WriteAndFlushEnrichedTraces net472 883μs 3.56μs 15.1μs 8.42 2.66 0.443 53.31 KB
#5959 WriteAndFlushEnrichedTraces net6.0 575μs 1.25μs 4.85μs 0.548 0 0 41.71 KB
#5959 WriteAndFlushEnrichedTraces netcoreapp3.1 656μs 1.95μs 7.3μs 0.336 0 0 41.63 KB
#5959 WriteAndFlushEnrichedTraces net472 863μs 3.61μs 14μs 8.3 2.62 0.437 53.27 KB
Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net6.0 1.28μs 0.992ns 3.84ns 0.014 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.7μs 1.64ns 6.13ns 0.0136 0 0 1.02 KB
master ExecuteNonQuery net472 1.99μs 2.65ns 10.3ns 0.156 0 0 987 B
#5959 ExecuteNonQuery net6.0 1.26μs 1.15ns 4.46ns 0.0144 0 0 1.02 KB
#5959 ExecuteNonQuery netcoreapp3.1 1.64μs 1.11ns 4.31ns 0.0139 0 0 1.02 KB
#5959 ExecuteNonQuery net472 1.94μs 0.972ns 3.64ns 0.156 0 0 987 B
Benchmarks.Trace.ElasticsearchBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #5959

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearchAsync‑net6.0 1.125 1,204.81 1,355.79

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net6.0 1.26μs 0.869ns 3.25ns 0.0136 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.59μs 0.634ns 2.37ns 0.0134 0 0 976 B
master CallElasticsearch net472 2.53μs 1.04ns 3.91ns 0.157 0 0 995 B
master CallElasticsearchAsync net6.0 1.2μs 1.24ns 4.82ns 0.0133 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.67μs 0.639ns 2.39ns 0.0133 0 0 1.02 KB
master CallElasticsearchAsync net472 2.56μs 1.61ns 6.03ns 0.166 0 0 1.05 KB
#5959 CallElasticsearch net6.0 1.19μs 1.27ns 4.92ns 0.0137 0 0 976 B
#5959 CallElasticsearch netcoreapp3.1 1.59μs 4.32ns 16.7ns 0.0134 0 0 976 B
#5959 CallElasticsearch net472 2.45μs 1.47ns 5.71ns 0.158 0 0 995 B
#5959 CallElasticsearchAsync net6.0 1.36μs 0.577ns 2.23ns 0.0132 0 0 952 B
#5959 CallElasticsearchAsync netcoreapp3.1 1.57μs 0.558ns 2.09ns 0.0135 0 0 1.02 KB
#5959 CallElasticsearchAsync net472 2.47μs 1.63ns 6.08ns 0.166 0 0 1.05 KB
Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net6.0 1.16μs 0.568ns 2.2ns 0.0133 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.58μs 1.29ns 4.83ns 0.0125 0 0 952 B
master ExecuteAsync net472 1.81μs 0.756ns 2.93ns 0.145 0 0 915 B
#5959 ExecuteAsync net6.0 1.25μs 2.66ns 10.3ns 0.0134 0 0 952 B
#5959 ExecuteAsync netcoreapp3.1 1.72μs 0.916ns 3.3ns 0.0129 0 0 952 B
#5959 ExecuteAsync net472 1.81μs 1.25ns 4.86ns 0.145 0 0 915 B
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net6.0 4.09μs 1.5ns 5.63ns 0.0307 0 0 2.22 KB
master SendAsync netcoreapp3.1 5.21μs 2.29ns 8.87ns 0.0364 0 0 2.76 KB
master SendAsync net472 7.76μs 2.74ns 10.6ns 0.498 0 0 3.15 KB
#5959 SendAsync net6.0 4.04μs 4.12ns 14.9ns 0.0303 0 0 2.22 KB
#5959 SendAsync netcoreapp3.1 5.25μs 2.98ns 11.5ns 0.0367 0 0 2.76 KB
#5959 SendAsync net472 7.84μs 2.45ns 9.49ns 0.499 0 0 3.15 KB
Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 1.52μs 0.877ns 3.4ns 0.0229 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.32μs 2.43ns 9.1ns 0.0219 0 0 1.64 KB
master EnrichedLog net472 2.79μs 1.91ns 7.41ns 0.25 0 0 1.57 KB
#5959 EnrichedLog net6.0 1.47μs 0.881ns 3.3ns 0.0228 0 0 1.64 KB
#5959 EnrichedLog netcoreapp3.1 2.14μs 1.9ns 7.38ns 0.0221 0 0 1.64 KB
#5959 EnrichedLog net472 2.62μs 2.42ns 9.38ns 0.249 0 0 1.57 KB
Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 113μs 104ns 389ns 0.0568 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 120μs 425ns 1.53μs 0 0 0 4.28 KB
master EnrichedLog net472 148μs 218ns 815ns 0.667 0.222 0 4.46 KB
#5959 EnrichedLog net6.0 115μs 289ns 1.12μs 0 0 0 4.28 KB
#5959 EnrichedLog netcoreapp3.1 122μs 126ns 487ns 0 0 0 4.28 KB
#5959 EnrichedLog net472 150μs 379ns 1.47μs 0.681 0.227 0 4.46 KB
Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 3.06μs 1.08ns 3.89ns 0.0306 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.17μs 3.12ns 11.2ns 0.0291 0 0 2.2 KB
master EnrichedLog net472 4.87μs 2.96ns 11.1ns 0.32 0 0 2.02 KB
#5959 EnrichedLog net6.0 3.07μs 1.08ns 4.18ns 0.0305 0 0 2.2 KB
#5959 EnrichedLog netcoreapp3.1 4.22μs 1.54ns 5.78ns 0.0295 0 0 2.2 KB
#5959 EnrichedLog net472 4.89μs 1.06ns 4.12ns 0.32 0 0 2.02 KB
Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net6.0 1.37μs 1.09ns 4.08ns 0.0157 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.75μs 0.826ns 3.2ns 0.0157 0 0 1.14 KB
master SendReceive net472 2.12μs 1.14ns 4.42ns 0.183 0 0 1.16 KB
#5959 SendReceive net6.0 1.38μs 0.814ns 3.15ns 0.0158 0 0 1.14 KB
#5959 SendReceive netcoreapp3.1 1.81μs 0.386ns 1.39ns 0.0154 0 0 1.14 KB
#5959 SendReceive net472 2.16μs 1.61ns 6.22ns 0.183 0 0 1.16 KB
Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 2.73μs 3.94ns 15.3ns 0.0218 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.98μs 1.24ns 4.82ns 0.0218 0 0 1.65 KB
master EnrichedLog net472 4.29μs 2.53ns 9.82ns 0.322 0 0 2.04 KB
#5959 EnrichedLog net6.0 2.8μs 1ns 3.88ns 0.0224 0 0 1.6 KB
#5959 EnrichedLog netcoreapp3.1 3.97μs 2.59ns 10ns 0.022 0 0 1.65 KB
#5959 EnrichedLog net472 4.33μs 1.45ns 5.61ns 0.323 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 400ns 0.304ns 1.18ns 0.00802 0 0 576 B
master StartFinishSpan netcoreapp3.1 607ns 0.444ns 1.72ns 0.00789 0 0 576 B
master StartFinishSpan net472 633ns 0.405ns 1.57ns 0.0916 0 0 578 B
master StartFinishScope net6.0 478ns 0.375ns 1.45ns 0.00979 0 0 696 B
master StartFinishScope netcoreapp3.1 774ns 0.694ns 2.6ns 0.00932 0 0 696 B
master StartFinishScope net472 774ns 1.28ns 4.97ns 0.104 0 0 658 B
#5959 StartFinishSpan net6.0 394ns 0.334ns 1.25ns 0.0081 0 0 576 B
#5959 StartFinishSpan netcoreapp3.1 549ns 0.452ns 1.75ns 0.00771 0 0 576 B
#5959 StartFinishSpan net472 584ns 0.596ns 2.31ns 0.0916 0 0 578 B
#5959 StartFinishScope net6.0 478ns 0.564ns 2.18ns 0.0098 0 0 696 B
#5959 StartFinishScope netcoreapp3.1 758ns 0.845ns 3.05ns 0.00924 0 0 696 B
#5959 StartFinishScope net472 752ns 0.909ns 3.52ns 0.104 0 0 658 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #5959

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑netcoreapp3.1 1.127 1,050.73 932.68

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net6.0 638ns 0.489ns 1.89ns 0.00993 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 1.05μs 0.533ns 2.07ns 0.00946 0 0 696 B
master RunOnMethodBegin net472 1.03μs 1.74ns 6.72ns 0.105 0 0 658 B
#5959 RunOnMethodBegin net6.0 663ns 0.452ns 1.75ns 0.00989 0 0 696 B
#5959 RunOnMethodBegin netcoreapp3.1 932ns 0.608ns 2.35ns 0.00935 0 0 696 B
#5959 RunOnMethodBegin net472 1.14μs 0.858ns 3.21ns 0.105 0 0 658 B

@gleocadie
gleocadie force-pushed the gleocadie/add-lock-holder-contention branch from 5551ad1 to 0469c3b Compare August 29, 2024 07:57
@gleocadie
gleocadie marked this pull request as ready for review August 29, 2024 07:57
@gleocadie
gleocadie requested a review from a team as a code owner August 29, 2024 07:57
chrisnas
chrisnas approved these changes Aug 29, 2024
View reviewed changes

@chrisnas chrisnas left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@gleocadie
gleocadie force-pushed the gleocadie/add-lock-holder-contention branch from 0469c3b to 34254f1 Compare August 29, 2024 08:27
@gleocadie
gleocadie force-pushed the gleocadie/add-lock-holder-contention branch from 34254f1 to e723bbb Compare August 29, 2024 09:19
@gleocadie
gleocadie merged commit 338dd13 into master Aug 29, 2024
@gleocadie
gleocadie deleted the gleocadie/add-lock-holder-contention branch August 29, 2024 12:54
@github-actions github-actions Bot added this to the vNext-v3 milestone Aug 29, 2024
@gleocadie gleocadie mentioned this pull request Sep 4, 2024
Merged
@andrewlock andrewlock added area:profiler Issues related to the continous-profiler area:profiler labels Sep 16, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@chrisnas chrisnas chrisnas approved these changes

Assignees

No one assigned

Labels

area:profiler Issues related to the continous-profiler type:new-feature

Projects

None yet

Milestone

3.2.0

Development

Successfully merging this pull request may close these issues.

3 participants

@gleocadie @andrewlock @chrisnas