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

[Dynamic Instrumentation] DEBUG-2913 Fix runtime reflection exceptions when getting field value

Open dudikeleti opened this issue 1 year ago • 4 comments

Summary of changes

This PR aims to fix various kind of runtime exceptions while trying the get field value by reflection

dudikeleti avatar Sep 25 '24 11:09 dudikeleti

Datadog Report

Branch report: dudik/get-field-value-error Commit report: 2321480 Test service: dd-trace-dotnet

:white_check_mark: 0 Failed, 375984 Passed, 2752 Skipped, 25h 44m 4.98s Total Time :hourglass: 2 Performance Regressions

:hourglass: Performance Regressions vs Default Branch (2)

  • Profiler_exceptions - scenarios 5.59s (+252.53ms, +5%) - Details
  • Profiler_exceptions_cpu_walltime - scenarios 5.6s (+197.49ms, +4%) - Details

datadog-ddstaging[bot] avatar Sep 25 '24 12:09 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 (6078) - mean (70ms)  : 68, 71
     .   : milestone, 70,
    master - mean (70ms)  : 68, 72
     .   : milestone, 70,

    section CallTarget+Inlining+NGEN
    This PR (6078) - mean (1,116ms)  : 1096, 1135
     .   : milestone, 1116,
    master - mean (1,116ms)  : 1097, 1135
     .   : milestone, 1116,


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

    section CallTarget+Inlining+NGEN
    This PR (6078) - mean (777ms)  : 762, 791
     .   : milestone, 777,
    master - mean (775ms)  : 760, 791
     .   : milestone, 775,


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

    section CallTarget+Inlining+NGEN
    This PR (6078) - mean (734ms)  : 712, 757
     .   : milestone, 734,
    master - mean (730ms)  : 716, 745
     .   : milestone, 730,


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

    section CallTarget+Inlining+NGEN
    This PR (6078) - mean (1,230ms)  : 1207, 1252
     .   : milestone, 1230,
    master - mean (1,228ms)  : 1206, 1249
     .   : milestone, 1228,


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

    section CallTarget+Inlining+NGEN
    This PR (6078) - mean (954ms)  : 937, 971
     .   : milestone, 954,
    master - mean (955ms)  : 934, 977
     .   : milestone, 955,


gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6078) - mean (265ms)  : 260, 270
     .   : milestone, 265,
    master - mean (264ms)  : 261, 267
     .   : milestone, 264,

    section CallTarget+Inlining+NGEN
    This PR (6078) - mean (937ms)  : 917, 957
     .   : milestone, 937,
    master - mean (939ms)  : 923, 956
     .   : milestone, 939,

andrewlock avatar Sep 25 '24 12:09 andrewlock

Benchmarks Report for tracer :snail:

Benchmarks for #6078 compared to master:

  • All benchmarks have the same speed
  • 1 benchmarks have fewer 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.99μs 44.2ns 283ns 0.0152 0.00759 0 5.6 KB
master StartStopWithChild netcoreapp3.1 10.3μs 55.4ns 304ns 0.0153 0.00509 0 5.8 KB
master StartStopWithChild net472 16.4μs 39.9ns 149ns 1.03 0.286 0.0816 6.21 KB
#6078 StartStopWithChild net6.0 8.07μs 46.4ns 359ns 0.02 0.00799 0 5.62 KB
#6078 StartStopWithChild netcoreapp3.1 10μs 51.3ns 256ns 0.0149 0.00497 0 5.81 KB
#6078 StartStopWithChild net472 16.2μs 33.3ns 124ns 1.03 0.306 0.0968 6.21 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 478μs 274ns 1.06μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 651μs 401ns 1.45μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 841μs 833ns 3.23μs 0.422 0 0 3.3 KB
#6078 WriteAndFlushEnrichedTraces net6.0 479μs 210ns 785ns 0 0 0 2.7 KB
#6078 WriteAndFlushEnrichedTraces netcoreapp3.1 635μs 342ns 1.33μs 0 0 0 2.7 KB
#6078 WriteAndFlushEnrichedTraces net472 847μs 501ns 1.88μs 0.422 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 202μs 1.16μs 9.03μs 0.197 0 0 18.73 KB
master SendRequest netcoreapp3.1 222μs 1.26μs 9.17μs 0.214 0 0 20.89 KB
master SendRequest net472 0.0211ns 0.00519ns 0.0201ns 0 0 0 0 b
#6078 SendRequest net6.0 201μs 1.15μs 9.2μs 0.19 0 0 18.73 KB
#6078 SendRequest netcoreapp3.1 216μs 1.23μs 9.32μs 0.214 0 0 20.89 KB
#6078 SendRequest net472 0.00279ns 0.000481ns 0.00186ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed :heavy_check_mark: Fewer allocations :tada:

Fewer allocations :tada: in #6078

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑netcoreapp3.1 41.87 KB 41.65 KB -218 B -0.52%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 565μs 2.42μs 9.37μs 0.579 0 0 41.57 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 680μs 3.6μs 17.7μs 0.336 0 0 41.87 KB
master WriteAndFlushEnrichedTraces net472 856μs 3.36μs 13μs 8.25 2.6 0.434 53.32 KB
#6078 WriteAndFlushEnrichedTraces net6.0 565μs 2.6μs 10.1μs 0.556 0 0 41.45 KB
#6078 WriteAndFlushEnrichedTraces netcoreapp3.1 672μs 2.48μs 9.29μs 0.331 0 0 41.65 KB
#6078 WriteAndFlushEnrichedTraces net472 898μs 4.35μs 18.5μs 8.19 2.59 0.431 53.3 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.26μs 0.873ns 3.27ns 0.0142 0 0 1.02 KB
master ExecuteNonQuery netcoreapp3.1 1.71μs 3.27ns 12.2ns 0.0137 0 0 1.02 KB
master ExecuteNonQuery net472 2.09μs 1.39ns 5.22ns 0.156 0.00105 0 987 B
#6078 ExecuteNonQuery net6.0 1.37μs 1.26ns 4.87ns 0.0145 0 0 1.02 KB
#6078 ExecuteNonQuery netcoreapp3.1 1.74μs 0.955ns 3.57ns 0.0137 0 0 1.02 KB
#6078 ExecuteNonQuery net472 2.08μs 1.39ns 5.39ns 0.157 0.00105 0 987 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.17μs 0.384ns 1.38ns 0.0135 0 0 976 B
master CallElasticsearch netcoreapp3.1 1.54μs 2.2ns 8.52ns 0.0133 0 0 976 B
master CallElasticsearch net472 2.69μs 2.28ns 8.85ns 0.158 0 0 995 B
master CallElasticsearchAsync net6.0 1.38μs 0.616ns 2.39ns 0.0131 0 0 952 B
master CallElasticsearchAsync netcoreapp3.1 1.71μs 0.599ns 2.16ns 0.0137 0 0 1.02 KB
master CallElasticsearchAsync net472 2.68μs 0.98ns 3.67ns 0.166 0 0 1.05 KB
#6078 CallElasticsearch net6.0 1.28μs 1.08ns 4.05ns 0.0135 0 0 976 B
#6078 CallElasticsearch netcoreapp3.1 1.57μs 2.74ns 10.6ns 0.0134 0 0 976 B
#6078 CallElasticsearch net472 2.62μs 3.27ns 12.7ns 0.158 0 0 995 B
#6078 CallElasticsearchAsync net6.0 1.41μs 2.08ns 7.78ns 0.0131 0 0 952 B
#6078 CallElasticsearchAsync netcoreapp3.1 1.67μs 1.4ns 4.84ns 0.0136 0 0 1.02 KB
#6078 CallElasticsearchAsync net472 2.68μs 1.67ns 6.46ns 0.166 0 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.37μs 0.819ns 3.06ns 0.0131 0 0 952 B
master ExecuteAsync netcoreapp3.1 1.71μs 0.913ns 3.42ns 0.0128 0 0 952 B
master ExecuteAsync net472 1.85μs 0.496ns 1.92ns 0.145 0 0 915 B
#6078 ExecuteAsync net6.0 1.28μs 0.683ns 2.64ns 0.0134 0 0 952 B
#6078 ExecuteAsync netcoreapp3.1 1.58μs 2.84ns 11ns 0.0126 0 0 952 B
#6078 ExecuteAsync net472 1.82μs 0.63ns 2.44ns 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.4μs 2.26ns 8.15ns 0.0331 0 0 2.31 KB
master SendAsync netcoreapp3.1 5.19μs 6.13ns 23.7ns 0.0382 0 0 2.85 KB
master SendAsync net472 7.5μs 1.98ns 7.69ns 0.494 0 0 3.12 KB
#6078 SendAsync net6.0 4.48μs 1.06ns 3.97ns 0.0312 0 0 2.31 KB
#6078 SendAsync netcoreapp3.1 5.3μs 2.32ns 8.68ns 0.0371 0 0 2.85 KB
#6078 SendAsync net472 7.55μs 1.68ns 6.28ns 0.494 0 0 3.12 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.52μs 1.19ns 4.47ns 0.0234 0 0 1.64 KB
master EnrichedLog netcoreapp3.1 2.16μs 0.869ns 3.13ns 0.0225 0 0 1.64 KB
master EnrichedLog net472 2.59μs 3ns 11.6ns 0.249 0 0 1.57 KB
#6078 EnrichedLog net6.0 1.49μs 0.937ns 3.63ns 0.0233 0 0 1.64 KB
#6078 EnrichedLog netcoreapp3.1 2.2μs 1.22ns 4.56ns 0.0219 0 0 1.64 KB
#6078 EnrichedLog net472 2.54μs 2.05ns 7.67ns 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 118μs 152ns 590ns 0 0 0 4.28 KB
master EnrichedLog netcoreapp3.1 123μs 176ns 681ns 0 0 0 4.28 KB
master EnrichedLog net472 152μs 151ns 585ns 0.675 0.225 0 4.46 KB
#6078 EnrichedLog net6.0 120μs 283ns 1.06μs 0.0598 0 0 4.28 KB
#6078 EnrichedLog netcoreapp3.1 121μs 386ns 1.5μs 0.0599 0 0 4.28 KB
#6078 EnrichedLog net472 151μs 343ns 1.33μs 0.674 0.225 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 3.05μs 1.91ns 7.39ns 0.0305 0 0 2.2 KB
master EnrichedLog netcoreapp3.1 4.08μs 0.894ns 3.46ns 0.0285 0 0 2.2 KB
master EnrichedLog net472 4.84μs 1.45ns 5.61ns 0.32 0 0 2.02 KB
#6078 EnrichedLog net6.0 3.08μs 0.99ns 3.57ns 0.0306 0 0 2.2 KB
#6078 EnrichedLog netcoreapp3.1 4.13μs 1.3ns 5.05ns 0.029 0 0 2.2 KB
#6078 EnrichedLog net472 4.81μs 1.93ns 7.48ns 0.32 0 0 2.02 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.5μs 1.01ns 3.92ns 0.0158 0 0 1.14 KB
master SendReceive netcoreapp3.1 1.79μs 0.92ns 3.44ns 0.0151 0 0 1.14 KB
master SendReceive net472 2.3μs 1.64ns 6.34ns 0.183 0 0 1.16 KB
#6078 SendReceive net6.0 1.38μs 0.745ns 2.69ns 0.0158 0 0 1.14 KB
#6078 SendReceive netcoreapp3.1 1.75μs 0.753ns 2.92ns 0.0149 0 0 1.14 KB
#6078 SendReceive net472 2.12μs 0.57ns 2.13ns 0.183 0 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.69μs 0.725ns 2.81ns 0.0215 0 0 1.6 KB
master EnrichedLog netcoreapp3.1 3.85μs 1.5ns 5.79ns 0.0213 0 0 1.65 KB
master EnrichedLog net472 4.45μs 3.04ns 11.8ns 0.322 0 0 2.04 KB
#6078 EnrichedLog net6.0 2.91μs 2.24ns 8.37ns 0.0218 0 0 1.6 KB
#6078 EnrichedLog netcoreapp3.1 3.81μs 3.62ns 14ns 0.0215 0 0 1.65 KB
#6078 EnrichedLog net472 4.36μs 2.26ns 8.47ns 0.323 0 0 2.04 KB
Benchmarks.Trace.SpanBenchmark - 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 StartFinishSpan net6.0 398ns 0.469ns 1.76ns 0.00798 0 0 576 B
master StartFinishSpan netcoreapp3.1 634ns 0.471ns 1.83ns 0.00767 0 0 576 B
master StartFinishSpan net472 676ns 0.662ns 2.56ns 0.0917 0 0 578 B
master StartFinishScope net6.0 558ns 0.362ns 1.4ns 0.00972 0 0 696 B
master StartFinishScope netcoreapp3.1 745ns 0.72ns 2.79ns 0.00963 0 0 696 B
master StartFinishScope net472 904ns 0.487ns 1.89ns 0.104 0 0 658 B
#6078 StartFinishSpan net6.0 395ns 0.295ns 1.14ns 0.00801 0 0 576 B
#6078 StartFinishSpan netcoreapp3.1 591ns 0.725ns 2.81ns 0.00763 0 0 576 B
#6078 StartFinishSpan net472 709ns 0.567ns 2.2ns 0.0918 0 0 578 B
#6078 StartFinishScope net6.0 516ns 0.488ns 1.89ns 0.00974 0 0 696 B
#6078 StartFinishScope netcoreapp3.1 736ns 0.478ns 1.79ns 0.00955 0 0 696 B
#6078 StartFinishScope net472 882ns 1.08ns 4.19ns 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 666ns 1.55ns 5.99ns 0.00981 0 0 696 B
master RunOnMethodBegin netcoreapp3.1 893ns 2.04ns 7.62ns 0.00932 0 0 696 B
master RunOnMethodBegin net472 1.15μs 1.27ns 4.93ns 0.104 0 0 658 B
#6078 RunOnMethodBegin net6.0 697ns 0.475ns 1.84ns 0.00979 0 0 696 B
#6078 RunOnMethodBegin netcoreapp3.1 888ns 0.49ns 1.83ns 0.00962 0 0 696 B
#6078 RunOnMethodBegin net472 1.2μs 0.898ns 3.48ns 0.104 0 0 658 B

andrewlock avatar Sep 25 '24 13:09 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 (6078) (11.011M)   : 0, 11011181
    master (11.142M)   : 0, 11142356
    benchmarks/2.9.0 (11.033M)   : 0, 11032866

    section Automatic
    This PR (6078) (7.044M)   : 0, 7044270
    master (7.252M)   : 0, 7251747
    benchmarks/2.9.0 (7.786M)   : 0, 7785853

    section Trace stats
    master (7.490M)   : 0, 7489995

    section Manual
    master (11.182M)   : 0, 11182404

    section Manual + Automatic
    This PR (6078) (6.640M)   : 0, 6640202
    master (6.703M)   : 0, 6702855

    section DD_TRACE_ENABLED=0
    master (10.094M)   : 0, 10094067


gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6078) (9.548M)   : 0, 9547843
    master (9.713M)   : 0, 9712642
    benchmarks/2.9.0 (9.495M)   : 0, 9494821

    section Automatic
    This PR (6078) (6.378M)   : 0, 6378034
    master (6.395M)   : 0, 6395384

    section Trace stats
    master (6.668M)   : 0, 6668118

    section Manual
    master (9.282M)   : 0, 9281784

    section Manual + Automatic
    This PR (6078) (6.031M)   : 0, 6031477
    master (5.818M)   : 0, 5818172

    section DD_TRACE_ENABLED=0
    master (8.914M)   : 0, 8913970


gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6078) (9.552M)   : 0, 9551976
    master (9.738M)   : 0, 9737538
    benchmarks/2.9.0 (10.020M)   : 0, 10019592

    section Automatic
    This PR (6078) (6.258M)   : 0, 6257917
    master (6.255M)   : 0, 6254669
    benchmarks/2.9.0 (7.255M)   : 0, 7255257

    section Trace stats
    master (6.891M)   : 0, 6891297

    section Manual
    master (9.657M)   : 0, 9656628

    section Manual + Automatic
    This PR (6078) (5.940M)   : 0, 5939558
    master (5.942M)   : 0, 5941778

    section DD_TRACE_ENABLED=0
    master (8.910M)   : 0, 8909916

andrewlock avatar Sep 25 '24 15:09 andrewlock