Fix error checking for CallTargetBubbleUpException (#5836 => v2) #5843

kevingosse · 2024-08-02T14:11:41Z

Summary of changes

Fix error checking when emitting the CallTargetBubbleUpException code. As a bonus, add synchronization when creating the metadata tokens.

Reason for change

If for some reason we fail to create the metadata tokens, we could create an invalid EH clause, which causes an access violation later on.

Implementation details

Converted the calltarget_tokens mutex to a recursive mutex, because the EnsureBaseCalltargetTokens methods call each other.

Test coverage

Hard to test, but coincidentally I discovered that the the added synchronization fixes a crash when running powershell with SentinelOne activated.

Other details

Fixes #5799
Backport of #5836 to v2.

## Summary of changes Fix error checking when emitting the CallTargetBubbleUpException code. As a bonus, add synchronization when creating the metadata tokens. ## Reason for change If for some reason we fail to create the metadata tokens, we could create an invalid EH clause, which causes an access violation later on. ## Implementation details Converted the calltarget_tokens mutex to a recursive mutex, because the `EnsureBaseCalltargetTokens` methods call each other. ## Test coverage Hard to test, but coincidentally I discovered that the the added synchronization fixes a crash when running powershell with SentinelOne activated. ## Other details Fixes #5799

datadog-ddstaging · 2024-08-02T14:29:53Z

Datadog Report

Branch report: kevin/bubble_metadata_v2
Commit report: b3e4c96
Test service: dd-trace-dotnet

✅ 0 Failed, 349768 Passed, 2258 Skipped, 23h 18m 43.48s Total Time
⌛ 14 Performance Regressions

⌛ Performance Regressions vs Default Branch (14)

This report shows up to 5 performance regressions.

Profiler_walltime - scenarios 3.25s (+905.57ms, +39%) - Details
Profiler_liveheap_cpu_walltime - scenarios 4.25s (+1.07s, +34%) - Details
Profiler_exceptions_cpu_walltime - scenarios 4.25s (+918ms, +28%) - Details
Profiler_garbagecollections_cpu_walltime - scenarios 2.49s (+1.38s, +124%) - Details
Profiler_garbagecollections - scenarios 2.45s (+1.34s, +121%) - Details

andrewlock · 2024-08-02T14:41:25Z

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

gantt
    title Execution time (ms) FakeDbCommand (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5843) - mean (74ms)  : 62, 85
     .   : milestone, 74,
    master - mean (73ms)  : 63, 82
     .   : milestone, 73,

    section CallTarget+Inlining+NGEN
    This PR (5843) - mean (1,024ms)  : 1009, 1039
     .   : milestone, 1024,
    master - mean (1,039ms)  : 1016, 1063
     .   : milestone, 1039,

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

    section CallTarget+Inlining+NGEN
    This PR (5843) - mean (712ms)  : 686, 738
     .   : milestone, 712,
    master - mean (727ms)  : 706, 748
     .   : milestone, 727,

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

    section CallTarget+Inlining+NGEN
    This PR (5843) - mean (669ms)  : 645, 693
     .   : milestone, 669,
    master - mean (679ms)  : 649, 709
     .   : milestone, 679,

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

    section CallTarget+Inlining+NGEN
    This PR (5843) - mean (1,137ms)  : 1085, 1189
     .   : milestone, 1137,
    master - mean (1,147ms)  : 1118, 1175
     .   : milestone, 1147,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5843) - mean (277ms)  : 272, 282
     .   : milestone, 277,
    master - mean (276ms)  : 270, 282
     .   : milestone, 276,

    section CallTarget+Inlining+NGEN
    This PR (5843) - mean (890ms)  : 850, 930
     .   : milestone, 890,
    master - mean (904ms)  : 882, 927
     .   : milestone, 904,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (5843) - mean (266ms)  : 263, 270
     .   : milestone, 266,
    master - mean (266ms)  : 262, 269
     .   : milestone, 266,

    section CallTarget+Inlining+NGEN
    This PR (5843) - mean (872ms)  : 847, 898
     .   : milestone, 872,
    master - mean (883ms)  : 859, 906
     .   : milestone, 883,

andrewlock · 2024-08-02T15:48:56Z

Benchmarks Report for tracer 🐌

Benchmarks for #5843 compared to master:

2 benchmarks are faster, with geometric mean 1.121
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.71μs	43.4ns	304ns	0.0165	0.00826	0	5.43 KB
master	`StartStopWithChild`	netcoreapp3.1	9.96μs	52.6ns	273ns	0.015	0.00501	0	5.62 KB
master	`StartStopWithChild`	net472	15.9μs	30.8ns	119ns	1.01	0.289	0.0938	6.07 KB
#5843	`StartStopWithChild`	net6.0	7.94μs	44.6ns	292ns	0.0121	0.00404	0	5.42 KB
#5843	`StartStopWithChild`	netcoreapp3.1	9.97μs	54.9ns	320ns	0.0193	0.00484	0	5.61 KB
#5843	`StartStopWithChild`	net472	16.3μs	63.3ns	245ns	1.04	0.328	0.104	6.06 KB

Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	461μs	480ns	1.8μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	639μs	361ns	1.3μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	848μs	459ns	1.78μs	0.425	3.3 KB
#5843	`WriteAndFlushEnrichedTraces`	net6.0	489μs	410ns	1.59μs	0	2.7 KB
#5843	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	651μs	460ns	1.72μs	0	2.7 KB
#5843	`WriteAndFlushEnrichedTraces`	net472	862μs	391ns	1.51μs	0.428	3.3 KB

Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendRequest`	net6.0	193μs	1μs	5.1μs	0.181	18.45 KB
master	`SendRequest`	netcoreapp3.1	217μs	1.22μs	7.78μs	0.209	20.61 KB
master	`SendRequest`	net472	0.00122ns	0.000608ns	0.00211ns	0	0 b
#5843	`SendRequest`	net6.0	198μs	1.13μs	8.39μs	0.194	18.45 KB
#5843	`SendRequest`	netcoreapp3.1	222μs	1.25μs	9.01μs	0.215	20.61 KB
#5843	`SendRequest`	net472	0.00255ns	0.00111ns	0.00431ns	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	586μs	2.88μs	12.9μs	0.576	0	0	41.54 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	679μs	2.39μs	9.24μs	0.351	0	0	41.64 KB
master	`WriteAndFlushEnrichedTraces`	net472	846μs	3.34μs	13μs	8.17	2.45	0.408	53.27 KB
#5843	`WriteAndFlushEnrichedTraces`	net6.0	584μs	3.31μs	24.7μs	0.551	0	0	41.74 KB
#5843	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	703μs	2.9μs	10.9μs	0.34	0	0	41.8 KB
#5843	`WriteAndFlushEnrichedTraces`	net472	880μs	4.28μs	17.7μs	8.36	2.64	0.44	53.32 KB

Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteNonQuery`	net6.0	1.19μs	1.49ns	5.76ns	0.0143	1.02 KB
master	`ExecuteNonQuery`	netcoreapp3.1	1.72μs	1.15ns	4.47ns	0.0139	1.02 KB
master	`ExecuteNonQuery`	net472	1.96μs	2.41ns	9.35ns	0.156	987 B
#5843	`ExecuteNonQuery`	net6.0	1.32μs	0.725ns	2.71ns	0.014	1.02 KB
#5843	`ExecuteNonQuery`	netcoreapp3.1	1.71μs	1.11ns	4.28ns	0.0137	1.02 KB
#5843	`ExecuteNonQuery`	net472	2.04μs	3.82ns	14.8ns	0.156	987 B

Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`CallElasticsearch`	net6.0	1.24μs	0.841ns	3.26ns	0.0137	0	976 B
master	`CallElasticsearch`	netcoreapp3.1	1.46μs	0.923ns	3.45ns	0.0134	0	976 B
master	`CallElasticsearch`	net472	2.48μs	1.75ns	6.55ns	0.158	0	995 B
master	`CallElasticsearchAsync`	net6.0	1.24μs	0.368ns	1.43ns	0.013	0	952 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.66μs	0.89ns	3.33ns	0.0141	0	1.02 KB
master	`CallElasticsearchAsync`	net472	2.57μs	1.74ns	6.5ns	0.166	0	1.05 KB
#5843	`CallElasticsearch`	net6.0	1.2μs	0.858ns	3.09ns	0.0138	0	976 B
#5843	`CallElasticsearch`	netcoreapp3.1	1.55μs	0.663ns	2.57ns	0.0133	0	976 B
#5843	`CallElasticsearch`	net472	2.46μs	2.32ns	9ns	0.158	0.00123	995 B
#5843	`CallElasticsearchAsync`	net6.0	1.34μs	0.754ns	2.82ns	0.0134	0	952 B
#5843	`CallElasticsearchAsync`	netcoreapp3.1	1.62μs	0.672ns	2.42ns	0.0137	0	1.02 KB
#5843	`CallElasticsearchAsync`	net472	2.54μs	2.14ns	8.29ns	0.166	0.00127	1.05 KB

Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteAsync`	net6.0	1.29μs	0.304ns	1.14ns	0.0136	952 B
master	`ExecuteAsync`	netcoreapp3.1	1.64μs	0.904ns	3.5ns	0.0123	952 B
master	`ExecuteAsync`	net472	1.7μs	0.816ns	3.16ns	0.145	915 B
#5843	`ExecuteAsync`	net6.0	1.34μs	0.63ns	2.36ns	0.0136	952 B
#5843	`ExecuteAsync`	netcoreapp3.1	1.63μs	1.39ns	5.19ns	0.013	952 B
#5843	`ExecuteAsync`	net472	1.65μs	0.842ns	3.15ns	0.145	915 B

Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendAsync`	net6.0	4.14μs	2ns	7.74ns	0.0309	2.22 KB
master	`SendAsync`	netcoreapp3.1	5.02μs	2.32ns	8.98ns	0.0376	2.76 KB
master	`SendAsync`	net472	7.8μs	4.4ns	17.1ns	0.499	3.15 KB
#5843	`SendAsync`	net6.0	4.32μs	1.43ns	5.53ns	0.0306	2.22 KB
#5843	`SendAsync`	netcoreapp3.1	5.17μs	2.08ns	7.77ns	0.0364	2.76 KB
#5843	`SendAsync`	net472	7.81μs	2.93ns	11.4ns	0.497	3.15 KB

Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.41μs	0.54ns	2.02ns	0.0235	1.64 KB
master	`EnrichedLog`	netcoreapp3.1	2.31μs	1.2ns	4.48ns	0.0219	1.64 KB
master	`EnrichedLog`	net472	2.62μs	0.883ns	3.42ns	0.249	1.57 KB
#5843	`EnrichedLog`	net6.0	1.46μs	0.791ns	2.85ns	0.0233	1.64 KB
#5843	`EnrichedLog`	netcoreapp3.1	2.27μs	0.846ns	3.17ns	0.0216	1.64 KB
#5843	`EnrichedLog`	net472	2.54μs	1.82ns	7.03ns	0.25	1.57 KB

Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`EnrichedLog`	net6.0	113μs	219ns	848ns	0.0557	0	4.28 KB
master	`EnrichedLog`	netcoreapp3.1	119μs	286ns	1.11μs	0.059	0	4.28 KB
master	`EnrichedLog`	net472	149μs	335ns	1.3μs	0.67	0.223	4.46 KB
#5843	`EnrichedLog`	net6.0	115μs	422ns	1.63μs	0.058	0	4.28 KB
#5843	`EnrichedLog`	netcoreapp3.1	119μs	321ns	1.24μs	0.0593	0	4.28 KB
#5843	`EnrichedLog`	net472	150μs	200ns	774ns	0.673	0.224	4.46 KB

Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.93μs	1.54ns	5.76ns	0.0308	2.2 KB
master	`EnrichedLog`	netcoreapp3.1	4.23μs	1.03ns	4ns	0.0288	2.2 KB
master	`EnrichedLog`	net472	4.81μs	1.35ns	5.21ns	0.319	2.02 KB
#5843	`EnrichedLog`	net6.0	3.04μs	0.643ns	2.49ns	0.0305	2.2 KB
#5843	`EnrichedLog`	netcoreapp3.1	4.16μs	2.41ns	9.34ns	0.0291	2.2 KB
#5843	`EnrichedLog`	net472	4.82μs	5.18ns	19.4ns	0.32	2.02 KB

Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`SendReceive`	net6.0	1.31μs	2.07ns	8.02ns	0.0158	0	1.14 KB
master	`SendReceive`	netcoreapp3.1	1.71μs	0.984ns	3.81ns	0.0154	0	1.14 KB
master	`SendReceive`	net472	2.14μs	0.819ns	3.06ns	0.184	0.00107	1.16 KB
#5843	`SendReceive`	net6.0	1.42μs	1.09ns	4.22ns	0.0163	0	1.14 KB
#5843	`SendReceive`	netcoreapp3.1	1.78μs	0.658ns	2.55ns	0.015	0	1.14 KB
#5843	`SendReceive`	net472	2.06μs	1.16ns	4.49ns	0.183	0	1.16 KB

Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.68μs	0.955ns	3.57ns	0.0228	1.6 KB
master	`EnrichedLog`	netcoreapp3.1	4μs	14ns	52.5ns	0.0214	1.65 KB
master	`EnrichedLog`	net472	4.22μs	3.43ns	13.3ns	0.322	2.04 KB
#5843	`EnrichedLog`	net6.0	2.85μs	1.68ns	6.51ns	0.0229	1.6 KB
#5843	`EnrichedLog`	netcoreapp3.1	3.89μs	1.38ns	5.34ns	0.0214	1.65 KB
#5843	`EnrichedLog`	net472	4.41μs	2.78ns	10.8ns	0.324	2.04 KB

Benchmarks.Trace.SpanBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #5843

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0	1.118	458.22	409.91

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	458ns	0.185ns	0.715ns	0.00804	576 B
master	`StartFinishSpan`	netcoreapp3.1	550ns	0.22ns	0.853ns	0.00768	576 B
master	`StartFinishSpan`	net472	706ns	0.628ns	2.43ns	0.0917	578 B
master	`StartFinishScope`	net6.0	483ns	0.594ns	2.3ns	0.00968	696 B
master	`StartFinishScope`	netcoreapp3.1	708ns	0.177ns	0.64ns	0.00922	696 B
master	`StartFinishScope`	net472	855ns	0.561ns	2.02ns	0.105	658 B
#5843	`StartFinishSpan`	net6.0	410ns	0.148ns	0.572ns	0.00796	576 B
#5843	`StartFinishSpan`	netcoreapp3.1	580ns	0.572ns	2.14ns	0.00776	576 B
#5843	`StartFinishSpan`	net472	650ns	0.27ns	1.04ns	0.0916	578 B
#5843	`StartFinishScope`	net6.0	478ns	0.141ns	0.547ns	0.00964	696 B
#5843	`StartFinishScope`	netcoreapp3.1	732ns	0.456ns	1.71ns	0.0091	696 B
#5843	`StartFinishScope`	net472	877ns	0.681ns	2.64ns	0.104	658 B

Benchmarks.Trace.TraceAnnotationsBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #5843

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑netcoreapp3.1	1.124	962.51	856.25

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	659ns	0.227ns	0.878ns	0.00964	696 B
master	`RunOnMethodBegin`	netcoreapp3.1	962ns	0.553ns	2.14ns	0.00963	696 B
master	`RunOnMethodBegin`	net472	1.16μs	0.365ns	1.32ns	0.104	658 B
#5843	`RunOnMethodBegin`	net6.0	663ns	0.285ns	1.1ns	0.00997	696 B
#5843	`RunOnMethodBegin`	netcoreapp3.1	856ns	0.359ns	1.39ns	0.00932	696 B
#5843	`RunOnMethodBegin`	net472	1.07μs	0.472ns	1.77ns	0.104	658 B

kevingosse requested review from a team as code owners August 2, 2024 14:11

andrewlock approved these changes Aug 2, 2024

View reviewed changes

GreenMatan approved these changes Aug 4, 2024

View reviewed changes

kevingosse merged commit ac374e7 into release/2.x Aug 8, 2024
65 of 68 checks passed

kevingosse deleted the kevin/bubble_metadata_v2 branch August 8, 2024 17:07

github-actions bot added this to the vNext-v2 milestone Aug 8, 2024

andrewlock added type:bug area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations) area:native-library Automatic instrumentation native C++ code (Datadog.Trace.ClrProfiler.Native) labels Aug 14, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix error checking for CallTargetBubbleUpException (#5836 => v2) #5843

Fix error checking for CallTargetBubbleUpException (#5836 => v2) #5843

kevingosse commented Aug 2, 2024 •

edited

Loading

datadog-ddstaging bot commented Aug 2, 2024 •

edited

Loading

andrewlock commented Aug 2, 2024

andrewlock commented Aug 2, 2024

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #5843

Raw results

Faster 🎉 in #5843

Raw results

Fix error checking for CallTargetBubbleUpException (#5836 => v2) #5843

Fix error checking for CallTargetBubbleUpException (#5836 => v2) #5843

Conversation

kevingosse commented Aug 2, 2024 • edited Loading

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

datadog-ddstaging bot commented Aug 2, 2024 • edited Loading

Datadog Report

⌛ Performance Regressions vs Default Branch (14)

andrewlock commented Aug 2, 2024

Execution-Time Benchmarks Report ⏱️

andrewlock commented Aug 2, 2024

Benchmarks Report for tracer 🐌

Benchmark details

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #5843

Raw results

Faster 🎉 in #5843

Raw results

kevingosse commented Aug 2, 2024 •

edited

Loading

datadog-ddstaging bot commented Aug 2, 2024 •

edited

Loading